2018-12-18T17:16:01.849Z,1545153361.849 [Supervisor](DEBUG): Initializing supervisor.
2018-12-18T17:16:01.861Z,1545153361.861 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-12-18T17:16:01.862Z,1545153361.862 [SyncHandler](INFO): Protected caller Thread ID is 798
2018-12-18T17:16:01.862Z,1545153361.862 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-12-18T17:16:01.873Z,1545153361.873 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-12-18T17:16:01.873Z,1545153361.873 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 799
2018-12-18T17:16:01.876Z,1545153361.876 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-12-18T17:16:01.898Z,1545153361.898 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-12-18T17:16:01.909Z,1545153361.909 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-12-18T17:16:01.909Z,1545153361.909 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 800
2018-12-18T17:16:01.910Z,1545153361.910 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-12-18T17:16:01.921Z,1545153361.921 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-12-18T17:16:01.921Z,1545153361.921 [logger ThreadHandler](INFO): Protected caller Thread ID is 801
2018-12-18T17:16:01.923Z,1545153361.923 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-12-18T17:16:01.923Z,1545153361.923 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-12-18T17:16:01.928Z,1545153361.928 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-12-18T17:16:02.575Z,1545153362.575 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-12-18T17:16:02.576Z,1545153362.576 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-12-18T17:16:02.930Z,1545153362.930 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-12-18T17:16:02.932Z,1545153362.932 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-12-18T17:16:03.488Z,1545153363.488 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-12-18T17:16:03.488Z,1545153363.488 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-12-18T17:16:03.753Z,1545153363.753 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-12-18T17:16:03.755Z,1545153363.755 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-12-18T17:16:03.911Z,1545153363.911 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-12-18T17:16:03.913Z,1545153363.913 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-12-18T17:16:04.481Z,1545153364.481 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-12-18T17:16:04.482Z,1545153364.482 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-12-18T17:16:04.948Z,1545153364.948 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-12-18T17:16:04.949Z,1545153364.949 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-12-18T17:16:05.511Z,1545153365.511 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-12-18T17:16:05.513Z,1545153365.513 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-12-18T17:16:05.617Z,1545153365.617 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-12-18T17:16:05.618Z,1545153365.618 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-12-18T17:16:05.714Z,1545153365.714 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-12-18T17:16:05.714Z,1545153365.714 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-12-18T17:16:05.929Z,1545153365.929 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-12-18T17:16:05.930Z,1545153365.930 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-12-18T17:16:06.132Z,1545153366.132 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-12-18T17:16:06.134Z,1545153366.134 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-12-18T17:16:06.529Z,1545153366.529 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-12-18T17:16:06.531Z,1545153366.531 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-12-18T17:16:06.675Z,1545153366.675 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-12-18T17:16:06.676Z,1545153366.676 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-12-18T17:16:06.759Z,1545153366.759 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2018-12-18T17:16:06.762Z,1545153366.762 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2018-12-18T17:16:06.866Z,1545153366.866 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2018-12-18T17:16:06.986Z,1545153366.986 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2018-12-18T17:16:07.082Z,1545153367.082 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2018-12-18T17:16:07.168Z,1545153367.168 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2018-12-18T17:16:07.335Z,1545153367.335 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2018-12-18T17:16:07.522Z,1545153367.522 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2018-12-18T17:16:07.598Z,1545153367.598 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2018-12-18T17:16:07.824Z,1545153367.824 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-12-18T17:16:07.824Z,1545153367.824 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2018-12-18T17:16:07.908Z,1545153367.908 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2018-12-18T17:16:07.998Z,1545153367.998 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2018-12-18T17:16:08.101Z,1545153368.101 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2018-12-18T17:16:08.229Z,1545153368.229 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-12-18T17:16:08.247Z,1545153368.247 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-12-18T17:16:08.525Z,1545153368.525 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-12-18T17:16:08.526Z,1545153368.526 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-12-18T17:16:08.582Z,1545153368.582 [DepthRateCalculator] Loaded
2018-12-18T17:16:08.582Z,1545153368.582 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-12-18T17:16:08.587Z,1545153368.587 [PitchRateCalculator] Loaded
2018-12-18T17:16:08.588Z,1545153368.588 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-12-18T17:16:08.603Z,1545153368.603 [SpeedCalculator] Loaded
2018-12-18T17:16:08.604Z,1545153368.604 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-12-18T17:16:08.624Z,1545153368.624 [TempGradientCalculator] Loaded
2018-12-18T17:16:08.624Z,1545153368.624 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-12-18T17:16:08.630Z,1545153368.630 [YawRateCalculator] Loaded
2018-12-18T17:16:08.630Z,1545153368.630 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-12-18T17:16:08.669Z,1545153368.669 [ElevatorOffsetCalculator] Loaded
2018-12-18T17:16:08.669Z,1545153368.669 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-12-18T17:16:08.670Z,1545153368.670 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-12-18T17:16:08.670Z,1545153368.670 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-12-18T17:16:08.771Z,1545153368.771 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-12-18T17:16:08.771Z,1545153368.771 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-12-18T17:16:08.914Z,1545153368.914 [BuoyancyServo] Loaded
2018-12-18T17:16:08.915Z,1545153368.915 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-12-18T17:16:08.929Z,1545153368.929 [ElevatorServo] Loaded
2018-12-18T17:16:08.929Z,1545153368.929 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-12-18T17:16:08.943Z,1545153368.943 [MassServo] Loaded
2018-12-18T17:16:08.944Z,1545153368.944 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-12-18T17:16:08.959Z,1545153368.959 [RudderServo] Loaded
2018-12-18T17:16:08.959Z,1545153368.959 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-12-18T17:16:08.973Z,1545153368.973 [ThrusterServo] Loaded
2018-12-18T17:16:08.973Z,1545153368.973 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-12-18T17:16:08.973Z,1545153368.973 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-12-18T17:16:08.975Z,1545153368.975 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-12-18T17:16:08.999Z,1545153368.999 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-12-18T17:16:08.999Z,1545153368.999 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-12-18T17:16:09.123Z,1545153369.123 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-12-18T17:16:09.124Z,1545153369.124 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-12-18T17:16:09.692Z,1545153369.692 [DataOverHttps] Loaded
2018-12-18T17:16:09.692Z,1545153369.692 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-12-18T17:16:09.706Z,1545153369.706 [Depth_Keller] Loaded
2018-12-18T17:16:09.706Z,1545153369.706 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-12-18T17:16:09.711Z,1545153369.711 [DropWeight] Loaded
2018-12-18T17:16:09.711Z,1545153369.711 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-12-18T17:16:09.806Z,1545153369.806 [NAL9602] Loaded
2018-12-18T17:16:09.807Z,1545153369.807 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-12-18T17:16:09.822Z,1545153369.822 [Onboard] Loaded
2018-12-18T17:16:09.822Z,1545153369.822 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-12-18T17:16:09.832Z,1545153369.832 [Radio_Surface] Loaded
2018-12-18T17:16:09.832Z,1545153369.832 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-12-18T17:16:09.834Z,1545153369.834 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4088F4E0
2018-12-18T17:16:09.834Z,1545153369.834 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 883
2018-12-18T17:16:09.985Z,1545153369.985 [PNI_TCM] Loaded
2018-12-18T17:16:09.985Z,1545153369.985 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-12-18T17:16:09.986Z,1545153369.986 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-12-18T17:16:09.986Z,1545153369.986 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-12-18T17:16:10.387Z,1545153370.387 [SBIT](DEBUG): Construct Startup Built In Test.
2018-12-18T17:16:10.408Z,1545153370.408 [SBIT] Loaded
2018-12-18T17:16:10.408Z,1545153370.408 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-12-18T17:16:10.409Z,1545153370.409 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-12-18T17:16:10.421Z,1545153370.421 [IBIT] Loaded
2018-12-18T17:16:10.421Z,1545153370.421 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-12-18T17:16:10.497Z,1545153370.497 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-12-18T17:16:10.939Z,1545153370.939 [CBIT] Loaded
2018-12-18T17:16:10.939Z,1545153370.939 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-12-18T17:16:10.939Z,1545153370.939 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-12-18T17:16:10.940Z,1545153370.940 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-12-18T17:16:11.230Z,1545153371.230 [CTD_NeilBrown] Loaded
2018-12-18T17:16:11.230Z,1545153371.230 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2018-12-18T17:16:11.231Z,1545153371.231 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4096F4E0
2018-12-18T17:16:11.231Z,1545153371.231 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 884
2018-12-18T17:16:11.311Z,1545153371.311 [CTD_Seabird] Loaded
2018-12-18T17:16:11.312Z,1545153371.312 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2018-12-18T17:16:11.313Z,1545153371.313 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 4099F4E0
2018-12-18T17:16:11.313Z,1545153371.313 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 885
2018-12-18T17:16:11.327Z,1545153371.327 [PAR_Licor] Loaded
2018-12-18T17:16:11.327Z,1545153371.327 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-12-18T17:16:11.375Z,1545153371.375 [WetLabsBB2FL] Loaded
2018-12-18T17:16:11.375Z,1545153371.375 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-12-18T17:16:11.376Z,1545153371.376 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409CF4E0
2018-12-18T17:16:11.376Z,1545153371.376 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 886
2018-12-18T17:16:11.377Z,1545153371.377 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-12-18T17:16:11.378Z,1545153371.378 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-12-18T17:16:11.463Z,1545153371.463 [VerticalControl](DEBUG): Construct VerticalControl.
2018-12-18T17:16:11.544Z,1545153371.544 [VerticalControl] Loaded
2018-12-18T17:16:11.544Z,1545153371.544 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-12-18T17:16:11.545Z,1545153371.545 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-12-18T17:16:11.600Z,1545153371.600 [HorizontalControl] Loaded
2018-12-18T17:16:11.600Z,1545153371.600 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-12-18T17:16:11.601Z,1545153371.601 [SpeedControl](DEBUG): Construct SpeedControl.
2018-12-18T17:16:11.603Z,1545153371.603 [SpeedControl] Loaded
2018-12-18T17:16:11.603Z,1545153371.603 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-12-18T17:16:11.604Z,1545153371.604 [LoopControl](DEBUG): Construct LoopControl.
2018-12-18T17:16:11.604Z,1545153371.604 [LoopControl] Loaded
2018-12-18T17:16:11.604Z,1545153371.604 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-12-18T17:16:11.605Z,1545153371.605 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-12-18T17:16:11.606Z,1545153371.606 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-12-18T17:16:11.646Z,1545153371.646 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-12-18T17:16:11.647Z,1545153371.647 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-12-18T17:16:11.757Z,1545153371.757 [DeadReckonUsingSpeedCalculator] Loaded
2018-12-18T17:16:11.757Z,1545153371.757 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-12-18T17:16:11.773Z,1545153371.773 [NavChart] Loaded
2018-12-18T17:16:11.774Z,1545153371.774 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-12-18T17:16:11.778Z,1545153371.778 [UniversalFixResidualReporter] Loaded
2018-12-18T17:16:11.778Z,1545153371.778 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-12-18T17:16:11.778Z,1545153371.778 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-12-18T17:16:11.782Z,1545153371.782 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-12-18T17:16:11.783Z,1545153371.783 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-12-18T17:16:11.789Z,1545153371.789 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-12-18T17:16:11.790Z,1545153371.790 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A684E0
2018-12-18T17:16:11.791Z,1545153371.791 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 887
2018-12-18T17:16:11.795Z,1545153371.795 [Supervisor](INFO): Main Thread ID is 797
2018-12-18T17:16:11.795Z,1545153371.795 [Supervisor](DEBUG): Running supervisor.
2018-12-18T17:16:11.796Z,1545153371.796 [CommandLine ThreadHandler](INFO): Handler Thread ID is 888
2018-12-18T17:16:11.798Z,1545153371.798 [controlThread ThreadHandler](INFO): Handler Thread ID is 889
2018-12-18T17:16:11.799Z,1545153371.799 [controlThread](DEBUG): Initializing ControlThread
2018-12-18T17:16:11.799Z,1545153371.799 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-12-18T17:16:11.800Z,1545153371.800 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-12-18T17:16:11.800Z,1545153371.800 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-12-18T17:16:11.800Z,1545153371.800 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-12-18T17:16:11.801Z,1545153371.801 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-12-18T17:16:11.802Z,1545153371.802 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-12-18T17:16:11.807Z,1545153371.807 [SBIT](INFO): Initialize SBIT Component.
2018-12-18T17:16:11.807Z,1545153371.807 [SBIT](IMPORTANT): git: 2018-12-13
2018-12-18T17:16:11.808Z,1545153371.808 [SBIT](INFO): git hash: 8200dc43e6ef01082c531ff0fab84136a371dc2d
2018-12-18T17:16:11.808Z,1545153371.808 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-12-18T17:16:11.808Z,1545153371.808 [SBIT](IMPORTANT): Kernel Version:#2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-12-18T17:16:11.809Z,1545153371.809 [SBIT](INFO): Beginning SBIT in 36.000000 seconds.
2018-12-18T17:16:11.810Z,1545153371.810 [IBIT](INFO): Initialize IBIT Component.
2018-12-18T17:16:11.811Z,1545153371.811 [CBIT](DEBUG): Initialize CBIT Component.
2018-12-18T17:16:11.812Z,1545153371.812 [logger ThreadHandler](INFO): Handler Thread ID is 890
2018-12-18T17:16:11.825Z,1545153371.825 [CBIT](DEBUG): Initialized mux pins.
2018-12-18T17:16:11.825Z,1545153371.825 [CBIT](DEBUG): Initializing the watchdog timer.
2018-12-18T17:16:11.829Z,1545153371.829 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 891
2018-12-18T17:16:11.835Z,1545153371.835 [Radio_Surface](INFO): Powering up
2018-12-18T17:16:11.845Z,1545153371.845 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 892
2018-12-18T17:16:11.846Z,1545153371.846 [CTD_NeilBrown](INFO): Powering down
2018-12-18T17:16:11.853Z,1545153371.853 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-12-18T17:16:11.853Z,1545153371.853 [CBIT](DEBUG): Initializing heartbeat.
2018-12-18T17:16:11.873Z,1545153371.873 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 893
2018-12-18T17:16:11.874Z,1545153371.874 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2018-12-18T17:16:11.879Z,1545153371.879 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 895
2018-12-18T17:16:11.880Z,1545153371.880 [WetLabsBB2FL](INFO): Powering down
2018-12-18T17:16:11.898Z,1545153371.898 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2018-12-18T17:16:11.906Z,1545153371.906 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 896
2018-12-18T17:16:11.925Z,1545153371.925 [CBIT](DEBUG): Deactivating GF circuits.
2018-12-18T17:16:11.925Z,1545153371.925 [CBIT](DEBUG): Deactivating emergency mode.
2018-12-18T17:16:11.934Z,1545153371.934 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-12-18T17:16:11.935Z,1545153371.935 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-12-18T17:16:11.935Z,1545153371.935 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-12-18T17:16:11.935Z,1545153371.935 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-12-18T17:16:11.935Z,1545153371.935 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-12-18T17:16:11.935Z,1545153371.935 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-12-18T17:16:11.936Z,1545153371.936 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-12-18T17:16:11.936Z,1545153371.936 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-12-18T17:16:11.936Z,1545153371.936 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-12-18T17:16:11.936Z,1545153371.936 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-12-18T17:16:11.936Z,1545153371.936 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-12-18T17:16:11.937Z,1545153371.937 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-12-18T17:16:11.937Z,1545153371.937 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-12-18T17:16:11.937Z,1545153371.937 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-12-18T17:16:11.937Z,1545153371.937 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-12-18T17:16:11.938Z,1545153371.938 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-12-18T17:16:11.965Z,1545153371.965 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-12-18T17:16:11.967Z,1545153371.967 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-12-18T17:16:11.968Z,1545153371.968 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-12-18T17:16:11.968Z,1545153371.968 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-12-18T17:16:11.968Z,1545153371.968 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-12-18T17:16:11.969Z,1545153371.969 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-12-18T17:16:11.970Z,1545153371.970 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-12-18T17:16:11.970Z,1545153371.970 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-12-18T17:16:11.971Z,1545153371.971 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-12-18T17:16:11.972Z,1545153371.972 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-12-18T17:16:12.013Z,1545153372.013 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-12-18T17:16:12.054Z,1545153372.054 [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-12-18T17:16:12.055Z,1545153372.055 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-12-18T17:16:12.186Z,1545153372.186 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-12-18T17:16:12.187Z,1545153372.187 [Default:A.Wait](DEBUG): Construct Wait.
2018-12-18T17:16:12.205Z,1545153372.205 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-12-18T17:16:12.236Z,1545153372.236 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-12-18T17:16:12.251Z,1545153372.251 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-12-18T17:16:12.256Z,1545153372.256 [Default:E.Execute](DEBUG): Construct Execute.
2018-12-18T17:16:12.284Z,1545153372.284 [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-12-18T17:16:12.289Z,1545153372.289 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-12-18T17:16:12.329Z,1545153372.329 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-12-18T17:16:12.378Z,1545153372.378 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2018-12-18T17:16:12.513Z,1545153372.513 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-12-18T17:16:12.937Z,1545153372.937 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-12-18T17:16:12.949Z,1545153372.949 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-12-18T17:16:12.975Z,1545153372.975 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-12-18T17:16:12.984Z,1545153372.984 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-12-18T17:16:12.990Z,1545153372.990 [MassServo](DEBUG): Initializing EZServoServo.
2018-12-18T17:16:12.993Z,1545153372.993 [MassServo](DEBUG): Initializing MassServo.
2018-12-18T17:16:13.002Z,1545153373.002 [RudderServo](DEBUG): Initializing EZServoServo.
2018-12-18T17:16:13.013Z,1545153373.013 [RudderServo](DEBUG): Initializing RudderServo.
2018-12-18T17:16:13.019Z,1545153373.019 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-12-18T17:16:13.029Z,1545153373.029 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-12-18T17:16:13.933Z,1545153373.933 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2018-12-18T17:16:13.933Z,1545153373.933 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2018-12-18T17:16:13.933Z,1545153373.933 [BuoyancyServo] Communications Fault, FailCount= 1
2018-12-18T17:16:13.933Z,1545153373.933 [BuoyancyServo](ERROR): Communications Fault
2018-12-18T17:16:14.140Z,1545153374.140 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2018-12-18T17:16:16.353Z,1545153376.353 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2018-12-18T17:16:16.353Z,1545153376.353 [BuoyancyServo] No Fault, FailCount= 1
2018-12-18T17:16:16.593Z,1545153376.593 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-12-18T17:16:16.714Z,1545153376.714 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-12-18T17:16:39.815Z,1545153399.815 [NAL9602](INFO): Powering up NAL9602
2018-12-18T17:16:48.287Z,1545153408.287 [SBIT](IMPORTANT): Beginning Startup BIT
2018-12-18T17:16:48.291Z,1545153408.291 [CBIT](IMPORTANT): Beginning ground fault scan
2018-12-18T17:16:51.167Z,1545153411.167 [NAL9602](INFO): NAL9602 initialized
2018-12-18T17:16:59.276Z,1545153419.276 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.002509
CHAN A1 (24V): -0.007157
CHAN A2 (12V): 4.697929
CHAN A3 (5V): -0.001374
CHAN B0 (3.3V): -0.000263
CHAN B1 (3.15aV): -0.000135
CHAN B2 (3.15bV): -0.000513
CHAN B3 (GND): -0.000059
OPEN: -0.000592
Full Scale Calc: 4.765 mA, -1.589 mA
2018-12-18T17:17:41.990Z,1545153461.990 [CommandLine](IMPORTANT): got command failComponent
2018-12-18T17:17:41.991Z,1545153461.991 [CommandLine](IMPORTANT): Failed components:
2018-12-18T17:17:41.991Z,1545153461.991 [CommandLine](IMPORTANT): No failed Components.
2018-12-18T17:17:42.346Z,1545153462.346 [SBIT](IMPORTANT): SBIT PASSED
2018-12-18T17:17:42.393Z,1545153462.393 [CommandLine](IMPORTANT): got command configSet list
2018-12-18T17:17:42.393Z,1545153462.393 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-12-18T17:17:42.394Z,1545153462.394 [CommandLine](IMPORTANT): Aanderaa_O2.loadAtStartup=0 bool;

2018-12-18T17:17:42.394Z,1545153462.394 [CommandLine](IMPORTANT): BPC1.batteryMuxCycleTime=10 minute;

2018-12-18T17:17:42.394Z,1545153462.394 [CommandLine](IMPORTANT): BPC1.loadAtStartup=0 bool;

2018-12-18T17:17:42.395Z,1545153462.395 [CommandLine](IMPORTANT): CTD_Seabird.loadAtStartup=1 bool;

2018-12-18T17:17:42.395Z,1545153462.395 [CommandLine](IMPORTANT): Express none CTD_NeilBrown.bin_mean_sea_water_salinity;

2018-12-18T17:17:42.395Z,1545153462.395 [CommandLine](IMPORTANT): Express none CTD_NeilBrown.bin_mean_sea_water_temperature 0.150000 kelvin;

2018-12-18T17:17:42.395Z,1545153462.395 [CommandLine](IMPORTANT): Express linearApproximation CTD_NeilBrown.bin_median_sea_water_salinity 0.020000 practical_salinity_unit;

2018-12-18T17:17:42.395Z,1545153462.395 [CommandLine](IMPORTANT): Express linearApproximation CTD_NeilBrown.bin_median_sea_water_temperature 0.150000 kelvin;

2018-12-18T17:17:42.395Z,1545153462.395 [CommandLine](IMPORTANT): Express none VerticalTemperatureHomogeneityIndexCalculator.vertical_temperature_homogeneity_index;

2018-12-18T17:17:42.395Z,1545153462.395 [CommandLine](IMPORTANT): Express linearApproximation height_above_sea_floor 5.000000 meter;

2018-12-18T17:17:42.395Z,1545153462.395 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=0 bool;

2018-12-18T17:17:42.395Z,1545153462.395 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=213 cubic_centimeter;

2018-12-18T17:17:42.396Z,1545153462.396 [CommandLine](IMPORTANT): VerticalControl.massDefault=4 millimeter;

2018-12-18T17:17:42.775Z,1545153462.775 [MissionManager](IMPORTANT): Started mission Startup
2018-12-18T17:17:42.776Z,1545153462.776 [Startup] Running Loop=1
2018-12-18T17:17:42.776Z,1545153462.776 [Startup](DEBUG): Aggregate::initialize Startup
2018-12-18T17:17:42.776Z,1545153462.776 [Startup:A.GoToSurface] Running Loop=1
2018-12-18T17:17:42.776Z,1545153462.776 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-12-18T17:17:42.777Z,1545153462.777 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-12-18T17:17:42.777Z,1545153462.777 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-12-18T17:17:42.777Z,1545153462.777 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-12-18T17:17:42.778Z,1545153462.778 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-12-18T17:17:42.778Z,1545153462.778 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-12-18T17:17:42.796Z,1545153462.796 [Startup:StartupSatComms] Running Loop=1
2018-12-18T17:17:42.796Z,1545153462.796 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-12-18T17:17:42.796Z,1545153462.796 [Startup:StartupSatComms:A] Running Loop=1
2018-12-18T17:17:43.133Z,1545153463.133 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-12-18T17:17:47.471Z,1545153467.471 [CommandLine](IMPORTANT): got command gfscan
2018-12-18T17:17:47.594Z,1545153467.594 [CBIT](IMPORTANT): Beginning ground fault scan
2018-12-18T17:17:58.358Z,1545153478.358 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.000052
CHAN A1 (24V): -0.003821
CHAN A2 (12V): -0.002635
CHAN A3 (5V): -0.001793
CHAN B0 (3.3V): -0.000002
CHAN B1 (3.15aV): -0.000467
CHAN B2 (3.15bV): 0.000084
CHAN B3 (GND): 0.000544
OPEN: -0.000610
Full Scale Calc: 4.765 mA, -1.589 mA
2018-12-18T17:18:43.140Z,1545153523.140 [Startup:StartupSatComms:A](INFO): Timed out from 2018-12-18T17:17:42.8Z
2018-12-18T17:18:43.140Z,1545153523.140 [Startup:StartupSatComms:A] Stopped
2018-12-18T17:18:43.140Z,1545153523.140 [Startup:StartupSatComms:B] Running Loop=1
2018-12-18T17:18:43.475Z,1545153523.475 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004378
2018-12-18T17:18:43.552Z,1545153523.552 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-12-18T17:18:47.468Z,1545153527.468 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20181218T171328/Courier0004.lzma
2018-12-18T17:18:48.235Z,1545153528.235 [DataOverHttps](INFO): Moved sent file to Logs/20181218T171328/Courier0004.lzma.bak
2018-12-18T17:18:48.235Z,1545153528.235 [DataOverHttps](INFO): SBD MOMSN=9084590
2018-12-18T17:18:56.995Z,1545153536.995 [DataOverHttps](INFO): Sending 935 bytes from file Logs/20181218T171328/Express0001.lzma
2018-12-18T17:18:57.791Z,1545153537.791 [DataOverHttps](INFO): Moved sent file to Logs/20181218T171328/Express0001.lzma.bak
2018-12-18T17:18:57.791Z,1545153537.791 [DataOverHttps](INFO): SBD MOMSN=9084594
2018-12-18T17:19:07.422Z,1545153547.422 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20181218T171328/Express0005.lzma
2018-12-18T17:19:08.207Z,1545153548.207 [DataOverHttps](INFO): Moved sent file to Logs/20181218T171328/Express0005.lzma.bak
2018-12-18T17:19:08.207Z,1545153548.207 [DataOverHttps](INFO): SBD MOMSN=9084620
2018-12-18T17:19:12.160Z,1545153552.160 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = 1000174.675322
2018-12-18T17:19:12.160Z,1545153552.160 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2018-12-18T17:19:12.161Z,1545153552.161 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-12-18T17:19:12.172Z,1545153552.172 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-12-18T17:19:12.318Z,1545153552.318 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-12-18T17:19:12.318Z,1545153552.318 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2018-12-18T17:19:12.639Z,1545153552.639 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-12-18T17:19:12.639Z,1545153552.639 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-12-18T17:19:12.640Z,1545153552.640 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-12-18T17:19:16.990Z,1545153556.990 [DataOverHttps](INFO): Sending 1094 bytes from file Logs/20181218T171601/Express0001.lzma
2018-12-18T17:19:17.787Z,1545153557.787 [DataOverHttps](INFO): Moved sent file to Logs/20181218T171601/Express0001.lzma.bak
2018-12-18T17:19:17.787Z,1545153557.787 [DataOverHttps](INFO): SBD MOMSN=9084622
2018-12-18T17:19:18.264Z,1545153558.264 [Startup:StartupSatComms:B] Stopped
2018-12-18T17:19:18.264Z,1545153558.264 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-12-18T17:19:18.264Z,1545153558.264 [Startup:StartupSatComms] Stopped
2018-12-18T17:19:18.265Z,1545153558.265 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-12-18T17:19:18.266Z,1545153558.266 [Startup](INFO): Completed Startup
2018-12-18T17:19:18.266Z,1545153558.266 [MissionManager](INFO): Startup is completed.
2018-12-18T17:19:18.266Z,1545153558.266 [MissionManager](INFO): Uninitializing Mission Startup
2018-12-18T17:19:18.266Z,1545153558.266 [Startup] Stopped
2018-12-18T17:19:18.266Z,1545153558.266 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-12-18T17:19:18.266Z,1545153558.266 [Startup:A.GoToSurface] Stopped
2018-12-18T17:19:18.266Z,1545153558.266 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-12-18T17:19:18.644Z,1545153558.644 [MissionManager](IMPORTANT): Started mission Default
2018-12-18T17:19:18.644Z,1545153558.644 [Default] Running Loop=1
2018-12-18T17:19:18.644Z,1545153558.644 [Default](DEBUG): Aggregate::initialize Default
2018-12-18T17:19:18.644Z,1545153558.644 [Default:B.GoToSurface] Running Loop=1
2018-12-18T17:19:18.644Z,1545153558.644 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-12-18T17:19:18.645Z,1545153558.645 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-12-18T17:19:18.645Z,1545153558.645 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-12-18T17:19:18.645Z,1545153558.645 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-12-18T17:19:18.646Z,1545153558.646 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-12-18T17:19:18.646Z,1545153558.646 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-12-18T17:19:18.646Z,1545153558.646 [Default:A.Wait] Running Loop=1
2018-12-18T17:19:18.646Z,1545153558.646 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-12-18T17:19:31.819Z,1545153571.819 [Default:A.Wait](INFO): Done Waiting.
2018-12-18T17:19:31.819Z,1545153571.819 [Default:A.Wait] Stopped
2018-12-18T17:19:31.819Z,1545153571.819 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-12-18T17:19:32.213Z,1545153572.213 [Default:CheckIn] Running Loop=1
2018-12-18T17:19:32.213Z,1545153572.213 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-12-18T17:19:32.213Z,1545153572.213 [Default:CheckIn:Read_GPS] Running Loop=1
2018-12-18T17:19:32.620Z,1545153572.620 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-12-18T17:21:54.142Z,1545153714.142 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-12-18T17:22:12.992Z,1545153732.992 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = 1000355.507183
2018-12-18T17:22:12.992Z,1545153732.992 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2018-12-18T17:22:12.992Z,1545153732.992 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-12-18T17:22:13.021Z,1545153733.021 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-12-18T17:22:13.402Z,1545153733.402 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-12-18T17:22:13.402Z,1545153733.402 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2018-12-18T17:22:13.781Z,1545153733.781 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-12-18T17:22:13.781Z,1545153733.781 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-12-18T17:22:13.782Z,1545153733.782 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-12-18T17:24:32.561Z,1545153872.561 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-12-18T17:19:32.2Z
2018-12-18T17:24:32.561Z,1545153872.561 [Default:CheckIn:Read_GPS] Stopped
2018-12-18T17:24:32.561Z,1545153872.561 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-12-18T17:24:32.944Z,1545153872.944 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-12-18T17:24:36.884Z,1545153876.884 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20181218T171601/Courier0004.lzma
2018-12-18T17:24:37.683Z,1545153877.683 [DataOverHttps](INFO): Moved sent file to Logs/20181218T171601/Courier0004.lzma.bak
2018-12-18T17:24:37.683Z,1545153877.683 [DataOverHttps](INFO): SBD MOMSN=9084712
2018-12-18T17:24:46.485Z,1545153886.485 [DataOverHttps](INFO): Sending 176 bytes from file Logs/20181218T171601/Express0005.lzma
2018-12-18T17:24:47.287Z,1545153887.287 [DataOverHttps](INFO): Moved sent file to Logs/20181218T171601/Express0005.lzma.bak
2018-12-18T17:24:47.287Z,1545153887.287 [DataOverHttps](INFO): SBD MOMSN=9084714
2018-12-18T17:24:47.738Z,1545153887.738 [Default:CheckIn:Read_Iridium] Stopped
2018-12-18T17:24:47.738Z,1545153887.738 [Default:CheckIn:C.Wait] Running Loop=1
2018-12-18T17:24:47.738Z,1545153887.738 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-12-18T17:25:14.148Z,1545153914.148 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = 1000536.663129
2018-12-18T17:25:14.148Z,1545153914.148 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3
2018-12-18T17:25:14.148Z,1545153914.148 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-12-18T17:25:14.196Z,1545153914.196 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-12-18T17:25:14.563Z,1545153914.563 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-12-18T17:25:14.563Z,1545153914.563 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3
2018-12-18T17:25:14.962Z,1545153914.962 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-12-18T17:25:14.963Z,1545153914.963 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-12-18T17:25:14.963Z,1545153914.963 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-12-18T17:26:53.279Z,1545154013.279 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-12-18T17:26:53.279Z,1545154013.279 [NAL9602] Data Fault, FailCount= 1
2018-12-18T17:26:53.279Z,1545154013.279 [NAL9602](ERROR): Data Fault
2018-12-18T17:26:53.363Z,1545154013.363 [CBIT](ERROR): Data Fault in component: NAL9602
2018-12-18T17:26:53.678Z,1545154013.678 [NAL9602](INFO): Powering down
2018-12-18T17:26:54.530Z,1545154014.530 [CBIT](INFO): Clearing failed state for component NAL9602
2018-12-18T17:26:54.530Z,1545154014.530 [NAL9602] No Fault, FailCount= 1
2018-12-18T17:27:24.078Z,1545154044.078 [NAL9602](INFO): Powering up NAL9602
2018-12-18T17:27:34.879Z,1545154054.879 [NAL9602](INFO): NAL9602 initialized
2018-12-18T17:28:15.308Z,1545154095.308 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = 1000717.822746
2018-12-18T17:28:15.308Z,1545154095.308 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 4
2018-12-18T17:28:15.308Z,1545154095.308 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-12-18T17:28:15.332Z,1545154095.332 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-12-18T17:28:15.714Z,1545154095.714 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-12-18T17:28:15.714Z,1545154095.714 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 4
2018-12-18T17:28:16.091Z,1545154096.091 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-12-18T17:28:16.091Z,1545154096.091 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-12-18T17:28:16.092Z,1545154096.092 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-12-18T17:29:48.524Z,1545154188.524 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-12-18T17:29:48.524Z,1545154188.524 [Default:CheckIn:C.Wait] Stopped
2018-12-18T17:29:48.524Z,1545154188.524 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-12-18T17:29:48.524Z,1545154188.524 [Default:CheckIn:D] Running Loop=1
2018-12-18T17:29:48.934Z,1545154188.934 [Default:CheckIn:D] Stopped
2018-12-18T17:29:48.934Z,1545154188.934 [Default:CheckIn:E] Running Loop=1
2018-12-18T17:29:52.012Z,1545154192.012 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.504733 min 
2018-12-18T17:29:52.046Z,1545154192.046 [Default:CheckIn:E] Stopped
2018-12-18T17:29:52.047Z,1545154192.047 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-12-18T17:29:52.047Z,1545154192.047 [Default:CheckIn] Stopped
2018-12-18T17:29:52.047Z,1545154192.047 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-12-18T17:29:52.047Z,1545154192.047 [Default:CheckIn](INFO): Running loop #2
2018-12-18T17:29:52.047Z,1545154192.047 [Default:CheckIn] Running Loop=2
2018-12-18T17:29:52.047Z,1545154192.047 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-12-18T17:29:52.047Z,1545154192.047 [Default:CheckIn:Read_GPS] Running Loop=1
2018-12-18T17:31:16.116Z,1545154276.116 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = 1000898.631459
2018-12-18T17:31:16.121Z,1545154276.121 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 5
2018-12-18T17:31:16.121Z,1545154276.121 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-12-18T17:31:16.149Z,1545154276.149 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-12-18T17:31:16.538Z,1545154276.538 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-12-18T17:31:16.538Z,1545154276.538 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 5
2018-12-18T17:31:16.937Z,1545154276.937 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-12-18T17:31:16.938Z,1545154276.938 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-12-18T17:31:16.938Z,1545154276.938 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-12-18T17:34:17.294Z,1545154457.294 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = 1001079.808222
2018-12-18T17:34:17.294Z,1545154457.294 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 6
2018-12-18T17:34:17.294Z,1545154457.294 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-12-18T17:34:17.306Z,1545154457.306 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-12-18T17:34:17.706Z,1545154457.706 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-12-18T17:34:17.706Z,1545154457.706 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 6
2018-12-18T17:34:18.067Z,1545154458.067 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-12-18T17:34:18.068Z,1545154458.068 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-12-18T17:34:18.068Z,1545154458.068 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-12-18T17:34:53.197Z,1545154493.197 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-12-18T17:29:52.0Z
2018-12-18T17:34:53.197Z,1545154493.197 [Default:CheckIn:Read_GPS] Stopped
2018-12-18T17:34:53.197Z,1545154493.197 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-12-18T17:34:53.659Z,1545154493.659 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20181218T171601/Courier0007.lzma
2018-12-18T17:34:54.451Z,1545154494.451 [DataOverHttps](INFO): Moved sent file to Logs/20181218T171601/Courier0007.lzma.bak
2018-12-18T17:34:54.451Z,1545154494.451 [DataOverHttps](INFO): SBD MOMSN=9084752
2018-12-18T17:35:04.030Z,1545154504.030 [DataOverHttps](INFO): Sending 170 bytes from file Logs/20181218T171601/Express0008.lzma
2018-12-18T17:35:04.827Z,1545154504.827 [DataOverHttps](INFO): Moved sent file to Logs/20181218T171601/Express0008.lzma.bak
2018-12-18T17:35:04.827Z,1545154504.827 [DataOverHttps](INFO): SBD MOMSN=9084755
2018-12-18T17:35:05.280Z,1545154505.280 [Default:CheckIn:Read_Iridium] Stopped
2018-12-18T17:35:05.281Z,1545154505.281 [Default:CheckIn:C.Wait] Running Loop=1
2018-12-18T17:35:05.281Z,1545154505.281 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-12-18T17:37:18.463Z,1545154638.463 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = 1001260.978123
2018-12-18T17:37:18.463Z,1545154638.463 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 7
2018-12-18T17:37:18.463Z,1545154638.463 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-12-18T17:37:18.512Z,1545154638.512 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-12-18T17:37:18.905Z,1545154638.905 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-12-18T17:37:18.905Z,1545154638.905 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 7
2018-12-18T17:37:19.269Z,1545154639.269 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-12-18T17:37:19.269Z,1545154639.269 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-12-18T17:37:19.269Z,1545154639.270 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-12-18T17:37:36.815Z,1545154656.815 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-12-18T17:37:36.815Z,1545154656.815 [NAL9602] Data Fault, FailCount= 2
2018-12-18T17:37:36.815Z,1545154656.815 [NAL9602](ERROR): Data Fault
2018-12-18T17:37:36.903Z,1545154656.903 [CBIT](ERROR): Data Fault in component: NAL9602
2018-12-18T17:37:37.214Z,1545154657.214 [NAL9602](INFO): Powering down
2018-12-18T17:37:38.075Z,1545154658.075 [CBIT](INFO): Clearing failed state for component NAL9602
2018-12-18T17:37:38.075Z,1545154658.075 [NAL9602] No Fault, FailCount= 2
2018-12-18T17:38:10.542Z,1545154690.542 [NAL9602](INFO): Powering up NAL9602
2018-12-18T17:38:21.422Z,1545154701.422 [NAL9602](INFO): NAL9602 initialized
2018-12-18T17:40:05.860Z,1545154805.860 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-12-18T17:40:05.860Z,1545154805.860 [Default:CheckIn:C.Wait] Stopped
2018-12-18T17:40:05.860Z,1545154805.860 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-12-18T17:40:05.860Z,1545154805.860 [Default:CheckIn:D] Running Loop=1
2018-12-18T17:40:06.259Z,1545154806.259 [Default:CheckIn:D] Stopped
2018-12-18T17:40:06.259Z,1545154806.259 [Default:CheckIn:E] Running Loop=1
2018-12-18T17:40:06.669Z,1545154806.669 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.793577 min 
2018-12-18T17:40:06.669Z,1545154806.669 [Default:CheckIn:E] Stopped
2018-12-18T17:40:06.669Z,1545154806.669 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-12-18T17:40:06.669Z,1545154806.669 [Default:CheckIn] Stopped
2018-12-18T17:40:06.669Z,1545154806.669 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-12-18T17:40:06.670Z,1545154806.670 [Default:CheckIn](INFO): Running loop #3
2018-12-18T17:40:06.670Z,1545154806.670 [Default:CheckIn] Running Loop=3
2018-12-18T17:40:06.670Z,1545154806.670 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-12-18T17:40:06.670Z,1545154806.670 [Default:CheckIn:Read_GPS] Running Loop=1
2018-12-18T17:40:19.463Z,1545154819.463 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = 1001441.978456
2018-12-18T17:40:19.464Z,1545154819.464 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 8
2018-12-18T17:40:19.464Z,1545154819.464 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-12-18T17:40:19.476Z,1545154819.476 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-12-18T17:40:19.894Z,1545154819.894 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-12-18T17:40:19.894Z,1545154819.894 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 8
2018-12-18T17:40:20.271Z,1545154820.271 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-12-18T17:40:20.271Z,1545154820.271 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-12-18T17:40:20.272Z,1545154820.272 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-12-18T17:41:41.120Z,1545154901.120 [CommandLine](IMPORTANT): got command ibit
2018-12-18T17:41:41.485Z,1545154901.485 [IBIT](IMPORTANT): Beginning Initiated BIT
2018-12-18T17:41:41.485Z,1545154901.485 [IBIT](IMPORTANT): Beginning control surface checks.
2018-12-18T17:41:41.488Z,1545154901.488 [CBIT](IMPORTANT): Beginning ground fault scan
2018-12-18T17:41:52.672Z,1545154912.672 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.012834
CHAN A1 (24V): -0.016016
CHAN A2 (12V): -0.002070
CHAN A3 (5V): -0.001468
CHAN B0 (3.3V): 0.000258
CHAN B1 (3.15aV): -0.000196
CHAN B2 (3.15bV): 0.000017
CHAN B3 (GND): 0.000115
OPEN: -0.000588
Full Scale Calc: 4.765 mA, -1.589 mA
2018-12-18T17:42:27.859Z,1545154947.859 [NAL9602](INFO): GPS fix at 20181218T174226: (36.802355, -121.787523)
2018-12-18T17:42:31.054Z,1545154951.054 [NAL9602](INFO): GPS fix at 20181218T174229: (36.802348, -121.787493)
2018-12-18T17:42:33.854Z,1545154953.854 [NAL9602](INFO): GPS fix at 20181218T174232: (36.802344, -121.787468)
2018-12-18T17:42:37.054Z,1545154957.054 [NAL9602](INFO): GPS fix at 20181218T174235: (36.802329, -121.787418)
2018-12-18T17:42:39.854Z,1545154959.854 [NAL9602](INFO): GPS fix at 20181218T174238: (36.802341, -121.787380)
2018-12-18T17:42:43.054Z,1545154963.054 [NAL9602](INFO): GPS fix at 20181218T174241: (36.802348, -121.787357)
2018-12-18T17:42:45.854Z,1545154965.854 [NAL9602](INFO): GPS fix at 20181218T174244: (36.802348, -121.787340)
2018-12-18T17:42:49.054Z,1545154969.054 [NAL9602](INFO): GPS fix at 20181218T174247: (36.802354, -121.787323)
2018-12-18T17:42:51.855Z,1545154971.855 [NAL9602](INFO): GPS fix at 20181218T174250: (36.802335, -121.787305)
2018-12-18T17:42:55.057Z,1545154975.057 [NAL9602](INFO): GPS fix at 20181218T174253: (36.802312, -121.787286)
2018-12-18T17:42:57.854Z,1545154977.854 [NAL9602](INFO): GPS fix at 20181218T174256: (36.802300, -121.787253)
2018-12-18T17:43:01.054Z,1545154981.054 [NAL9602](INFO): GPS fix at 20181218T174259: (36.802304, -121.787210)
2018-12-18T17:43:03.861Z,1545154983.861 [NAL9602](INFO): GPS fix at 20181218T174302: (36.802323, -121.787179)
2018-12-18T17:43:07.054Z,1545154987.054 [NAL9602](INFO): GPS fix at 20181218T174305: (36.802326, -121.787162)
2018-12-18T17:43:12.042Z,1545154992.042 [NAL9602](INFO): GPS fix at 20181218T174310: (36.802343, -121.787148)
2018-12-18T17:43:14.834Z,1545154994.834 [NAL9602](INFO): GPS fix at 20181218T174312: (36.802354, -121.787132)
2018-12-18T17:43:18.034Z,1545154998.034 [NAL9602](INFO): GPS fix at 20181218T174316: (36.802372, -121.787116)
2018-12-18T17:43:20.834Z,1545155000.834 [NAL9602](INFO): GPS fix at 20181218T174318: (36.802373, -121.787097)
2018-12-18T17:43:24.034Z,1545155004.034 [NAL9602](INFO): GPS fix at 20181218T174322: (36.802387, -121.787084)
2018-12-18T17:43:26.834Z,1545155006.834 [NAL9602](INFO): GPS fix at 20181218T174324: (36.802391, -121.787073)
2018-12-18T17:43:30.034Z,1545155010.034 [NAL9602](INFO): GPS fix at 20181218T174328: (36.802395, -121.787048)
2018-12-18T17:43:32.834Z,1545155012.834 [NAL9602](INFO): GPS fix at 20181218T174330: (36.802400, -121.787036)
2018-12-18T17:43:32.903Z,1545155012.903 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2018-12-18T17:43:33.296Z,1545155013.296 [IBIT](FAULT): Warning: Battery Data not active. Expected only when running primaries. Threshold checking not active.
2018-12-18T17:43:33.687Z,1545155013.687 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2018-12-18T17:43:33.687Z,1545155013.687 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2018-12-18T17:43:33.688Z,1545155013.688 [IBIT](IMPORTANT): Pressure:10.015011 PSI
2018-12-18T17:43:33.688Z,1545155013.688 [IBIT](IMPORTANT): Humidity:15.901598 %
2018-12-18T17:43:34.101Z,1545155014.101 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2018-12-18T17:43:34.101Z,1545155014.101 [IBIT](IMPORTANT): buoyancyNeutral: 213.000000 cc
2018-12-18T17:43:34.101Z,1545155014.101 [IBIT](IMPORTANT): massDefault: 0.400000 cm
2018-12-18T17:43:34.102Z,1545155014.102 [IBIT](IMPORTANT): stopDepth: 205.000000 m
2018-12-18T17:43:34.102Z,1545155014.102 [IBIT](IMPORTANT): abortDepth: 250.000000 m
2018-12-18T17:43:34.102Z,1545155014.102 [IBIT](IMPORTANT): IBIT FAILED
2018-12-18T17:43:34.469Z,1545155014.469 [Default:CheckIn:Read_GPS] Stopped
2018-12-18T17:43:34.469Z,1545155014.469 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-12-18T17:43:39.454Z,1545155019.454 [DataOverHttps](INFO): Sending 211 bytes from file Logs/20181218T171601/Courier0010.lzma
2018-12-18T17:43:40.248Z,1545155020.248 [DataOverHttps](INFO): Moved sent file to Logs/20181218T171601/Courier0010.lzma.bak
2018-12-18T17:43:40.248Z,1545155020.248 [DataOverHttps](INFO): SBD MOMSN=9085060
2018-12-18T17:43:50.339Z,1545155030.339 [DataOverHttps](INFO): Sending 815 bytes from file Logs/20181218T171601/Express0011.lzma
2018-12-18T17:43:51.135Z,1545155031.135 [DataOverHttps](INFO): Moved sent file to Logs/20181218T171601/Express0011.lzma.bak
2018-12-18T17:43:51.135Z,1545155031.135 [DataOverHttps](INFO): SBD MOMSN=9085063
2018-12-18T17:43:51.588Z,1545155031.588 [Default:CheckIn:Read_Iridium] Stopped
2018-12-18T17:43:51.588Z,1545155031.588 [Default:CheckIn:C.Wait] Running Loop=1
2018-12-18T17:43:51.588Z,1545155031.588 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-12-18T17:44:03.636Z,1545155043.636 [CommandLine](IMPORTANT): got command ibit
2018-12-18T17:44:03.699Z,1545155043.699 [IBIT](IMPORTANT): Beginning Initiated BIT
2018-12-18T17:44:03.699Z,1545155043.699 [IBIT](IMPORTANT): Beginning control surface checks.
2018-12-18T17:44:03.707Z,1545155043.707 [CBIT](IMPORTANT): Beginning ground fault scan
2018-12-18T17:44:05.226Z,1545155045.226 [NAL9602](INFO): GPS fix at 20181218T174403: (36.802616, -121.786889)
2018-12-18T17:44:08.023Z,1545155048.023 [NAL9602](INFO): GPS fix at 20181218T174406: (36.802640, -121.786872)
2018-12-18T17:44:10.820Z,1545155050.820 [NAL9602](INFO): GPS fix at 20181218T174408: (36.802652, -121.786869)
2018-12-18T17:44:14.022Z,1545155054.022 [NAL9602](INFO): GPS fix at 20181218T174412: (36.802671, -121.786895)
2018-12-18T17:44:14.560Z,1545155054.560 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.012287
CHAN A1 (24V): -0.016134
CHAN A2 (12V): -0.001809
CHAN A3 (5V): -0.001769
CHAN B0 (3.3V): -0.000231
CHAN B1 (3.15aV): -0.000632
CHAN B2 (3.15bV): 0.000086
CHAN B3 (GND): -0.000215
OPEN: -0.000520
Full Scale Calc: 4.765 mA, -1.589 mA
2018-12-18T17:44:16.822Z,1545155056.822 [NAL9602](INFO): GPS fix at 20181218T174414: (36.802684, -121.786910)
2018-12-18T17:44:20.022Z,1545155060.022 [NAL9602](INFO): GPS fix at 20181218T174418: (36.802696, -121.786910)
2018-12-18T17:44:22.822Z,1545155062.822 [NAL9602](INFO): GPS fix at 20181218T174420: (36.802708, -121.786910)
2018-12-18T17:44:26.026Z,1545155066.026 [NAL9602](INFO): GPS fix at 20181218T174424: (36.802714, -121.786910)
2018-12-18T17:44:28.822Z,1545155068.822 [NAL9602](INFO): GPS fix at 20181218T174426: (36.802717, -121.786920)
2018-12-18T17:44:32.022Z,1545155072.022 [NAL9602](INFO): GPS fix at 20181218T174430: (36.802715, -121.786915)
2018-12-18T17:44:34.822Z,1545155074.822 [NAL9602](INFO): GPS fix at 20181218T174432: (36.802717, -121.786913)
2018-12-18T17:44:38.026Z,1545155078.026 [NAL9602](INFO): GPS fix at 20181218T174436: (36.802726, -121.786919)
2018-12-18T17:44:40.822Z,1545155080.822 [NAL9602](INFO): GPS fix at 20181218T174438: (36.802732, -121.786918)
2018-12-18T17:44:44.022Z,1545155084.022 [NAL9602](INFO): GPS fix at 20181218T174442: (36.802737, -121.786919)
2018-12-18T17:44:46.822Z,1545155086.822 [NAL9602](INFO): GPS fix at 20181218T174444: (36.802735, -121.786919)
2018-12-18T17:44:50.022Z,1545155090.022 [NAL9602](INFO): GPS fix at 20181218T174448: (36.802737, -121.786919)
2018-12-18T17:44:55.326Z,1545155095.326 [NAL9602](INFO): GPS fix at 20181218T174453: (36.802749, -121.786915)
2018-12-18T17:44:58.070Z,1545155098.070 [NAL9602](INFO): GPS fix at 20181218T174456: (36.802750, -121.786918)
2018-12-18T17:45:00.870Z,1545155100.870 [NAL9602](INFO): GPS fix at 20181218T174459: (36.802751, -121.786922)
2018-12-18T17:45:04.070Z,1545155104.070 [NAL9602](INFO): GPS fix at 20181218T174502: (36.802755, -121.786920)
2018-12-18T17:45:06.874Z,1545155106.874 [NAL9602](INFO): GPS fix at 20181218T174505: (36.802757, -121.786925)
2018-12-18T17:45:10.071Z,1545155110.071 [NAL9602](INFO): GPS fix at 20181218T174508: (36.802753, -121.786930)
2018-12-18T17:45:12.870Z,1545155112.870 [NAL9602](INFO): GPS fix at 20181218T174511: (36.802750, -121.786925)
2018-12-18T17:45:16.070Z,1545155116.070 [NAL9602](INFO): GPS fix at 20181218T174514: (36.802743, -121.786919)
2018-12-18T17:45:18.870Z,1545155118.870 [NAL9602](INFO): GPS fix at 20181218T174516: (36.802743, -121.786919)
2018-12-18T17:45:22.070Z,1545155122.070 [NAL9602](INFO): GPS fix at 20181218T174520: (36.802741, -121.786921)
2018-12-18T17:45:24.873Z,1545155124.873 [NAL9602](INFO): GPS fix at 20181218T174523: (36.802742, -121.786920)
2018-12-18T17:45:28.070Z,1545155128.070 [NAL9602](INFO): GPS fix at 20181218T174526: (36.802740, -121.786923)
2018-12-18T17:45:30.868Z,1545155130.868 [NAL9602](INFO): GPS fix at 20181218T174528: (36.802739, -121.786919)
2018-12-18T17:45:34.070Z,1545155134.070 [NAL9602](INFO): GPS fix at 20181218T174532: (36.802737, -121.786918)
2018-12-18T17:45:36.870Z,1545155136.870 [NAL9602](INFO): GPS fix at 20181218T174534: (36.802737, -121.786918)
2018-12-18T17:45:40.070Z,1545155140.070 [NAL9602](INFO): GPS fix at 20181218T174538: (36.802738, -121.786919)
2018-12-18T17:45:42.871Z,1545155142.871 [NAL9602](INFO): GPS fix at 20181218T174540: (36.802738, -121.786919)
2018-12-18T17:45:46.078Z,1545155146.078 [NAL9602](INFO): GPS fix at 20181218T174544: (36.802738, -121.786918)
2018-12-18T17:45:48.870Z,1545155148.870 [NAL9602](INFO): GPS fix at 20181218T174546: (36.802737, -121.786919)
2018-12-18T17:45:52.070Z,1545155152.070 [NAL9602](INFO): GPS fix at 20181218T174550: (36.802737, -121.786921)
2018-12-18T17:45:55.431Z,1545155155.431 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2018-12-18T17:45:55.552Z,1545155155.552 [IBIT](FAULT): Warning: Battery Data not active. Expected only when running primaries. Threshold checking not active.
2018-12-18T17:45:55.901Z,1545155155.901 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2018-12-18T17:45:55.901Z,1545155155.901 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2018-12-18T17:45:55.902Z,1545155155.902 [IBIT](IMPORTANT): Pressure:9.871243 PSI
2018-12-18T17:45:55.902Z,1545155155.902 [IBIT](IMPORTANT): Humidity:15.901598 %
2018-12-18T17:45:56.315Z,1545155156.315 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2018-12-18T17:45:56.316Z,1545155156.316 [IBIT](IMPORTANT): buoyancyNeutral: 213.000000 cc
2018-12-18T17:45:56.316Z,1545155156.316 [IBIT](IMPORTANT): massDefault: 0.400000 cm
2018-12-18T17:45:56.316Z,1545155156.316 [IBIT](IMPORTANT): stopDepth: 205.000000 m
2018-12-18T17:45:56.317Z,1545155156.317 [IBIT](IMPORTANT): abortDepth: 250.000000 m
2018-12-18T17:45:56.317Z,1545155156.317 [IBIT](IMPORTANT): IBIT FAILED
2018-12-18T17:46:05.243Z,1545155165.243 [CommandLine](IMPORTANT): got command failComponent
2018-12-18T17:46:05.243Z,1545155165.243 [CommandLine](IMPORTANT): Failed components:
2018-12-18T17:46:05.243Z,1545155165.243 [CommandLine](IMPORTANT): No failed Components.
2018-12-18T17:46:23.151Z,1545155183.151 [CommandLine](IMPORTANT): got command failComponent hardware NAL9602
2018-12-18T17:46:23.151Z,1545155183.151 [NAL9602] Hardware Fault, FailCount= 3
2018-12-18T17:46:23.151Z,1545155183.151 [NAL9602](ERROR): Hardware Fault
2018-12-18T17:46:23.152Z,1545155183.152 [CommandLine](IMPORTANT): NAL9602 failureMode is Hardware Fault
2018-12-18T17:46:23.454Z,1545155183.454 [NAL9602](INFO): Powering down
2018-12-18T17:46:23.525Z,1545155183.525 [CBIT](ERROR): Hardware Fault in component: NAL9602
2018-12-18T17:46:24.317Z,1545155184.317 [CBIT](INFO): Clearing failed state for component NAL9602
2018-12-18T17:46:24.317Z,1545155184.317 [NAL9602] No Fault, FailCount= 3
2018-12-18T17:46:33.729Z,1545155193.729 [CommandLine](IMPORTANT): got command failComponent
2018-12-18T17:46:33.729Z,1545155193.729 [CommandLine](IMPORTANT): Failed components:
2018-12-18T17:46:33.729Z,1545155193.729 [CommandLine](IMPORTANT): No failed Components.
2018-12-18T17:46:36.924Z,1545155196.924 [CommandLine](IMPORTANT): got command ibit
2018-12-18T17:46:37.091Z,1545155197.091 [IBIT](IMPORTANT): Beginning Initiated BIT
2018-12-18T17:46:37.091Z,1545155197.091 [IBIT](IMPORTANT): Beginning control surface checks.
2018-12-18T17:46:37.094Z,1545155197.094 [CBIT](IMPORTANT): Beginning ground fault scan
2018-12-18T17:46:47.910Z,1545155207.910 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.012613
CHAN A1 (24V): -0.016309
CHAN A2 (12V): 4.697929
CHAN A3 (5V): -0.001406
CHAN B0 (3.3V): 0.000287
CHAN B1 (3.15aV): -0.000478
CHAN B2 (3.15bV): -0.000151
CHAN B3 (GND): -0.000156
OPEN: -0.000665
Full Scale Calc: 4.765 mA, -1.589 mA
2018-12-18T17:46:55.439Z,1545155215.439 [NAL9602](INFO): Powering up NAL9602
2018-12-18T17:47:06.342Z,1545155226.342 [NAL9602](INFO): NAL9602 initialized
2018-12-18T17:47:33.146Z,1545155253.146 [NAL9602](INFO): GPS fix at 20181218T174731: (36.802742, -121.786912)
2018-12-18T17:47:35.946Z,1545155255.946 [NAL9602](INFO): GPS fix at 20181218T174734: (36.802743, -121.786908)
2018-12-18T17:47:39.154Z,1545155259.154 [NAL9602](INFO): GPS fix at 20181218T174737: (36.802740, -121.786909)
2018-12-18T17:47:41.946Z,1545155261.946 [NAL9602](INFO): GPS fix at 20181218T174740: (36.802740, -121.786907)
2018-12-18T17:47:45.146Z,1545155265.146 [NAL9602](INFO): GPS fix at 20181218T174743: (36.802739, -121.786909)
2018-12-18T17:47:47.946Z,1545155267.946 [NAL9602](INFO): GPS fix at 20181218T174746: (36.802736, -121.786910)
2018-12-18T17:47:51.146Z,1545155271.146 [NAL9602](INFO): GPS fix at 20181218T174749: (36.802734, -121.786909)
2018-12-18T17:47:56.382Z,1545155276.382 [NAL9602](INFO): GPS fix at 20181218T174754: (36.802733, -121.786909)
2018-12-18T17:47:59.170Z,1545155279.170 [NAL9602](INFO): GPS fix at 20181218T174757: (36.802735, -121.786911)
2018-12-18T17:48:01.970Z,1545155281.970 [NAL9602](INFO): GPS fix at 20181218T174800: (36.802737, -121.786915)
2018-12-18T17:48:05.042Z,1545155285.042 [CommandLine](IMPORTANT): got command show variable NAL9602
2018-12-18T17:48:05.092Z,1545155285.092 [CommandLine](IMPORTANT): NAL9602.loadAtStartup (bool)
2018-12-18T17:48:05.092Z,1545155285.092 [CommandLine](IMPORTANT): NAL9602.simulateHardware (bool)
2018-12-18T17:48:05.092Z,1545155285.092 [CommandLine](IMPORTANT): NAL9602.gpsFailTimeout (minute)
2018-12-18T17:48:05.093Z,1545155285.093 [CommandLine](IMPORTANT): NAL9602.iridiumMTQueueTimeout (minute)
2018-12-18T17:48:05.093Z,1545155285.093 [CommandLine](IMPORTANT): NAL9602.power (watt)
2018-12-18T17:48:05.094Z,1545155285.094 [CommandLine](IMPORTANT): NAL9602.power_platform_communications (watt)
2018-12-18T17:48:05.094Z,1545155285.094 [CommandLine](IMPORTANT): NAL9602.requestGGA (bool)
2018-12-18T17:48:05.094Z,1545155285.094 [CommandLine](IMPORTANT): NAL9602.fastGPSFix (bool)
2018-12-18T17:48:05.102Z,1545155285.102 [CommandLine](IMPORTANT): NAL9602.loadControl (none)
2018-12-18T17:48:05.102Z,1545155285.102 [CommandLine](IMPORTANT): NAL9602.uart (none)
2018-12-18T17:48:05.103Z,1545155285.103 [CommandLine](IMPORTANT): NAL9602.baud (bit_per_second)
2018-12-18T17:48:05.170Z,1545155285.170 [NAL9602](INFO): GPS fix at 20181218T174803: (36.802737, -121.786918)
2018-12-18T17:48:05.270Z,1545155285.270 [CommandLine](IMPORTANT): NAL9602.SNRSatellite_0 (count)
2018-12-18T17:48:05.271Z,1545155285.271 [CommandLine](IMPORTANT): NAL9602.SNRSatellite_1 (count)
2018-12-18T17:48:05.271Z,1545155285.271 [CommandLine](IMPORTANT): NAL9602.SNRSatellite_2 (count)
2018-12-18T17:48:05.271Z,1545155285.271 [CommandLine](IMPORTANT): NAL9602.SNRSatellite_3 (count)
2018-12-18T17:48:05.271Z,1545155285.272 [CommandLine](IMPORTANT): NAL9602.SNRSatellite_4 (count)
2018-12-18T17:48:05.272Z,1545155285.272 [CommandLine](IMPORTANT): NAL9602.SNRSatellite_5 (count)
2018-12-18T17:48:05.272Z,1545155285.272 [CommandLine](IMPORTANT): NAL9602.SNRSatellite_6 (count)
2018-12-18T17:48:05.272Z,1545155285.272 [CommandLine](IMPORTANT): NAL9602.SNRSatellite_7 (count)
2018-12-18T17:48:05.289Z,1545155285.289 [CommandLine](IMPORTANT): NAL9602.SNRSatellite_8 (count)
2018-12-18T17:48:05.289Z,1545155285.289 [CommandLine](IMPORTANT): NAL9602.SNRSatellite_9 (count)
2018-12-18T17:48:05.290Z,1545155285.290 [CommandLine](IMPORTANT): NAL9602.SNRSatellite_10 (count)
2018-12-18T17:48:05.290Z,1545155285.290 [CommandLine](IMPORTANT): NAL9602.SNRSatellite_11 (count)
2018-12-18T17:48:05.290Z,1545155285.290 [CommandLine](IMPORTANT): NAL9602.goodFix (bool)
2018-12-18T17:48:05.291Z,1545155285.291 [CommandLine](IMPORTANT): NAL9602.numSatellites (count)
2018-12-18T17:48:05.291Z,1545155285.291 [CommandLine](IMPORTANT): NAL9602.sigQuality (count)
2018-12-18T17:48:05.291Z,1545155285.291 [CommandLine](IMPORTANT): NAL9602.SOG (knot)
2018-12-18T17:48:05.292Z,1545155285.292 [CommandLine](IMPORTANT): NAL9602.COG (degree)
2018-12-18T17:48:05.292Z,1545155285.292 [CommandLine](IMPORTANT): NAL9602.time_fix (second)
2018-12-18T17:48:05.292Z,1545155285.292 [CommandLine](IMPORTANT): NAL9602.latitude_fix (degree)
2018-12-18T17:48:05.312Z,1545155285.312 [CommandLine](IMPORTANT): NAL9602.longitude_fix (degree)
2018-12-18T17:48:05.314Z,1545155285.314 [CommandLine](IMPORTANT): NAL9602.location_fix (degree)
2018-12-18T17:48:05.315Z,1545155285.315 [CommandLine](IMPORTANT): NAL9602.platform_communications (bool)
2018-12-18T17:48:05.362Z,1545155285.362 [CommandLine](IMPORTANT): NAL9602.durationOfLastRun (second)
2018-12-18T17:48:05.376Z,1545155285.376 [CommandLine](IMPORTANT): NAL9602.component_voltage (volt)
2018-12-18T17:48:05.376Z,1545155285.376 [CommandLine](IMPORTANT): NAL9602.component_avgVoltage (volt)
2018-12-18T17:48:05.381Z,1545155285.381 [CommandLine](IMPORTANT): NAL9602.component_current (milliampere)
2018-12-18T17:48:05.381Z,1545155285.381 [CommandLine](IMPORTANT): NAL9602.component_avgCurrent (milliampere)
2018-12-18T17:48:07.970Z,1545155287.970 [NAL9602](INFO): GPS fix at 20181218T174806: (36.802736, -121.786919)
2018-12-18T17:48:11.178Z,1545155291.178 [NAL9602](INFO): GPS fix at 20181218T174809: (36.802735, -121.786918)
2018-12-18T17:48:13.974Z,1545155293.974 [NAL9602](INFO): GPS fix at 20181218T174812: (36.802734, -121.786918)
2018-12-18T17:48:17.170Z,1545155297.170 [NAL9602](INFO): GPS fix at 20181218T174815: (36.802733, -121.786918)
2018-12-18T17:48:19.441Z,1545155299.441 [CommandLine](IMPORTANT): got command get NAL9602.sigQuality
2018-12-18T17:48:19.441Z,1545155299.441 [CommandLine](IMPORTANT): NAL9602.sigQuality 0 count
2018-12-18T17:48:19.978Z,1545155299.978 [NAL9602](INFO): GPS fix at 20181218T174818: (36.802733, -121.786917)
2018-12-18T17:48:23.170Z,1545155303.170 [NAL9602](INFO): GPS fix at 20181218T174821: (36.802732, -121.786918)
2018-12-18T17:48:25.974Z,1545155305.974 [NAL9602](INFO): GPS fix at 20181218T174824: (36.802732, -121.786919)
2018-12-18T17:48:28.029Z,1545155308.029 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2018-12-18T17:48:28.412Z,1545155308.412 [IBIT](FAULT): Warning: Battery Data not active. Expected only when running primaries. Threshold checking not active.
2018-12-18T17:48:28.822Z,1545155308.822 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2018-12-18T17:48:28.822Z,1545155308.822 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2018-12-18T17:48:28.823Z,1545155308.823 [IBIT](IMPORTANT): Pressure:9.969259 PSI
2018-12-18T17:48:28.823Z,1545155308.823 [IBIT](IMPORTANT): Humidity:15.901598 %
2018-12-18T17:48:29.170Z,1545155309.170 [NAL9602](INFO): GPS fix at 20181218T174827: (36.802733, -121.786920)
2018-12-18T17:48:29.250Z,1545155309.250 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2018-12-18T17:48:29.250Z,1545155309.250 [IBIT](IMPORTANT): buoyancyNeutral: 213.000000 cc
2018-12-18T17:48:29.250Z,1545155309.250 [IBIT](IMPORTANT): massDefault: 0.400000 cm
2018-12-18T17:48:29.251Z,1545155309.251 [IBIT](IMPORTANT): stopDepth: 205.000000 m
2018-12-18T17:48:29.251Z,1545155309.251 [IBIT](IMPORTANT): abortDepth: 250.000000 m
2018-12-18T17:48:29.251Z,1545155309.251 [IBIT](IMPORTANT): IBIT FAILED
2018-12-18T17:48:38.002Z,1545155318.002 [CommandLine](IMPORTANT): got command get NAL9602.sigQuality
2018-12-18T17:48:38.003Z,1545155318.003 [CommandLine](IMPORTANT): NAL9602.sigQuality 0 count
2018-12-18T17:48:52.006Z,1545155332.006 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-12-18T17:48:52.007Z,1545155332.007 [Default:CheckIn:C.Wait] Stopped
2018-12-18T17:48:52.007Z,1545155332.007 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-12-18T17:48:52.007Z,1545155332.007 [Default:CheckIn:D] Running Loop=1
2018-12-18T17:48:52.419Z,1545155332.419 [Default:CheckIn:D] Stopped
2018-12-18T17:48:52.419Z,1545155332.419 [Default:CheckIn:E] Running Loop=1
2018-12-18T17:48:55.588Z,1545155335.588 [CommandLine](IMPORTANT): got command get NAL9602.sigQuality
2018-12-18T17:48:55.588Z,1545155335.588 [CommandLine](IMPORTANT): NAL9602.sigQuality 0 count
2018-12-18T17:48:55.930Z,1545155335.930 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.562905 min 
2018-12-18T17:48:55.931Z,1545155335.931 [Default:CheckIn:E] Stopped
2018-12-18T17:48:55.931Z,1545155335.931 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-12-18T17:48:55.931Z,1545155335.931 [Default:CheckIn] Stopped
2018-12-18T17:48:55.931Z,1545155335.931 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-12-18T17:48:55.931Z,1545155335.931 [Default:CheckIn](INFO): Running loop #4
2018-12-18T17:48:55.931Z,1545155335.931 [Default:CheckIn] Running Loop=4
2018-12-18T17:48:55.931Z,1545155335.931 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-12-18T17:48:55.931Z,1545155335.931 [Default:CheckIn:Read_GPS] Running Loop=1
2018-12-18T17:48:57.569Z,1545155337.569 [NAL9602](INFO): GPS fix at 20181218T174855: (36.802730, -121.786912)
2018-12-18T17:48:57.602Z,1545155337.602 [Default:CheckIn:Read_GPS] Stopped
2018-12-18T17:48:57.602Z,1545155337.602 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-12-18T17:49:00.068Z,1545155340.068 [CommandLine](IMPORTANT): got command get NAL9602.sigQuality
2018-12-18T17:49:00.068Z,1545155340.068 [CommandLine](IMPORTANT): NAL9602.sigQuality 0 count
2018-12-18T17:49:02.131Z,1545155342.131 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20181218T171601/Courier0013.lzma
2018-12-18T17:49:02.931Z,1545155342.931 [DataOverHttps](INFO): Moved sent file to Logs/20181218T171601/Courier0013.lzma.bak
2018-12-18T17:49:02.931Z,1545155342.931 [DataOverHttps](INFO): SBD MOMSN=9085142
2018-12-18T17:49:11.770Z,1545155351.770 [DataOverHttps](INFO): Sending 1340 bytes from file Logs/20181218T171601/Express0014.lzma
2018-12-18T17:49:12.567Z,1545155352.567 [DataOverHttps](INFO): Moved sent file to Logs/20181218T171601/Express0014.lzma.bak
2018-12-18T17:49:12.567Z,1545155352.567 [DataOverHttps](INFO): SBD MOMSN=9085145
2018-12-18T17:49:13.053Z,1545155353.053 [Default:CheckIn:Read_Iridium] Stopped
2018-12-18T17:49:13.053Z,1545155353.053 [Default:CheckIn:C.Wait] Running Loop=1
2018-12-18T17:49:13.053Z,1545155353.053 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-12-18T17:49:22.790Z,1545155362.790 [CommandLine](IMPORTANT): got command get NAL9602.sigQuality
2018-12-18T17:49:22.791Z,1545155362.791 [CommandLine](IMPORTANT): NAL9602.sigQuality 0 count
2018-12-18T17:49:25.996Z,1545155365.996 [CommandLine](IMPORTANT): got command get NAL9602.sigQuality
2018-12-18T17:49:25.997Z,1545155365.997 [CommandLine](IMPORTANT): NAL9602.sigQuality 0 count
2018-12-18T17:49:32.338Z,1545155372.338 [NAL9602](INFO): Powering down
2018-12-18T17:49:41.235Z,1545155381.235 [CommandLine](IMPORTANT): got command get NAL9602.sigQuality
2018-12-18T17:49:41.236Z,1545155381.236 [CommandLine](IMPORTANT): NAL9602.sigQuality 0 count
2018-12-18T17:49:56.711Z,1545155396.711 [CommandLine](IMPORTANT): got command get NAL9602.sigQuality
2018-12-18T17:49:56.711Z,1545155396.711 [CommandLine](IMPORTANT): NAL9602.sigQuality 0 count
2018-12-18T17:50:02.157Z,1545155402.157 [CommandLine](IMPORTANT): got command get NAL9602.sigQuality
2018-12-18T17:50:02.157Z,1545155402.157 [CommandLine](IMPORTANT): NAL9602.sigQuality 0 count
2018-12-18T17:50:11.109Z,1545155411.109 [CommandLine](IMPORTANT): got command get NAL9602.sigQuality
2018-12-18T17:50:11.109Z,1545155411.109 [CommandLine](IMPORTANT): NAL9602.sigQuality 0 count
2018-12-18T17:50:25.513Z,1545155425.513 [CommandLine](IMPORTANT): got command get NAL9602.sigQuality
2018-12-18T17:50:25.517Z,1545155425.517 [CommandLine](IMPORTANT): NAL9602.sigQuality 0 count
2018-12-18T17:50:41.510Z,1545155441.510 [CommandLine](IMPORTANT): got command restart application
2018-12-18T17:50:42.517Z,1545155442.517 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2018-12-18T17:50:42.517Z,1545155442.517 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-12-18T17:50:42.517Z,1545155442.517 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-12-18T17:50:42.681Z,1545155442.681 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2018-12-18T17:50:42.681Z,1545155442.681 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-12-18T17:50:42.682Z,1545155442.682 [CommandLine](INFO): Join timeout helper Thread ID is 998
2018-12-18T17:50:42.682Z,1545155442.682 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-12-18T17:50:42.682Z,1545155442.682 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-12-18T17:50:42.682Z,1545155442.682 [NavChartDb](INFO): Join timeout helper Thread ID is 999
2018-12-18T17:50:42.945Z,1545155442.945 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-12-18T17:50:42.945Z,1545155442.945 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-12-18T17:50:42.961Z,1545155442.961 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2018-12-18T17:50:42.961Z,1545155442.961 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-12-18T17:50:42.961Z,1545155442.961 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1000
2018-12-18T17:50:43.397Z,1545155443.397 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2018-12-18T17:50:43.397Z,1545155443.397 [WetLabsBB2FL](INFO): Powering down
2018-12-18T17:50:43.398Z,1545155443.398 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-12-18T17:50:43.405Z,1545155443.405 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2018-12-18T17:50:43.405Z,1545155443.405 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-12-18T17:50:43.405Z,1545155443.405 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1001
2018-12-18T17:50:43.793Z,1545155443.793 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2018-12-18T17:50:43.794Z,1545155443.794 [CTD_Seabird](INFO): Powering down
2018-12-18T17:50:43.805Z,1545155443.805 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-12-18T17:50:43.821Z,1545155443.821 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2018-12-18T17:50:43.821Z,1545155443.821 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-12-18T17:50:43.822Z,1545155443.822 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 1002
2018-12-18T17:50:43.993Z,1545155443.993 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2018-12-18T17:50:43.993Z,1545155443.993 [CTD_NeilBrown](INFO): Powering down
2018-12-18T17:50:44.005Z,1545155444.005 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-12-18T17:50:44.010Z,1545155444.010 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-12-18T17:50:44.010Z,1545155444.010 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-12-18T17:50:44.010Z,1545155444.010 [Radio_Surface](INFO): Join timeout helper Thread ID is 1003
2018-12-18T17:50:44.329Z,1545155444.329 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-12-18T17:50:44.329Z,1545155444.329 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-12-18T17:50:44.338Z,1545155444.338 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-12-18T17:50:44.338Z,1545155444.338 [logger ThreadHandler](INFO): Thread cancelled.
2018-12-18T17:50:44.338Z,1545155444.338 [logger](INFO): Join timeout helper Thread ID is 1004
2018-12-18T17:50:44.365Z,1545155444.365 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-12-18T17:50:44.365Z,1545155444.365 [logger ThreadHandler](INFO): Thread cancelled.
2018-12-18T17:50:44.381Z,1545155444.381 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-12-18T17:50:44.382Z,1545155444.382 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-12-18T17:50:44.382Z,1545155444.382 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-12-18T17:50:44.382Z,1545155444.382 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-12-18T17:50:44.382Z,1545155444.382 [controlThread](INFO): Join timeout helper Thread ID is 1005
2018-12-18T17:50:44.697Z,1545155444.697 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-12-18T17:50:44.697Z,1545155444.697 [controlThread](DEBUG): Uninitializing ControlThread
2018-12-18T17:50:44.698Z,1545155444.698 [NAL9602](INFO): Powering down
2018-12-18T17:50:44.699Z,1545155444.699 [PNI_TCM](INFO): Powering down
2018-12-18T17:50:44.786Z,1545155444.786 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2018-12-18T17:50:44.787Z,1545155444.787 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2018-12-18T17:50:44.787Z,1545155444.787 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-12-18T17:50:44.787Z,1545155444.787 [MissionManager](INFO): Uninitializing Mission Default
2018-12-18T17:50:44.788Z,1545155444.788 [Default] Stopped
2018-12-18T17:50:44.788Z,1545155444.788 [Default](DEBUG): Aggregate::uninitialize Default
2018-12-18T17:50:44.788Z,1545155444.788 [Default:B.GoToSurface] Stopped
2018-12-18T17:50:44.788Z,1545155444.788 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-12-18T17:50:44.788Z,1545155444.788 [Default:CheckIn] Stopped
2018-12-18T17:50:44.788Z,1545155444.788 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-12-18T17:50:44.788Z,1545155444.788 [Default:CheckIn:C.Wait] Stopped
2018-12-18T17:50:44.788Z,1545155444.788 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-12-18T17:50:44.791Z,1545155444.791 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-12-18T17:50:44.791Z,1545155444.791 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-12-18T17:50:44.792Z,1545155444.792 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-12-18T17:50:44.792Z,1545155444.792 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-12-18T17:50:44.792Z,1545155444.792 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-12-18T17:50:44.792Z,1545155444.792 [BuoyancyServo](INFO): Powering down
2018-12-18T17:50:44.805Z,1545155444.805 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-12-18T17:50:44.805Z,1545155444.805 [ElevatorServo](INFO): Powering down
2018-12-18T17:50:44.806Z,1545155444.806 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-12-18T17:50:44.806Z,1545155444.806 [MassServo](INFO): Powering down
2018-12-18T17:50:44.807Z,1545155444.807 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-12-18T17:50:44.807Z,1545155444.807 [RudderServo](INFO): Powering down
2018-12-18T17:50:44.808Z,1545155444.808 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-12-18T17:50:44.808Z,1545155444.808 [ThrusterServo](INFO): Powering down
2018-12-18T17:50:44.808Z,1545155444.808 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-12-18T17:50:44.809Z,1545155444.809 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-12-18T17:50:44.809Z,1545155444.809 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-12-18T17:50:44.809Z,1545155444.809 [CBIT](DEBUG): Powering off loads.
2018-12-18T17:50:44.821Z,1545155444.821 [CBIT](DEBUG): Disabling WDT.
2018-12-18T17:50:44.833Z,1545155444.833 [CBIT](DEBUG): Opening all GF detection circuits.
2018-12-18T17:50:44.834Z,1545155444.834 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-12-18T17:50:44.879Z,1545155444.879 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-12-18T17:50:44.918Z,1545155444.918 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-12-18T17:50:44.921Z,1545155444.921 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-12-18T17:50:44.924Z,1545155444.924 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-12-18T17:50:44.950Z,1545155444.950 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-12-18T17:50:45.018Z,1545155445.018 [logger ThreadHandler](INFO): Thread cancelled.