2019-08-07T15:16:39.689Z,1565190999.689 [Supervisor](DEBUG): Initializing supervisor.
2019-08-07T15:16:39.692Z,1565190999.692 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-08-07T15:16:39.693Z,1565190999.693 [SyncHandler](INFO): Protected caller Thread ID is 807
2019-08-07T15:16:39.693Z,1565190999.693 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-08-07T15:16:39.694Z,1565190999.694 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-08-07T15:16:39.694Z,1565190999.694 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 808
2019-08-07T15:16:39.697Z,1565190999.697 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-08-07T15:16:39.709Z,1565190999.709 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-08-07T15:16:39.710Z,1565190999.710 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-08-07T15:16:39.710Z,1565190999.710 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 809
2019-08-07T15:16:39.711Z,1565190999.711 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-08-07T15:16:39.712Z,1565190999.712 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-08-07T15:16:39.712Z,1565190999.712 [logger ThreadHandler](INFO): Protected caller Thread ID is 810
2019-08-07T15:16:39.714Z,1565190999.714 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-08-07T15:16:39.715Z,1565190999.715 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-08-07T15:16:39.719Z,1565190999.719 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-08-07T15:16:39.922Z,1565190999.922 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-08-07T15:16:39.924Z,1565190999.924 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-08-07T15:16:40.005Z,1565191000.005 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-08-07T15:16:40.444Z,1565191000.444 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-08-07T15:16:40.444Z,1565191000.444 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-08-07T15:16:40.782Z,1565191000.782 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-08-07T15:16:40.784Z,1565191000.784 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-08-07T15:16:40.880Z,1565191000.880 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-08-07T15:16:40.882Z,1565191000.882 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-08-07T15:16:41.182Z,1565191001.182 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-08-07T15:16:41.183Z,1565191001.183 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-08-07T15:16:41.379Z,1565191001.379 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-08-07T15:16:41.380Z,1565191001.380 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-08-07T15:16:41.836Z,1565191001.836 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-08-07T15:16:41.837Z,1565191001.837 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-08-07T15:16:41.942Z,1565191001.942 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-08-07T15:16:41.944Z,1565191001.944 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-08-07T15:16:42.045Z,1565191002.045 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-08-07T15:16:42.045Z,1565191002.045 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-08-07T15:16:42.705Z,1565191002.705 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-08-07T15:16:42.705Z,1565191002.705 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-08-07T15:16:43.801Z,1565191003.801 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-08-07T15:16:43.803Z,1565191003.803 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-08-07T15:16:44.000Z,1565191004.000 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-08-07T15:16:44.002Z,1565191004.002 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-08-07T15:16:44.148Z,1565191004.148 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-08-07T15:16:44.149Z,1565191004.149 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-08-07T15:16:44.299Z,1565191004.299 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-08-07T15:16:44.301Z,1565191004.301 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2019-08-07T15:16:44.304Z,1565191004.304 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2019-08-07T15:16:44.395Z,1565191004.395 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2019-08-07T15:16:44.482Z,1565191004.482 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2019-08-07T15:16:44.585Z,1565191004.585 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2019-08-07T15:16:44.669Z,1565191004.669 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2019-08-07T15:16:44.765Z,1565191004.765 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2019-08-07T15:16:44.867Z,1565191004.867 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2019-08-07T15:16:45.083Z,1565191005.083 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2019-08-07T15:16:45.160Z,1565191005.160 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2019-08-07T15:16:45.330Z,1565191005.330 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2019-08-07T15:16:45.467Z,1565191005.467 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2019-08-07T15:16:45.588Z,1565191005.588 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2019-08-07T15:16:45.819Z,1565191005.819 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-08-07T15:16:45.820Z,1565191005.820 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-08-07T15:16:45.835Z,1565191005.835 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-08-07T15:16:45.923Z,1565191005.923 [VerticalControl](DEBUG): Construct VerticalControl.
2019-08-07T15:16:46.036Z,1565191006.036 [VerticalControl] Loaded
2019-08-07T15:16:46.036Z,1565191006.036 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-08-07T15:16:46.037Z,1565191006.037 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-08-07T15:16:46.104Z,1565191006.104 [HorizontalControl] Loaded
2019-08-07T15:16:46.105Z,1565191006.105 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-08-07T15:16:46.105Z,1565191006.105 [SpeedControl](DEBUG): Construct SpeedControl.
2019-08-07T15:16:46.111Z,1565191006.111 [SpeedControl] Loaded
2019-08-07T15:16:46.111Z,1565191006.111 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-08-07T15:16:46.112Z,1565191006.112 [LoopControl](DEBUG): Construct LoopControl.
2019-08-07T15:16:46.113Z,1565191006.113 [LoopControl] Loaded
2019-08-07T15:16:46.113Z,1565191006.113 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-08-07T15:16:46.113Z,1565191006.113 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-08-07T15:16:46.115Z,1565191006.115 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-08-07T15:16:46.141Z,1565191006.141 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-08-07T15:16:46.143Z,1565191006.143 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-08-07T15:16:46.267Z,1565191006.267 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-08-07T15:16:46.268Z,1565191006.268 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-08-07T15:16:46.416Z,1565191006.416 [BuoyancyServo] Loaded
2019-08-07T15:16:46.417Z,1565191006.417 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-08-07T15:16:46.428Z,1565191006.428 [ElevatorServo] Loaded
2019-08-07T15:16:46.428Z,1565191006.428 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-08-07T15:16:46.439Z,1565191006.439 [MassServo] Loaded
2019-08-07T15:16:46.439Z,1565191006.439 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-08-07T15:16:46.450Z,1565191006.450 [RudderServo] Loaded
2019-08-07T15:16:46.451Z,1565191006.451 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-08-07T15:16:46.462Z,1565191006.462 [ThrusterServo] Loaded
2019-08-07T15:16:46.462Z,1565191006.462 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-08-07T15:16:46.462Z,1565191006.462 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-08-07T15:16:46.463Z,1565191006.463 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-08-07T15:16:46.587Z,1565191006.587 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-08-07T15:16:46.588Z,1565191006.588 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-08-07T15:16:46.609Z,1565191006.609 [NavChart] Loaded
2019-08-07T15:16:46.609Z,1565191006.609 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-08-07T15:16:46.613Z,1565191006.613 [UniversalFixResidualReporter] Loaded
2019-08-07T15:16:46.613Z,1565191006.613 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-08-07T15:16:46.613Z,1565191006.613 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-08-07T15:16:46.614Z,1565191006.614 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-08-07T15:16:46.726Z,1565191006.726 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-08-07T15:16:46.727Z,1565191006.727 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-08-07T15:16:47.405Z,1565191007.405 [AHRS_M2] Loaded
2019-08-07T15:16:47.405Z,1565191007.405 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-08-07T15:16:47.549Z,1565191007.549 [DataOverHttps] Loaded
2019-08-07T15:16:47.549Z,1565191007.549 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-08-07T15:16:47.550Z,1565191007.550 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4087D4E0
2019-08-07T15:16:47.550Z,1565191007.550 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 893
2019-08-07T15:16:47.564Z,1565191007.564 [Depth_Keller] Loaded
2019-08-07T15:16:47.564Z,1565191007.564 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-08-07T15:16:47.569Z,1565191007.569 [DropWeight] Loaded
2019-08-07T15:16:47.569Z,1565191007.569 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-08-07T15:16:47.666Z,1565191007.666 [NAL9602] Loaded
2019-08-07T15:16:47.666Z,1565191007.666 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-08-07T15:16:47.682Z,1565191007.682 [Onboard] Loaded
2019-08-07T15:16:47.682Z,1565191007.682 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-08-07T15:16:47.685Z,1565191007.685 [Radio_Surface] Loaded
2019-08-07T15:16:47.686Z,1565191007.686 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-08-07T15:16:47.687Z,1565191007.687 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408AD4E0
2019-08-07T15:16:47.687Z,1565191007.687 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 894
2019-08-07T15:16:50.144Z,1565191010.144 [BPC1] Loaded
2019-08-07T15:16:50.144Z,1565191010.144 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-08-07T15:16:50.144Z,1565191010.144 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-08-07T15:16:50.145Z,1565191010.145 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-08-07T15:16:50.201Z,1565191010.201 [DepthRateCalculator] Loaded
2019-08-07T15:16:50.201Z,1565191010.201 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-08-07T15:16:50.206Z,1565191010.206 [PitchRateCalculator] Loaded
2019-08-07T15:16:50.206Z,1565191010.206 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-08-07T15:16:50.218Z,1565191010.218 [SpeedCalculator] Loaded
2019-08-07T15:16:50.218Z,1565191010.218 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-08-07T15:16:50.240Z,1565191010.240 [TempGradientCalculator] Loaded
2019-08-07T15:16:50.240Z,1565191010.240 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-08-07T15:16:50.245Z,1565191010.245 [YawRateCalculator] Loaded
2019-08-07T15:16:50.245Z,1565191010.245 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-08-07T15:16:50.274Z,1565191010.274 [ElevatorOffsetCalculator] Loaded
2019-08-07T15:16:50.275Z,1565191010.275 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-08-07T15:16:50.275Z,1565191010.275 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-08-07T15:16:50.276Z,1565191010.276 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-08-07T15:16:50.531Z,1565191010.531 [Aanderaa_O2] Loaded
2019-08-07T15:16:50.532Z,1565191010.532 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2019-08-07T15:16:50.544Z,1565191010.544 [CANONSampler] Loaded
2019-08-07T15:16:50.544Z,1565191010.544 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2019-08-07T15:16:50.628Z,1565191010.628 [CTD_NeilBrown] Loaded
2019-08-07T15:16:50.628Z,1565191010.628 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-08-07T15:16:50.629Z,1565191010.629 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 409AF4E0
2019-08-07T15:16:50.630Z,1565191010.630 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 895
2019-08-07T15:16:50.639Z,1565191010.639 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-08-07T15:16:50.644Z,1565191010.644 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-08-07T15:16:50.646Z,1565191010.646 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-08-07T15:16:50.653Z,1565191010.653 [CTD_Seabird](INFO): created writer for : depth
2019-08-07T15:16:50.654Z,1565191010.654 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-08-07T15:16:50.659Z,1565191010.659 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-08-07T15:16:50.659Z,1565191010.659 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-08-07T15:16:50.664Z,1565191010.664 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-08-07T15:16:50.665Z,1565191010.665 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-08-07T15:16:50.670Z,1565191010.670 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-08-07T15:16:50.671Z,1565191010.671 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-08-07T15:16:50.676Z,1565191010.676 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-08-07T15:16:50.676Z,1565191010.676 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-08-07T15:16:50.681Z,1565191010.681 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-08-07T15:16:50.708Z,1565191010.708 [CTD_Seabird] Loaded
2019-08-07T15:16:50.708Z,1565191010.708 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-08-07T15:16:50.709Z,1565191010.709 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409DF4E0
2019-08-07T15:16:50.709Z,1565191010.709 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 896
2019-08-07T15:16:50.724Z,1565191010.724 [PAR_Licor] Loaded
2019-08-07T15:16:50.724Z,1565191010.724 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-08-07T15:16:50.772Z,1565191010.772 [WetLabsBB2FL] Loaded
2019-08-07T15:16:50.772Z,1565191010.772 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-08-07T15:16:50.773Z,1565191010.773 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A0F4E0
2019-08-07T15:16:50.773Z,1565191010.773 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 897
2019-08-07T15:16:50.774Z,1565191010.774 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-08-07T15:16:50.775Z,1565191010.775 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-08-07T15:16:50.824Z,1565191010.824 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-08-07T15:16:50.825Z,1565191010.825 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-08-07T15:16:51.165Z,1565191011.165 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-08-07T15:16:51.166Z,1565191011.166 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-08-07T15:16:51.328Z,1565191011.328 [SBIT](DEBUG): Construct Startup Built In Test.
2019-08-07T15:16:51.339Z,1565191011.339 [SBIT] Loaded
2019-08-07T15:16:51.339Z,1565191011.339 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-08-07T15:16:51.340Z,1565191011.340 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-08-07T15:16:51.352Z,1565191011.352 [IBIT] Loaded
2019-08-07T15:16:51.352Z,1565191011.352 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-08-07T15:16:51.355Z,1565191011.355 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-08-07T15:16:51.493Z,1565191011.493 [CBIT] Loaded
2019-08-07T15:16:51.493Z,1565191011.493 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-08-07T15:16:51.493Z,1565191011.493 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-08-07T15:16:51.497Z,1565191011.497 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-08-07T15:16:51.498Z,1565191011.498 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-08-07T15:16:51.505Z,1565191011.505 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-08-07T15:16:51.506Z,1565191011.506 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B0E4E0
2019-08-07T15:16:51.507Z,1565191011.507 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 898
2019-08-07T15:16:51.511Z,1565191011.511 [Supervisor](INFO): Main Thread ID is 803
2019-08-07T15:16:51.511Z,1565191011.511 [Supervisor](DEBUG): Running supervisor.
2019-08-07T15:16:51.512Z,1565191011.512 [CommandLine ThreadHandler](INFO): Handler Thread ID is 899
2019-08-07T15:16:51.514Z,1565191011.514 [controlThread ThreadHandler](INFO): Handler Thread ID is 900
2019-08-07T15:16:51.515Z,1565191011.515 [controlThread](DEBUG): Initializing ControlThread
2019-08-07T15:16:51.516Z,1565191011.516 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-08-07T15:16:51.517Z,1565191011.517 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-08-07T15:16:51.518Z,1565191011.518 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-08-07T15:16:51.518Z,1565191011.518 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-08-07T15:16:51.520Z,1565191011.520 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-08-07T15:16:51.520Z,1565191011.520 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-08-07T15:16:51.525Z,1565191011.525 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-08-07T15:16:51.525Z,1565191011.525 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-08-07T15:16:51.525Z,1565191011.525 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-08-07T15:16:51.525Z,1565191011.525 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-08-07T15:16:51.526Z,1565191011.526 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-08-07T15:16:51.526Z,1565191011.526 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-08-07T15:16:51.531Z,1565191011.531 [SBIT](INFO): Initialize SBIT Component.
2019-08-07T15:16:51.531Z,1565191011.531 [SBIT](IMPORTANT): git: 2019-08-07
2019-08-07T15:16:51.531Z,1565191011.531 [SBIT](INFO): git hash: 49f01da6f65cabd29e5588026e609de99f82dc0c
2019-08-07T15:16:51.532Z,1565191011.532 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-08-07T15:16:51.533Z,1565191011.533 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
2019-08-07T15:16:51.534Z,1565191011.534 [SBIT](INFO): Beginning SBIT in 36.000000 seconds.
2019-08-07T15:16:51.535Z,1565191011.535 [IBIT](INFO): Initialize IBIT Component.
2019-08-07T15:16:51.536Z,1565191011.536 [CBIT](DEBUG): Initialize CBIT Component.
2019-08-07T15:16:51.537Z,1565191011.537 [logger ThreadHandler](INFO): Handler Thread ID is 901
2019-08-07T15:16:51.546Z,1565191011.546 [CBIT](DEBUG): Initialized mux pins.
2019-08-07T15:16:51.547Z,1565191011.547 [CBIT](DEBUG): Initializing the watchdog timer.
2019-08-07T15:16:51.555Z,1565191011.555 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 902
2019-08-07T15:16:51.556Z,1565191011.556 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-08-07T15:16:51.567Z,1565191011.567 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 903
2019-08-07T15:16:51.570Z,1565191011.570 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-08-07T15:16:51.571Z,1565191011.571 [CBIT](DEBUG): Initializing heartbeat.
2019-08-07T15:16:51.579Z,1565191011.579 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 904
2019-08-07T15:16:51.580Z,1565191011.580 [CTD_NeilBrown](INFO): Powering down
2019-08-07T15:16:51.599Z,1565191011.599 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 905
2019-08-07T15:16:51.600Z,1565191011.600 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-08-07T15:16:51.607Z,1565191011.607 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-08-07T15:16:51.611Z,1565191011.611 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 907
2019-08-07T15:16:51.612Z,1565191011.612 [WetLabsBB2FL](INFO): Powering down
2019-08-07T15:16:51.641Z,1565191011.641 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 908
2019-08-07T15:16:51.643Z,1565191011.643 [CBIT](DEBUG): Deactivating GF circuits.
2019-08-07T15:16:51.643Z,1565191011.643 [CBIT](DEBUG): Deactivating emergency mode.
2019-08-07T15:16:51.650Z,1565191011.650 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-08-07T15:16:51.651Z,1565191011.651 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-08-07T15:16:51.651Z,1565191011.651 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-08-07T15:16:51.651Z,1565191011.651 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-08-07T15:16:51.651Z,1565191011.651 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-08-07T15:16:51.651Z,1565191011.651 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-08-07T15:16:51.652Z,1565191011.652 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-08-07T15:16:51.652Z,1565191011.652 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-08-07T15:16:51.652Z,1565191011.652 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-08-07T15:16:51.652Z,1565191011.652 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-08-07T15:16:51.652Z,1565191011.652 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-08-07T15:16:51.653Z,1565191011.653 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-08-07T15:16:51.653Z,1565191011.653 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-08-07T15:16:51.653Z,1565191011.653 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-08-07T15:16:51.653Z,1565191011.653 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-08-07T15:16:51.653Z,1565191011.653 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-08-07T15:16:51.678Z,1565191011.678 [CBIT](DEBUG): Backplane powered.
2019-08-07T15:16:51.679Z,1565191011.679 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-08-07T15:16:51.708Z,1565191011.708 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-08-07T15:16:51.743Z,1565191011.743 [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>


2019-08-07T15:16:51.744Z,1565191011.744 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-08-07T15:16:51.812Z,1565191011.812 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-08-07T15:16:51.813Z,1565191011.813 [Default:A.Wait](DEBUG): Construct Wait.
2019-08-07T15:16:51.815Z,1565191011.815 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-08-07T15:16:51.846Z,1565191011.846 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-08-07T15:16:51.873Z,1565191011.873 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-08-07T15:16:51.894Z,1565191011.894 [Default:E.Execute](DEBUG): Construct Execute.
2019-08-07T15:16:51.897Z,1565191011.897 [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>


2019-08-07T15:16:51.902Z,1565191011.902 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,Onboard,BPC1,Aanderaa_O2,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-08-07T15:16:51.919Z,1565191011.919 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-08-07T15:16:51.970Z,1565191011.970 [Radio_Surface](INFO): Powering up
2019-08-07T15:16:52.019Z,1565191012.019 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2019-08-07T15:16:52.072Z,1565191012.072 [CANONSampler](INFO): Powering down
2019-08-07T15:16:52.199Z,1565191012.199 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-08-07T15:16:52.250Z,1565191012.250 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-08-07T15:16:52.259Z,1565191012.259 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-08-07T15:16:52.260Z,1565191012.260 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-08-07T15:16:52.267Z,1565191012.267 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-08-07T15:16:52.268Z,1565191012.268 [MassServo](DEBUG): Initializing EZServoServo.
2019-08-07T15:16:52.275Z,1565191012.275 [MassServo](DEBUG): Initializing MassServo.
2019-08-07T15:16:52.276Z,1565191012.276 [RudderServo](DEBUG): Initializing EZServoServo.
2019-08-07T15:16:52.284Z,1565191012.284 [RudderServo](DEBUG): Initializing RudderServo.
2019-08-07T15:16:52.284Z,1565191012.284 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-08-07T15:16:52.291Z,1565191012.291 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-08-07T15:16:55.351Z,1565191015.351 [Aanderaa_O2](INFO): Powering down
2019-08-07T15:17:17.808Z,1565191037.808 [NAL9602](INFO): Powering up NAL9602
2019-08-07T15:17:27.957Z,1565191047.957 [SBIT](IMPORTANT): Beginning Startup BIT
2019-08-07T15:17:27.965Z,1565191047.965 [CBIT](IMPORTANT): Beginning ground fault scan
2019-08-07T15:17:28.716Z,1565191048.716 [NAL9602](INFO): NAL9602 initialized
2019-08-07T15:17:29.534Z,1565191049.534 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:17:38.989Z,1565191058.989 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.003517
CHAN A1 (24V): -0.133379
CHAN A2 (12V): 4.697929
CHAN A3 (5V): -0.001297
CHAN B0 (3.3V): -0.000074
CHAN B1 (3.15aV): -0.000008
CHAN B2 (3.15bV): -0.000181
CHAN B3 (GND): 0.000580
OPEN: -0.000147
Full Scale Calc: 4.765 mA, -1.589 mA
2019-08-07T15:18:22.031Z,1565191102.031 [SBIT](IMPORTANT): SBIT PASSED
2019-08-07T15:18:22.107Z,1565191102.107 [CommandLine](IMPORTANT): got command configSet list
2019-08-07T15:18:22.108Z,1565191102.108 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-08-07T15:18:22.109Z,1565191102.109 [CommandLine](IMPORTANT): CANONSampler.loadAtStartup=1 bool;

2019-08-07T15:18:22.109Z,1565191102.109 [CommandLine](IMPORTANT): DAT.ignoreElevationAngle=1 bool;

2019-08-07T15:18:22.109Z,1565191102.109 [CommandLine](IMPORTANT): DAT.loadAtStartup=0 bool;

2019-08-07T15:18:22.109Z,1565191102.109 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup=0 bool;

2019-08-07T15:18:22.109Z,1565191102.109 [CommandLine](IMPORTANT): ESPComponent.loadAtStartup=0 bool;

2019-08-07T15:18:22.109Z,1565191102.109 [CommandLine](IMPORTANT): NAL9602.fastGPSFix=1 bool;

2019-08-07T15:18:22.109Z,1565191102.109 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=200 cubic_centimeter;

2019-08-07T15:18:22.109Z,1565191102.109 [CommandLine](IMPORTANT): VerticalControl.massDefault=-4 millimeter;

2019-08-07T15:18:22.109Z,1565191102.109 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitAft=-31 millimeter;

2019-08-07T15:18:22.110Z,1565191102.110 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitFwd=30 millimeter;

2019-08-07T15:18:22.440Z,1565191102.440 [MissionManager](IMPORTANT): Started mission Startup
2019-08-07T15:18:22.440Z,1565191102.440 [Startup] Running Loop=1
2019-08-07T15:18:22.440Z,1565191102.440 [Startup](DEBUG): Aggregate::initialize Startup
2019-08-07T15:18:22.441Z,1565191102.441 [Startup:A.GoToSurface] Running Loop=1
2019-08-07T15:18:22.441Z,1565191102.441 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-08-07T15:18:22.441Z,1565191102.441 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-08-07T15:18:22.442Z,1565191102.442 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-08-07T15:18:22.442Z,1565191102.442 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-08-07T15:18:22.443Z,1565191102.443 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-08-07T15:18:22.443Z,1565191102.443 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-08-07T15:18:22.444Z,1565191102.444 [Startup:StartupSatComms] Running Loop=1
2019-08-07T15:18:22.444Z,1565191102.444 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-08-07T15:18:22.445Z,1565191102.445 [Startup:StartupSatComms:A] Running Loop=1
2019-08-07T15:18:22.841Z,1565191102.841 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-08-07T15:19:16.137Z,1565191156.137 [NAL9602](INFO): SBD MO Status=2, MOMSN=15863, MT Status=2, MTMSN=0
2019-08-07T15:19:16.138Z,1565191156.138 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-07T15:19:19.988Z,1565191159.988 [CommandLine](IMPORTANT): got command failComponent
2019-08-07T15:19:19.988Z,1565191159.988 [CommandLine](IMPORTANT): Failed components:
2019-08-07T15:19:19.989Z,1565191159.989 [CommandLine](IMPORTANT): No failed Components.
2019-08-07T15:19:22.625Z,1565191162.625 [Startup:StartupSatComms:A](INFO): Timed out from 2019-08-07T15:18:22.4Z
2019-08-07T15:19:22.625Z,1565191162.625 [Startup:StartupSatComms:A] Stopped
2019-08-07T15:19:22.625Z,1565191162.625 [Startup:StartupSatComms:B] Running Loop=1
2019-08-07T15:19:23.029Z,1565191163.029 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-08-07T15:19:34.025Z,1565191174.025 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005000
2019-08-07T15:19:38.907Z,1565191178.907 [DataOverHttps](INFO): Sending 795 bytes from file Logs/20190807T151639/Express0001.lzma
2019-08-07T15:19:39.712Z,1565191179.712 [DataOverHttps](INFO): Moved sent file to Logs/20190807T151639/Express0001.lzma.bak
2019-08-07T15:19:39.712Z,1565191179.712 [DataOverHttps](INFO): SBD MOMSN=11534519
2019-08-07T15:19:40.400Z,1565191180.400 [Startup:StartupSatComms:B] Stopped
2019-08-07T15:19:40.401Z,1565191180.401 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-08-07T15:19:40.401Z,1565191180.401 [Startup:StartupSatComms] Stopped
2019-08-07T15:19:40.401Z,1565191180.401 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-08-07T15:19:40.401Z,1565191180.401 [Startup](INFO): Completed Startup
2019-08-07T15:19:40.402Z,1565191180.402 [MissionManager](INFO): Startup is completed.
2019-08-07T15:19:40.402Z,1565191180.402 [MissionManager](INFO): Uninitializing Mission Startup
2019-08-07T15:19:40.402Z,1565191180.402 [Startup] Stopped
2019-08-07T15:19:40.402Z,1565191180.402 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-08-07T15:19:40.402Z,1565191180.402 [Startup:A.GoToSurface] Stopped
2019-08-07T15:19:40.402Z,1565191180.402 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-08-07T15:19:40.804Z,1565191180.804 [MissionManager](IMPORTANT): Started mission Default
2019-08-07T15:19:40.804Z,1565191180.804 [Default] Running Loop=1
2019-08-07T15:19:40.804Z,1565191180.804 [Default](DEBUG): Aggregate::initialize Default
2019-08-07T15:19:40.805Z,1565191180.805 [Default:B.GoToSurface] Running Loop=1
2019-08-07T15:19:40.805Z,1565191180.805 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-08-07T15:19:40.805Z,1565191180.805 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-08-07T15:19:40.805Z,1565191180.805 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-08-07T15:19:40.806Z,1565191180.806 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-08-07T15:19:40.806Z,1565191180.806 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-08-07T15:19:40.806Z,1565191180.806 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-08-07T15:19:40.807Z,1565191180.807 [Default:A.Wait] Running Loop=1
2019-08-07T15:19:40.807Z,1565191180.807 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-08-07T15:19:41.585Z,1565191181.585 [NAL9602](INFO): SBD MO Status=2, MOMSN=15863, MT Status=2, MTMSN=0
2019-08-07T15:19:41.585Z,1565191181.585 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-07T15:19:51.720Z,1565191191.720 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-08-07T15:19:51.720Z,1565191191.720 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-08-07T15:19:51.729Z,1565191191.729 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-08-07T15:19:52.138Z,1565191192.138 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-08-07T15:19:52.138Z,1565191192.138 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-08-07T15:19:54.145Z,1565191194.145 [Default:A.Wait](INFO): Done Waiting.
2019-08-07T15:19:54.145Z,1565191194.145 [Default:A.Wait] Stopped
2019-08-07T15:19:54.145Z,1565191194.145 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-08-07T15:19:54.543Z,1565191194.543 [Default:CheckIn] Running Loop=1
2019-08-07T15:19:54.543Z,1565191194.543 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-07T15:19:54.543Z,1565191194.543 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-07T15:19:54.952Z,1565191194.952 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-08-07T15:20:16.997Z,1565191216.997 [CommandLine](IMPORTANT): got command burn on
2019-08-07T15:20:16.997Z,1565191216.997 [CommandLine](IMPORTANT): Activating dropweight wire
2019-08-07T15:20:20.773Z,1565191220.773 [NAL9602](INFO): SBD MO Status=2, MOMSN=15863, MT Status=2, MTMSN=0
2019-08-07T15:20:20.773Z,1565191220.773 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-07T15:20:27.267Z,1565191227.267 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2019-08-07T15:20:46.229Z,1565191246.229 [NAL9602](INFO): SBD MO Status=2, MOMSN=15863, MT Status=2, MTMSN=0
2019-08-07T15:20:46.229Z,1565191246.229 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-07T15:20:54.323Z,1565191254.323 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file).
2019-08-07T15:21:03.597Z,1565191263.597 [NAL9602](INFO): SBD MO Status=2, MOMSN=15863, MT Status=2, MTMSN=0
2019-08-07T15:21:03.598Z,1565191263.598 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-07T15:21:46.437Z,1565191306.437 [NAL9602](INFO): SBD MO Status=2, MOMSN=15863, MT Status=2, MTMSN=0
2019-08-07T15:21:46.438Z,1565191306.438 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-07T15:22:32.076Z,1565191352.076 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-08-07T15:22:32.890Z,1565191352.890 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:22:33.286Z,1565191353.286 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,152226.00,A,3648.16471,N,12147.28501,W,0.447,348.38,070819,,,A*7B
2019-08-07T15:22:33.289Z,1565191353.289 [NAL9602](INFO): GPS fix at 20190807T152226: (36.802745, -121.788083)
2019-08-07T15:22:33.318Z,1565191353.318 [Default:CheckIn:Read_GPS] Stopped
2019-08-07T15:22:33.319Z,1565191353.319 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-07T15:22:33.735Z,1565191353.735 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-08-07T15:22:41.322Z,1565191361.322 [DataOverHttps](INFO): Sending 214 bytes from file Logs/20190807T151639/Courier0004.lzma
2019-08-07T15:22:42.128Z,1565191362.128 [DataOverHttps](INFO): Moved sent file to Logs/20190807T151639/Courier0004.lzma.bak
2019-08-07T15:22:42.128Z,1565191362.128 [DataOverHttps](INFO): SBD MOMSN=11534545
2019-08-07T15:22:54.832Z,1565191374.832 [CommandLine](IMPORTANT): got command burn off
2019-08-07T15:22:54.832Z,1565191374.832 [CommandLine](IMPORTANT): Deactivating dropweight wire
2019-08-07T15:23:00.626Z,1565191380.626 [DataOverHttps](INFO): Sending 344 bytes from file Logs/20190807T151639/Express0005.lzma
2019-08-07T15:23:01.432Z,1565191381.432 [DataOverHttps](INFO): Moved sent file to Logs/20190807T151639/Express0005.lzma.bak
2019-08-07T15:23:01.432Z,1565191381.432 [DataOverHttps](INFO): SBD MOMSN=11534554
2019-08-07T15:23:02.027Z,1565191382.027 [Default:CheckIn:Read_Iridium] Stopped
2019-08-07T15:23:02.027Z,1565191382.027 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-07T15:23:02.027Z,1565191382.027 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-07T15:23:05.207Z,1565191385.207 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-07T15:25:23.626Z,1565191523.626 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2019-08-07T15:25:23.629Z,1565191523.629 [BPC1](INFO): Received data from all battery sticks.
2019-08-07T15:28:02.415Z,1565191682.415 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-07T15:28:02.415Z,1565191682.415 [Default:CheckIn:C.Wait] Stopped
2019-08-07T15:28:02.415Z,1565191682.415 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-07T15:28:02.415Z,1565191682.415 [Default:CheckIn:D] Running Loop=1
2019-08-07T15:28:02.809Z,1565191682.809 [Default:CheckIn:D] Stopped
2019-08-07T15:28:02.809Z,1565191682.809 [Default:CheckIn:E] Running Loop=1
2019-08-07T15:28:03.251Z,1565191683.251 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 8.366748 min 
2019-08-07T15:28:03.251Z,1565191683.251 [Default:CheckIn:E] Stopped
2019-08-07T15:28:03.251Z,1565191683.251 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-07T15:28:03.252Z,1565191683.252 [Default:CheckIn] Stopped
2019-08-07T15:28:03.252Z,1565191683.252 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-07T15:28:03.252Z,1565191683.252 [Default:CheckIn](INFO): Running loop #2
2019-08-07T15:28:03.252Z,1565191683.252 [Default:CheckIn] Running Loop=2
2019-08-07T15:28:03.252Z,1565191683.252 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-07T15:28:03.252Z,1565191683.252 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-07T15:28:04.817Z,1565191684.817 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:28:05.208Z,1565191685.208 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,152804.00,A,3648.16809,N,12147.28691,W,0.369,0.00,070819,,,A*77
2019-08-07T15:28:05.210Z,1565191685.210 [NAL9602](INFO): GPS fix at 20190807T152804: (36.802802, -121.788115)
2019-08-07T15:28:05.300Z,1565191685.300 [Default:CheckIn:Read_GPS] Stopped
2019-08-07T15:28:05.300Z,1565191685.300 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-07T15:28:08.821Z,1565191688.821 [DataOverHttps](INFO): Sending 221 bytes from file Logs/20190807T151639/Courier0007.lzma
2019-08-07T15:28:09.627Z,1565191689.627 [DataOverHttps](INFO): Moved sent file to Logs/20190807T151639/Courier0007.lzma.bak
2019-08-07T15:28:09.627Z,1565191689.627 [DataOverHttps](INFO): SBD MOMSN=11534589
2019-08-07T15:28:20.709Z,1565191700.709 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20190807T151639/Express0008.lzma
2019-08-07T15:28:21.515Z,1565191701.515 [DataOverHttps](INFO): Moved sent file to Logs/20190807T151639/Express0008.lzma.bak
2019-08-07T15:28:21.515Z,1565191701.515 [DataOverHttps](INFO): SBD MOMSN=11534592
2019-08-07T15:28:22.278Z,1565191702.278 [Default:CheckIn:Read_Iridium] Stopped
2019-08-07T15:28:22.278Z,1565191702.278 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-07T15:28:22.278Z,1565191702.278 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-07T15:28:35.987Z,1565191715.987 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2019-08-07T15:28:36.062Z,1565191716.062 [NAL9602](FAULT): received: 
+CSQ:0

OK863, 2, 0, 0, 0

OK
2019-08-07T15:28:36.062Z,1565191716.062 [NAL9602] Data Fault, FailCount= 1
2019-08-07T15:28:36.062Z,1565191716.062 [NAL9602](ERROR): Data Fault
2019-08-07T15:28:36.139Z,1565191716.139 [CBIT](ERROR): Data Fault in component: NAL9602
2019-08-07T15:28:36.388Z,1565191716.388 [NAL9602](INFO): Powering down
2019-08-07T15:28:37.235Z,1565191717.235 [CBIT](INFO): Clearing failed state for component NAL9602
2019-08-07T15:28:37.235Z,1565191717.235 [NAL9602] No Fault, FailCount= 1
2019-08-07T15:29:06.699Z,1565191746.699 [NAL9602](INFO): Powering up NAL9602
2019-08-07T15:29:17.603Z,1565191757.603 [NAL9602](INFO): NAL9602 initialized
2019-08-07T15:29:48.711Z,1565191788.711 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-07T15:33:22.853Z,1565192002.853 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-07T15:33:22.853Z,1565192002.853 [Default:CheckIn:C.Wait] Stopped
2019-08-07T15:33:22.853Z,1565192002.853 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-07T15:33:22.853Z,1565192002.853 [Default:CheckIn:D] Running Loop=1
2019-08-07T15:33:23.252Z,1565192003.252 [Default:CheckIn:D] Stopped
2019-08-07T15:33:23.252Z,1565192003.252 [Default:CheckIn:E] Running Loop=1
2019-08-07T15:33:23.662Z,1565192003.662 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 13.707454 min 
2019-08-07T15:33:23.662Z,1565192003.662 [Default:CheckIn:E] Stopped
2019-08-07T15:33:23.662Z,1565192003.662 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-07T15:33:23.662Z,1565192003.662 [Default:CheckIn] Stopped
2019-08-07T15:33:23.662Z,1565192003.662 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-07T15:33:23.662Z,1565192003.662 [Default:CheckIn](INFO): Running loop #3
2019-08-07T15:33:23.662Z,1565192003.662 [Default:CheckIn] Running Loop=3
2019-08-07T15:33:23.662Z,1565192003.662 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-07T15:33:23.663Z,1565192003.663 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-07T15:33:25.266Z,1565192005.266 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:33:27.675Z,1565192007.675 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-08-07T15:33:28.497Z,1565192008.497 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:33:31.325Z,1565192011.325 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:33:34.149Z,1565192014.149 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:33:36.977Z,1565192016.977 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:33:40.213Z,1565192020.213 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:33:43.037Z,1565192023.037 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:33:46.273Z,1565192026.273 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:33:49.102Z,1565192029.102 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:33:52.333Z,1565192032.333 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:33:55.157Z,1565192035.157 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:33:57.985Z,1565192037.985 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:34:00.005Z,1565192040.005 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:34:02.429Z,1565192042.429 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:34:05.257Z,1565192045.257 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:34:08.493Z,1565192048.493 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:34:11.321Z,1565192051.321 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:34:14.549Z,1565192054.549 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:34:17.378Z,1565192057.378 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:34:20.209Z,1565192060.209 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:34:23.038Z,1565192063.038 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:34:25.066Z,1565192065.066 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:34:28.297Z,1565192068.297 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:34:31.117Z,1565192071.117 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:34:34.345Z,1565192074.345 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:34:37.177Z,1565192077.177 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:34:40.405Z,1565192080.405 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:34:43.237Z,1565192083.237 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:34:46.465Z,1565192086.465 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:34:49.293Z,1565192089.293 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:34:52.126Z,1565192092.126 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:34:55.357Z,1565192095.357 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:34:58.185Z,1565192098.185 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:35:01.417Z,1565192101.417 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:35:04.258Z,1565192104.258 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:35:07.477Z,1565192107.477 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:35:10.301Z,1565192110.301 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:35:13.129Z,1565192113.129 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:35:16.366Z,1565192116.366 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:35:19.193Z,1565192119.193 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:35:22.429Z,1565192122.429 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:35:25.250Z,1565192125.250 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:35:28.481Z,1565192128.481 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:35:31.313Z,1565192131.313 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:35:34.542Z,1565192134.542 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:35:37.369Z,1565192137.369 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:35:40.613Z,1565192140.613 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:35:43.433Z,1565192143.433 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:35:46.671Z,1565192146.671 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:35:48.523Z,1565192148.523 [CommandLine](IMPORTANT): got command show variable stopdepth
2019-08-07T15:35:48.555Z,1565192148.555 [CommandLine](IMPORTANT): VerticalControl.stopDepthExcursion (meter)
2019-08-07T15:35:48.563Z,1565192148.563 [CommandLine](IMPORTANT): CBIT.stopDepth (meter)
2019-08-07T15:35:49.493Z,1565192149.493 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:35:52.321Z,1565192152.321 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:35:53.356Z,1565192153.356 [CommandLine](IMPORTANT): got command get CBIT.stopDepth
2019-08-07T15:35:53.356Z,1565192153.356 [CommandLine](IMPORTANT): CBIT.stopDepth 205.000000 m
2019-08-07T15:35:55.550Z,1565192155.550 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:35:58.397Z,1565192158.397 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:36:00.711Z,1565192160.711 [CommandLine](IMPORTANT): got command get CBIT.abortDepth
2019-08-07T15:36:00.712Z,1565192160.712 [CommandLine](IMPORTANT): CBIT.abortDepth 250.000000 m
2019-08-07T15:36:01.609Z,1565192161.609 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:36:04.441Z,1565192164.441 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:36:07.639Z,1565192167.639 [CommandLine](IMPORTANT): got command show variable neutral
2019-08-07T15:36:07.678Z,1565192167.678 [CommandLine](IMPORTANT): Config/Simulator.buoyancyNeutralOffset (cubic_centimeter)
2019-08-07T15:36:07.680Z,1565192167.680 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral (cubic_centimeter)
2019-08-07T15:36:07.697Z,1565192167.697 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:36:10.501Z,1565192170.501 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:36:12.656Z,1565192172.656 [CommandLine](IMPORTANT): got command get VerticalControl.buoyancyNeutral
2019-08-07T15:36:12.657Z,1565192172.657 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral 200.000000 cc
2019-08-07T15:36:13.334Z,1565192173.334 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:36:16.562Z,1565192176.562 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:36:19.390Z,1565192179.390 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:36:21.078Z,1565192181.078 [CommandLine](IMPORTANT): got command show variable massDefault
2019-08-07T15:36:21.103Z,1565192181.103 [CommandLine](IMPORTANT): VerticalControl.massDefault (centimeter)
2019-08-07T15:36:22.625Z,1565192182.625 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:36:25.445Z,1565192185.445 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:36:25.475Z,1565192185.475 [CommandLine](IMPORTANT): got command get VerticalControl.massDefault
2019-08-07T15:36:25.476Z,1565192185.476 [CommandLine](IMPORTANT): VerticalControl.massDefault -0.400000 cm
2019-08-07T15:36:28.678Z,1565192188.678 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:36:31.509Z,1565192191.509 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:36:34.741Z,1565192194.741 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:36:36.155Z,1565192196.155 [CommandLine](IMPORTANT): got command show variable limitFwd
2019-08-07T15:36:36.184Z,1565192196.184 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitFwd (millimeter)
2019-08-07T15:36:37.569Z,1565192197.569 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:36:40.393Z,1565192200.393 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:36:41.731Z,1565192201.731 [CommandLine](IMPORTANT): got command get VerticalControl.massPositionLimitFwd
2019-08-07T15:36:41.732Z,1565192201.732 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitFwd 30.000000 mm
2019-08-07T15:36:43.629Z,1565192203.629 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:36:46.453Z,1565192206.453 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:36:49.701Z,1565192209.701 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:36:52.517Z,1565192212.517 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:36:55.750Z,1565192215.750 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:36:58.577Z,1565192218.577 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:37:01.405Z,1565192221.405 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:37:04.670Z,1565192224.670 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:37:07.502Z,1565192227.502 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:37:10.754Z,1565192230.754 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:37:13.577Z,1565192233.577 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:37:16.405Z,1565192236.405 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:37:19.657Z,1565192239.657 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:37:22.465Z,1565192242.465 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:37:25.702Z,1565192245.702 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:37:28.525Z,1565192248.525 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:37:31.758Z,1565192251.758 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:37:34.585Z,1565192254.585 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:37:37.817Z,1565192257.817 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:37:40.645Z,1565192260.645 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:37:43.473Z,1565192263.473 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:37:46.717Z,1565192266.717 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:37:49.533Z,1565192269.533 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:37:52.765Z,1565192272.765 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:37:55.597Z,1565192275.597 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:37:58.825Z,1565192278.825 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:38:01.654Z,1565192281.654 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:38:04.889Z,1565192284.889 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:38:07.713Z,1565192287.713 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:38:10.541Z,1565192290.541 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:38:13.773Z,1565192293.773 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:38:16.605Z,1565192296.605 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:38:19.837Z,1565192299.837 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:38:22.681Z,1565192302.681 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:38:23.891Z,1565192303.891 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-07T15:33:23.7Z
2019-08-07T15:38:23.891Z,1565192303.891 [Default:CheckIn:Read_GPS] Stopped
2019-08-07T15:38:23.891Z,1565192303.891 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-07T15:38:29.677Z,1565192309.677 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190807T151639/Courier0010.lzma
2019-08-07T15:38:30.483Z,1565192310.483 [DataOverHttps](INFO): Moved sent file to Logs/20190807T151639/Courier0010.lzma.bak
2019-08-07T15:38:30.483Z,1565192310.483 [DataOverHttps](INFO): SBD MOMSN=11534629
2019-08-07T15:38:41.794Z,1565192321.794 [DataOverHttps](INFO): Sending 564 bytes from file Logs/20190807T151639/Express0011.lzma
2019-08-07T15:38:42.599Z,1565192322.599 [DataOverHttps](INFO): Moved sent file to Logs/20190807T151639/Express0011.lzma.bak
2019-08-07T15:38:42.599Z,1565192322.599 [DataOverHttps](INFO): SBD MOMSN=11534631
2019-08-07T15:38:43.286Z,1565192323.286 [Default:CheckIn:Read_Iridium] Stopped
2019-08-07T15:38:43.286Z,1565192323.286 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-07T15:38:43.286Z,1565192323.286 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-07T15:38:55.778Z,1565192335.778 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-07T15:39:39.606Z,1565192379.606 [CommandLine](IMPORTANT): got command failComponent
2019-08-07T15:39:39.606Z,1565192379.606 [CommandLine](IMPORTANT): Failed components:
2019-08-07T15:39:39.607Z,1565192379.606 [CommandLine](IMPORTANT): No failed Components.
2019-08-07T15:43:43.855Z,1565192623.855 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-07T15:43:43.855Z,1565192623.855 [Default:CheckIn:C.Wait] Stopped
2019-08-07T15:43:43.855Z,1565192623.855 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-07T15:43:43.855Z,1565192623.855 [Default:CheckIn:D] Running Loop=1
2019-08-07T15:43:44.273Z,1565192624.273 [Default:CheckIn:D] Stopped
2019-08-07T15:43:44.273Z,1565192624.273 [Default:CheckIn:E] Running Loop=1
2019-08-07T15:43:44.682Z,1565192624.682 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 24.057808 min 
2019-08-07T15:43:44.683Z,1565192624.683 [Default:CheckIn:E] Stopped
2019-08-07T15:43:44.683Z,1565192624.683 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-07T15:43:44.683Z,1565192624.683 [Default:CheckIn] Stopped
2019-08-07T15:43:44.683Z,1565192624.683 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-07T15:43:44.683Z,1565192624.683 [Default:CheckIn](INFO): Running loop #4
2019-08-07T15:43:44.683Z,1565192624.683 [Default:CheckIn] Running Loop=4
2019-08-07T15:43:44.683Z,1565192624.683 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-07T15:43:44.683Z,1565192624.683 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-07T15:43:46.269Z,1565192626.269 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-08-07T15:43:46.269Z,1565192626.269 [NAL9602] Data Fault, FailCount= 1
2019-08-07T15:43:46.269Z,1565192626.269 [NAL9602](ERROR): Data Fault
2019-08-07T15:43:46.326Z,1565192626.326 [CBIT](ERROR): Data Fault in component: NAL9602
2019-08-07T15:43:46.658Z,1565192626.658 [NAL9602](INFO): Powering down
2019-08-07T15:43:47.534Z,1565192627.534 [CBIT](INFO): Clearing failed state for component NAL9602
2019-08-07T15:43:47.534Z,1565192627.534 [NAL9602] No Fault, FailCount= 1
2019-08-07T15:44:16.959Z,1565192656.959 [NAL9602](INFO): Powering up NAL9602
2019-08-07T15:44:27.867Z,1565192667.867 [NAL9602](INFO): NAL9602 initialized
2019-08-07T15:44:28.686Z,1565192668.686 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:48:32.292Z,1565192912.292 [NAL9602](INFO): SBD MO Status=2, MOMSN=15863, MT Status=2, MTMSN=0
2019-08-07T15:48:32.292Z,1565192912.292 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-07T15:48:44.842Z,1565192924.842 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-07T15:43:44.7Z
2019-08-07T15:48:44.842Z,1565192924.842 [Default:CheckIn:Read_GPS] Stopped
2019-08-07T15:48:44.842Z,1565192924.842 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-07T15:48:50.021Z,1565192930.021 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190807T151639/Courier0013.lzma
2019-08-07T15:48:50.827Z,1565192930.827 [DataOverHttps](INFO): Moved sent file to Logs/20190807T151639/Courier0013.lzma.bak
2019-08-07T15:48:50.827Z,1565192930.827 [DataOverHttps](INFO): SBD MOMSN=11534688
2019-08-07T15:48:56.124Z,1565192936.124 [NAL9602](INFO): SBD MO Status=2, MOMSN=15863, MT Status=2, MTMSN=0
2019-08-07T15:48:56.124Z,1565192936.124 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-07T15:49:01.866Z,1565192941.866 [DataOverHttps](INFO): Sending 210 bytes from file Logs/20190807T151639/Express0014.lzma
2019-08-07T15:49:02.671Z,1565192942.671 [DataOverHttps](INFO): Moved sent file to Logs/20190807T151639/Express0014.lzma.bak
2019-08-07T15:49:02.671Z,1565192942.671 [DataOverHttps](INFO): SBD MOMSN=11534690
2019-08-07T15:49:03.434Z,1565192943.434 [Default:CheckIn:Read_Iridium] Stopped
2019-08-07T15:49:03.434Z,1565192943.434 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-07T15:49:03.434Z,1565192943.434 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-07T15:49:31.271Z,1565192971.271 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-08-07T15:50:01.975Z,1565193001.975 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-07T15:54:03.991Z,1565193243.991 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-07T15:54:03.991Z,1565193243.991 [Default:CheckIn:C.Wait] Stopped
2019-08-07T15:54:03.991Z,1565193243.991 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-07T15:54:03.991Z,1565193243.991 [Default:CheckIn:D] Running Loop=1
2019-08-07T15:54:04.403Z,1565193244.403 [Default:CheckIn:D] Stopped
2019-08-07T15:54:04.403Z,1565193244.403 [Default:CheckIn:E] Running Loop=1
2019-08-07T15:54:04.807Z,1565193244.807 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.393306 min 
2019-08-07T15:54:04.807Z,1565193244.807 [Default:CheckIn:E] Stopped
2019-08-07T15:54:04.807Z,1565193244.807 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-07T15:54:04.807Z,1565193244.807 [Default:CheckIn] Stopped
2019-08-07T15:54:04.807Z,1565193244.807 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-07T15:54:04.807Z,1565193244.807 [Default:CheckIn](INFO): Running loop #5
2019-08-07T15:54:04.807Z,1565193244.807 [Default:CheckIn] Running Loop=5
2019-08-07T15:54:04.808Z,1565193244.808 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-07T15:54:04.808Z,1565193244.808 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-07T15:54:06.414Z,1565193246.414 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:54:37.503Z,1565193277.503 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2019-08-07T15:54:37.585Z,1565193277.585 [NAL9602](FAULT): received: 
+CSQ:0

OK863, 2, 0, 0, 0

OK
2019-08-07T15:54:37.586Z,1565193277.586 [NAL9602] Data Fault, FailCount= 2
2019-08-07T15:54:37.586Z,1565193277.586 [NAL9602](ERROR): Data Fault
2019-08-07T15:54:37.646Z,1565193277.646 [CBIT](ERROR): Data Fault in component: NAL9602
2019-08-07T15:54:37.906Z,1565193277.906 [NAL9602](INFO): Powering down
2019-08-07T15:54:38.791Z,1565193278.791 [CBIT](INFO): Clearing failed state for component NAL9602
2019-08-07T15:54:38.791Z,1565193278.791 [NAL9602] No Fault, FailCount= 2
2019-08-07T15:55:08.206Z,1565193308.206 [NAL9602](INFO): Powering up NAL9602
2019-08-07T15:55:19.119Z,1565193319.119 [NAL9602](INFO): NAL9602 initialized
2019-08-07T15:55:19.923Z,1565193319.923 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-08-07T15:55:19.923Z,1565193319.923 [NAL9602] Data Fault, FailCount= 3
2019-08-07T15:55:19.923Z,1565193319.923 [NAL9602](ERROR): Data Fault
2019-08-07T15:55:19.956Z,1565193319.956 [CBIT](ERROR): Data Fault in component: NAL9602
2019-08-07T15:55:20.326Z,1565193320.326 [NAL9602](INFO): Powering down
2019-08-07T15:55:21.174Z,1565193321.174 [CBIT](INFO): Clearing failed state for component NAL9602
2019-08-07T15:55:21.174Z,1565193321.174 [NAL9602] No Fault, FailCount= 3
2019-08-07T15:55:50.631Z,1565193350.631 [NAL9602](INFO): Powering up NAL9602
2019-08-07T15:56:01.535Z,1565193361.535 [NAL9602](INFO): NAL9602 initialized
2019-08-07T15:56:02.357Z,1565193362.357 [NAL9602](DEBUG): Fix Requested
2019-08-07T15:59:04.998Z,1565193544.998 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-07T15:54:04.8Z
2019-08-07T15:59:04.998Z,1565193544.998 [Default:CheckIn:Read_GPS] Stopped
2019-08-07T15:59:04.998Z,1565193544.998 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-07T15:59:08.995Z,1565193548.995 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-08-07T15:59:10.433Z,1565193550.433 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190807T151639/Courier0016.lzma
2019-08-07T15:59:11.239Z,1565193551.239 [DataOverHttps](INFO): Moved sent file to Logs/20190807T151639/Courier0016.lzma.bak
2019-08-07T15:59:11.240Z,1565193551.240 [DataOverHttps](INFO): SBD MOMSN=11534736
2019-08-07T15:59:22.429Z,1565193562.429 [DataOverHttps](INFO): Sending 253 bytes from file Logs/20190807T151639/Express0017.lzma
2019-08-07T15:59:23.259Z,1565193563.259 [DataOverHttps](INFO): Moved sent file to Logs/20190807T151639/Express0017.lzma.bak
2019-08-07T15:59:23.259Z,1565193563.259 [DataOverHttps](INFO): SBD MOMSN=11534738
2019-08-07T15:59:23.962Z,1565193563.962 [Default:CheckIn:Read_Iridium] Stopped
2019-08-07T15:59:23.962Z,1565193563.962 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-07T15:59:23.963Z,1565193563.963 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-07T15:59:39.699Z,1565193579.699 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-07T16:04:24.597Z,1565193864.597 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-07T16:04:24.597Z,1565193864.597 [Default:CheckIn:C.Wait] Stopped
2019-08-07T16:04:24.597Z,1565193864.597 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-07T16:04:24.597Z,1565193864.597 [Default:CheckIn:D] Running Loop=1
2019-08-07T16:04:25.002Z,1565193865.002 [Default:CheckIn:D] Stopped
2019-08-07T16:04:25.002Z,1565193865.002 [Default:CheckIn:E] Running Loop=1
2019-08-07T16:04:25.466Z,1565193865.466 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 44.736633 min 
2019-08-07T16:04:25.467Z,1565193865.467 [Default:CheckIn:E] Stopped
2019-08-07T16:04:25.467Z,1565193865.467 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-07T16:04:25.467Z,1565193865.467 [Default:CheckIn] Stopped
2019-08-07T16:04:25.467Z,1565193865.467 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-07T16:04:25.467Z,1565193865.467 [Default:CheckIn](INFO): Running loop #6
2019-08-07T16:04:25.467Z,1565193865.467 [Default:CheckIn] Running Loop=6
2019-08-07T16:04:25.467Z,1565193865.467 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-07T16:04:25.467Z,1565193865.467 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-07T16:04:27.022Z,1565193867.022 [NAL9602](DEBUG): Fix Requested
2019-08-07T16:04:58.127Z,1565193898.127 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2019-08-07T16:04:58.209Z,1565193898.209 [NAL9602](FAULT): received: 
+CSQ:0

OK863, 2, 0, 0, 0

OK
2019-08-07T16:04:58.210Z,1565193898.210 [NAL9602] Data Fault, FailCount= 4
2019-08-07T16:04:58.210Z,1565193898.210 [NAL9602](ERROR): Data Fault
2019-08-07T16:04:58.309Z,1565193898.309 [CBIT](ERROR): Data Fault in component: NAL9602
2019-08-07T16:04:58.530Z,1565193898.530 [NAL9602](INFO): Powering down
2019-08-07T16:04:59.399Z,1565193899.399 [CBIT](INFO): Clearing failed state for component NAL9602
2019-08-07T16:04:59.399Z,1565193899.399 [NAL9602] No Fault, FailCount= 4
2019-08-07T16:05:28.830Z,1565193928.830 [NAL9602](INFO): Powering up NAL9602
2019-08-07T16:05:39.743Z,1565193939.743 [NAL9602](INFO): NAL9602 initialized
2019-08-07T16:05:40.561Z,1565193940.561 [NAL9602](DEBUG): Fix Requested
2019-08-07T16:08:58.964Z,1565194138.964 [NAL9602](INFO): SBD MO Status=2, MOMSN=15863, MT Status=2, MTMSN=0
2019-08-07T16:08:58.964Z,1565194138.964 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-07T16:09:25.652Z,1565194165.652 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-07T16:04:25.5Z
2019-08-07T16:09:25.652Z,1565194165.652 [Default:CheckIn:Read_GPS] Stopped
2019-08-07T16:09:25.652Z,1565194165.652 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-07T16:09:29.667Z,1565194169.667 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-08-07T16:09:31.049Z,1565194171.049 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190807T151639/Courier0019.lzma
2019-08-07T16:09:31.855Z,1565194171.855 [DataOverHttps](INFO): Moved sent file to Logs/20190807T151639/Courier0019.lzma.bak
2019-08-07T16:09:31.855Z,1565194171.855 [DataOverHttps](INFO): SBD MOMSN=11534783
2019-08-07T16:09:42.797Z,1565194182.797 [DataOverHttps](INFO): Sending 236 bytes from file Logs/20190807T151639/Express0020.lzma
2019-08-07T16:09:43.603Z,1565194183.603 [DataOverHttps](INFO): Moved sent file to Logs/20190807T151639/Express0020.lzma.bak
2019-08-07T16:09:43.603Z,1565194183.603 [DataOverHttps](INFO): SBD MOMSN=11534785
2019-08-07T16:09:44.249Z,1565194184.249 [Default:CheckIn:Read_Iridium] Stopped
2019-08-07T16:09:44.250Z,1565194184.250 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-07T16:09:44.250Z,1565194184.250 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-07T16:10:00.373Z,1565194200.373 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-07T16:12:20.207Z,1565194340.207 [DataOverHttps](IMPORTANT): SBD MTMSN=20190807T161215
2019-08-07T16:12:25.294Z,1565194345.294 [DataOverHttps](INFO): Received command:ibit
2019-08-07T16:12:25.310Z,1565194345.310 [CommandLine](IMPORTANT): got command ibit
2019-08-07T16:12:25.439Z,1565194345.439 [IBIT](IMPORTANT): Beginning Initiated BIT
2019-08-07T16:12:25.440Z,1565194345.440 [IBIT](IMPORTANT): Beginning control surface checks.
2019-08-07T16:12:25.443Z,1565194345.443 [CBIT](IMPORTANT): Beginning ground fault scan
2019-08-07T16:12:26.631Z,1565194346.631 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-08-07T16:12:26.631Z,1565194346.631 [NAL9602] Data Fault, FailCount= 5
2019-08-07T16:12:26.631Z,1565194346.631 [NAL9602](ERROR): Data Fault
2019-08-07T16:12:26.676Z,1565194346.676 [CBIT](ERROR): Data Fault in component: NAL9602
2019-08-07T16:12:26.676Z,1565194346.676 [CBIT](CRITICAL): Data Fault in component: NAL9602
2019-08-07T16:12:27.023Z,1565194347.023 [NAL9602](INFO): Powering down
2019-08-07T16:12:27.097Z,1565194347.097 [CommandLine](FAULT): Scheduling is paused
2019-08-07T16:12:27.098Z,1565194347.098 [CBIT](INFO): Critical error at 20190807T161226
2019-08-07T16:12:27.098Z,1565194347.098 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-08-07T16:12:36.382Z,1565194356.382 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.005851
CHAN A1 (24V): -0.134183
CHAN A2 (12V): -0.002065
CHAN A3 (5V): -0.002037
CHAN B0 (3.3V): 0.000211
CHAN B1 (3.15aV): -0.000078
CHAN B2 (3.15bV): 0.000014
CHAN B3 (GND): 0.000193
OPEN: -0.000289
Full Scale Calc: 4.765 mA, -1.589 mA
2019-08-07T16:14:16.539Z,1565194456.539 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2019-08-07T16:14:16.951Z,1565194456.951 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 0.000000
2019-08-07T16:14:16.951Z,1565194456.951 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2019-08-07T16:14:16.951Z,1565194456.951 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2019-08-07T16:14:17.352Z,1565194457.352 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2019-08-07T16:14:17.352Z,1565194457.352 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2019-08-07T16:14:17.353Z,1565194457.353 [IBIT](IMPORTANT): Pressure:8.921788 PSI
2019-08-07T16:14:17.353Z,1565194457.353 [IBIT](IMPORTANT): Humidity:4.364546 %
2019-08-07T16:14:17.769Z,1565194457.769 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2019-08-07T16:14:17.769Z,1565194457.769 [IBIT](IMPORTANT): buoyancyNeutral: 200.000000 cc
2019-08-07T16:14:17.770Z,1565194457.770 [IBIT](IMPORTANT): massDefault: -0.400000 cm
2019-08-07T16:14:17.770Z,1565194457.770 [IBIT](IMPORTANT): stopDepth: 205.000000 m
2019-08-07T16:14:17.770Z,1565194457.770 [IBIT](IMPORTANT): abortDepth: 250.000000 m
2019-08-07T16:14:17.770Z,1565194457.770 [IBIT](IMPORTANT): IBIT FAILED
2019-08-07T16:14:26.646Z,1565194466.646 [CBIT](INFO): Clearing failed state for component NAL9602
2019-08-07T16:14:26.646Z,1565194466.646 [NAL9602] No Fault, FailCount= 5
2019-08-07T16:14:27.010Z,1565194467.010 [NAL9602](INFO): Powering up NAL9602
2019-08-07T16:14:37.923Z,1565194477.923 [NAL9602](INFO): NAL9602 initialized
2019-08-07T16:14:38.327Z,1565194478.327 [NAL9602](INFO): Failure count cleared after critical for NAL9602
2019-08-07T16:14:44.810Z,1565194484.810 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-07T16:14:44.810Z,1565194484.810 [Default:CheckIn:C.Wait] Stopped
2019-08-07T16:14:44.810Z,1565194484.810 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-07T16:14:44.810Z,1565194484.810 [Default:CheckIn:D] Running Loop=1
2019-08-07T16:14:45.211Z,1565194485.211 [Default:CheckIn:D] Stopped
2019-08-07T16:14:45.211Z,1565194485.211 [Default:CheckIn:E] Running Loop=1
2019-08-07T16:14:45.622Z,1565194485.622 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 55.073450 min 
2019-08-07T16:14:45.622Z,1565194485.622 [Default:CheckIn:E] Stopped
2019-08-07T16:14:45.622Z,1565194485.622 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-07T16:14:45.623Z,1565194485.623 [Default:CheckIn] Stopped
2019-08-07T16:14:45.623Z,1565194485.623 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-07T16:14:45.623Z,1565194485.623 [Default:CheckIn](INFO): Running loop #7
2019-08-07T16:14:45.623Z,1565194485.623 [Default:CheckIn] Running Loop=7
2019-08-07T16:14:45.623Z,1565194485.623 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-07T16:14:45.623Z,1565194485.623 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-07T16:14:47.221Z,1565194487.221 [NAL9602](DEBUG): Fix Requested
2019-08-07T16:15:08.628Z,1565194508.628 [NAL9602](INFO): SBD MO Status=2, MOMSN=15863, MT Status=2, MTMSN=0
2019-08-07T16:15:08.628Z,1565194508.628 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-07T16:16:35.886Z,1565194595.886 [NAL9602](INFO): SBD MO Status=2, MOMSN=15863, MT Status=2, MTMSN=0
2019-08-07T16:16:35.886Z,1565194595.886 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-07T16:17:44.164Z,1565194664.164 [NAL9602](INFO): SBD MO Status=2, MOMSN=15863, MT Status=2, MTMSN=0
2019-08-07T16:17:44.164Z,1565194664.164 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-07T16:18:02.350Z,1565194682.350 [NAL9602](INFO): SBD MO Status=2, MOMSN=15863, MT Status=2, MTMSN=0
2019-08-07T16:18:02.351Z,1565194682.351 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-07T16:18:17.292Z,1565194697.292 [NAL9602](INFO): SBD MO Status=2, MOMSN=15863, MT Status=2, MTMSN=0
2019-08-07T16:18:17.292Z,1565194697.292 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-07T16:18:37.496Z,1565194717.496 [NAL9602](INFO): SBD MO Status=2, MOMSN=15863, MT Status=2, MTMSN=0
2019-08-07T16:18:37.496Z,1565194717.496 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-07T16:18:46.802Z,1565194726.802 [NAL9602](INFO): SBD MO Status=0, MOMSN=15863, MT Status=0, MTMSN=0
2019-08-07T16:18:46.802Z,1565194726.802 [NAL9602](INFO): No messages in MT queue
2019-08-07T16:18:47.614Z,1565194727.614 [NAL9602](DEBUG): Fix Requested
2019-08-07T16:18:48.020Z,1565194728.020 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161842.00,A,3648.14318,N,12147.22841,W,0.000,0.00,070819,,,A*79
2019-08-07T16:18:48.035Z,1565194728.035 [NAL9602](INFO): GPS fix at 20190807T161842: (36.802386, -121.787140)
2019-08-07T16:18:48.059Z,1565194728.059 [Default:CheckIn:Read_GPS] Stopped
2019-08-07T16:18:48.059Z,1565194728.059 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-07T16:18:53.413Z,1565194733.413 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20190807T151639/Courier0022.lzma
2019-08-07T16:18:54.220Z,1565194734.220 [DataOverHttps](INFO): Moved sent file to Logs/20190807T151639/Courier0022.lzma.bak
2019-08-07T16:18:54.220Z,1565194734.220 [DataOverHttps](IMPORTANT): SBD MOMSN=11534823, MTMSN=20190807T161848
2019-08-07T16:18:59.217Z,1565194739.217 [DataOverHttps](INFO): Received command:load Science/sci2.xml;set sci2.NeedCommsTime 20 minute;set sci2.Lat1 36.797 degree;set sci2.Lon1 -121.847 degree;set sci2.YoYoMaxDepth 20 meter;set sci2.MaxDepth 30 meter;run 
2019-08-07T16:18:59.235Z,1565194739.235 [CommandLine](IMPORTANT): got command load ./Missions/Science/sci2.xml
2019-08-07T16:18:59.236Z,1565194739.236 [MissionManager](INFO): Loading Mission: ./Missions/Science/sci2.xml
2019-08-07T16:18:59.400Z,1565194739.400 [MissionManager](INFO): DefineArg sci2.MissionTimeout = 2.000000 h
2019-08-07T16:18:59.403Z,1565194739.403 [MissionManager](INFO): DefineArg sci2.NeedCommsTime = 60.000000 min
2019-08-07T16:18:59.442Z,1565194739.442 [MissionManager](INFO): DefineArg sci2.Repeat = 1.000000 count
2019-08-07T16:18:59.444Z,1565194739.444 [MissionManager](INFO): DefineArg sci2.Lat1 = nan arcdeg
2019-08-07T16:18:59.447Z,1565194739.447 [MissionManager](INFO): DefineArg sci2.Lon1 = nan arcdeg
2019-08-07T16:18:59.450Z,1565194739.450 [MissionManager](INFO): DefineArg sci2.Lat2 = nan arcdeg
2019-08-07T16:18:59.452Z,1565194739.452 [MissionManager](INFO): DefineArg sci2.Lon2 = nan arcdeg
2019-08-07T16:18:59.467Z,1565194739.467 [MissionManager](INFO): DefineArg sci2.Lat3 = nan arcdeg
2019-08-07T16:18:59.470Z,1565194739.470 [MissionManager](INFO): DefineArg sci2.Lon3 = nan arcdeg
2019-08-07T16:18:59.473Z,1565194739.473 [MissionManager](INFO): DefineArg sci2.Lat4 = nan arcdeg
2019-08-07T16:18:59.476Z,1565194739.476 [MissionManager](INFO): DefineArg sci2.Lon4 = nan arcdeg
2019-08-07T16:18:59.478Z,1565194739.478 [MissionManager](INFO): DefineArg sci2.Lat5 = nan arcdeg
2019-08-07T16:18:59.481Z,1565194739.481 [MissionManager](INFO): DefineArg sci2.Lon5 = nan arcdeg
2019-08-07T16:18:59.505Z,1565194739.505 [MissionManager](INFO): DefineArg sci2.Lat6 = nan arcdeg
2019-08-07T16:18:59.507Z,1565194739.507 [MissionManager](INFO): DefineArg sci2.Lon6 = nan arcdeg
2019-08-07T16:18:59.510Z,1565194739.510 [MissionManager](INFO): DefineArg sci2.Lat7 = nan arcdeg
2019-08-07T16:18:59.513Z,1565194739.513 [MissionManager](INFO): DefineArg sci2.Lon7 = nan arcdeg
2019-08-07T16:18:59.527Z,1565194739.527 [MissionManager](INFO): DefineArg sci2.Speed = 1.000000 m/s
2019-08-07T16:18:59.531Z,1565194739.531 [MissionManager](INFO): DefineArg sci2.CaptureRadius = nan m
2019-08-07T16:18:59.544Z,1565194739.544 [MissionManager](INFO): DefineArg sci2.YoYoMinDepth = 2.000000 m
2019-08-07T16:18:59.547Z,1565194739.547 [MissionManager](INFO): DefineArg sci2.YoYoMaxDepth = 200.000000 m
2019-08-07T16:18:59.550Z,1565194739.550 [MissionManager](INFO): DefineArg sci2.YoYoMinAltitude = 9.000000 m
2019-08-07T16:18:59.553Z,1565194739.553 [MissionManager](INFO): DefineArg sci2.YoYoUpPitch = 20.000000 arcdeg
2019-08-07T16:18:59.582Z,1565194739.582 [MissionManager](INFO): DefineArg sci2.YoYoDownPitch = -20.000000 arcdeg
2019-08-07T16:18:59.596Z,1565194739.596 [MissionManager](INFO): DefineArg sci2.BuoyancyNeutral = 199.999995 cc
2019-08-07T16:18:59.600Z,1565194739.600 [MissionManager](INFO): DefineArg sci2.MassDefault = -0.400000 cm
2019-08-07T16:18:59.603Z,1565194739.603 [MissionManager](INFO): DefineArg sci2.MinAltitude = 5.000000 m
2019-08-07T16:18:59.626Z,1565194739.626 [MissionManager](INFO): DefineArg sci2.MaxDepth = 205.000000 m
2019-08-07T16:18:59.628Z,1565194739.628 [MissionManager](INFO): DefineArg sci2.MinOffshore = 2.000000 km
2019-08-07T16:18:59.629Z,1565194739.629 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml
2019-08-07T16:18:59.994Z,1565194739.994 [MissionManager](INFO): DefineArg sci2:Science.SampleISUS = 0 bool
2019-08-07T16:18:59.996Z,1565194739.996 [MissionManager](INFO): DefineArg sci2:Science.SampleISUSmaxPitch = 60.000000 arcdeg
2019-08-07T16:19:00.003Z,1565194740.003 [MissionManager](INFO): DefineArg sci2:Science.SampleISUSminPitch = -60.000000 arcdeg
2019-08-07T16:19:00.006Z,1565194740.006 [MissionManager](INFO): DefineArg sci2:Science.PeakDetectChlActive = 0 bool
2019-08-07T16:19:00.009Z,1565194740.009 [MissionManager](INFO): DefineArg sci2:Science.TimeWindowPeakReport = nan min
2019-08-07T16:19:00.024Z,1565194740.024 [MissionManager](INFO): DefineArg sci2:Science.HighestChlPeakReportActive = 0 bool
2019-08-07T16:19:00.027Z,1565194740.027 [MissionManager](INFO): DefineArg sci2:Science.PatchTracking = 0 bool
2019-08-07T16:19:00.038Z,1565194740.038 [MissionManager](INFO): DefineArg sci2:Science.FilterWidthHorizontal = 3.000000 count
2019-08-07T16:19:00.041Z,1565194740.041 [MissionManager](INFO): DefineArg sci2:Science.NumProfilesSlidingwindow = 100.000000 count
2019-08-07T16:19:00.044Z,1565194740.044 [MissionManager](INFO): DefineArg sci2:Science.OffPeakFractionHorizontal = 80.000000 %
2019-08-07T16:19:00.047Z,1565194740.047 [MissionManager](INFO): DefineArg sci2:Science.PeakDetectNO3Active = 0 bool
2019-08-07T16:19:00.049Z,1565194740.049 [MissionManager](INFO): DefineArg sci2:Science.PeakDetectOilActive = 0 bool
2019-08-07T16:19:00.060Z,1565194740.060 [MissionManager](INFO): DefineArg sci2:Science.PeakDetectFDOMActive = 0 bool
2019-08-07T16:19:00.063Z,1565194740.063 [MissionManager](INFO): DefineArg sci2:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2019-08-07T16:19:00.074Z,1565194740.074 [MissionManager](INFO): DefineArg sci2:Science.EnabledAanderaaO2 = 1.000000 bool
2019-08-07T16:19:00.082Z,1565194740.082 [MissionManager](INFO): DefineArg sci2:Science.EnabledNeilBrown = 1.000000 bool
2019-08-07T16:19:00.090Z,1565194740.090 [MissionManager](INFO): DefineArg sci2:Science.EnabledSeabird = 1.000000 bool
2019-08-07T16:19:00.094Z,1565194740.094 [MissionManager](INFO): DefineArg sci2:Science.EnabledTurbulence_NPS = 0.000000 bool
2019-08-07T16:19:00.098Z,1565194740.098 [MissionManager](INFO): DefineArg sci2:Science.EnabledWetLabsBB2FL = 1.000000 bool
2019-08-07T16:19:00.122Z,1565194740.122 [MissionManager](INFO): DefineArg sci2:Science.EnabledWetLabsSeaOWL_UV_A = 0.000000 bool
2019-08-07T16:19:00.148Z,1565194740.148 [MissionManager](INFO): DefineArg sci2:Science.EnabledWetLabsUBAT = 0.000000 bool
2019-08-07T16:19:00.168Z,1565194740.168 [MissionManager](INFO): DefineArg sci2:Science.EnabledISUS = 0.000000 bool
2019-08-07T16:19:00.173Z,1565194740.173 [MissionManager](INFO): DefineArg sci2:Science.LowPassWindowLength = 20.000000 count
2019-08-07T16:19:00.184Z,1565194740.184 [MissionManager](INFO): DefineArg sci2:Science.MedianFilterLen = 5.000000 count
2019-08-07T16:19:00.189Z,1565194740.189 [MissionManager](INFO): DefineArg sci2:Science.PeakChlShallowBound = nan m
2019-08-07T16:19:00.200Z,1565194740.200 [MissionManager](INFO): DefineArg sci2:Science.PeakChlDeepBound = nan m
2019-08-07T16:19:00.215Z,1565194740.215 [MissionManager](INFO): DefineArg sci2:Science.PeakShallowBound = nan m
2019-08-07T16:19:00.222Z,1565194740.222 [MissionManager](INFO): DefineArg sci2:Science.PeakDeepBound = nan m
2019-08-07T16:19:00.227Z,1565194740.227 [MissionManager](INFO): DefineOutput sci2:Science.PeakChl = 0.000000 ug/l
2019-08-07T16:19:00.230Z,1565194740.230 [MissionManager](INFO): DefineOutput sci2:Science.PeakChlDepth = 0.000000 m
2019-08-07T16:19:00.238Z,1565194740.238 [MissionManager](INFO): DefineOutput sci2:Science.PeakChlTemperature = 0.000000 degC
2019-08-07T16:19:00.241Z,1565194740.241 [MissionManager](INFO): DefineOutput sci2:Science.PeakChlLatitude = nan arcdeg
2019-08-07T16:19:00.248Z,1565194740.248 [MissionManager](INFO): DefineOutput sci2:Science.PeakChlLongitude = nan arcdeg
2019-08-07T16:19:00.263Z,1565194740.263 [MissionManager](INFO): DefineOutput sci2:Science.PeakNO3 = 0.000000 umol/l
2019-08-07T16:19:00.270Z,1565194740.270 [MissionManager](INFO): DefineOutput sci2:Science.PeakNO3Depth = 0.000000 m
2019-08-07T16:19:00.273Z,1565194740.273 [MissionManager](INFO): DefineOutput sci2:Science.PeakNO3Latitude = nan arcdeg
2019-08-07T16:19:00.284Z,1565194740.284 [MissionManager](INFO): DefineOutput sci2:Science.PeakNO3Longitude = nan arcdeg
2019-08-07T16:19:00.288Z,1565194740.288 [MissionManager](INFO): DefineOutput sci2:Science.PatchChl = 0.000000 m
2019-08-07T16:19:00.291Z,1565194740.291 [MissionManager](INFO): DefineOutput sci2:Science.PatchChlDepth = 0.000000 m
2019-08-07T16:19:00.302Z,1565194740.302 [MissionManager](INFO): DefineOutput sci2:Science.PatchChlLatitude = nan arcdeg
2019-08-07T16:19:00.306Z,1565194740.306 [MissionManager](INFO): DefineOutput sci2:Science.PatchChlLongitude = nan arcdeg
2019-08-07T16:19:00.309Z,1565194740.309 [MissionManager](INFO): DefineOutput sci2:Science.PatchChlDistance = nan m
2019-08-07T16:19:00.320Z,1565194740.320 [MissionManager](INFO): DefineOutput sci2:Science.PeakOil = 0.000000 kg/m3
2019-08-07T16:19:00.335Z,1565194740.335 [MissionManager](INFO): DefineOutput sci2:Science.PeakOilDepth = 0.000000 m
2019-08-07T16:19:00.342Z,1565194740.342 [MissionManager](INFO): DefineOutput sci2:Science.PeakOilLatitude = nan arcdeg
2019-08-07T16:19:00.348Z,1565194740.348 [MissionManager](INFO): DefineOutput sci2:Science.PeakOilLongitude = nan arcdeg
2019-08-07T16:19:00.351Z,1565194740.351 [MissionManager](INFO): DefineOutput sci2:Science.PeakFDOM = 0.000000 ppb
2019-08-07T16:19:00.354Z,1565194740.354 [MissionManager](INFO): DefineOutput sci2:Science.PeakFDOMDepth = 0.000000 m
2019-08-07T16:19:00.357Z,1565194740.357 [MissionManager](INFO): DefineOutput sci2:Science.PeakFDOMLatitude = nan arcdeg
2019-08-07T16:19:00.360Z,1565194740.360 [MissionManager](INFO): DefineOutput sci2:Science.PeakFDOMLongitude = nan arcdeg
2019-08-07T16:19:00.384Z,1565194740.384 [MissionManager](INFO): DefineOutput sci2:Science.PatchFDOMDistance = nan m
2019-08-07T16:19:00.413Z,1565194740.413 [sci2:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-08-07T16:19:00.438Z,1565194740.438 [sci2:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2019-08-07T16:19:00.482Z,1565194740.482 [sci2:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-08-07T16:19:00.492Z,1565194740.492 [sci2:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-08-07T16:19:00.546Z,1565194740.546 [sci2:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-08-07T16:19:00.568Z,1565194740.568 [MissionManager](INFO): RedefineArg sci2:Science.SampleISUS = value:1 bool
2019-08-07T16:19:00.570Z,1565194740.570 [MissionManager](INFO): RedefineArg sci2:Science.PeakDetectChlActive = value:1 bool
2019-08-07T16:19:00.570Z,1565194740.570 [MissionManager](INFO): Inserting Stack: Missions/Insert/NeedComms.xml
2019-08-07T16:19:00.675Z,1565194740.675 [MissionManager](INFO): DefineArg sci2:NeedComms.DiveInterval = 3.000000 h
2019-08-07T16:19:00.678Z,1565194740.678 [MissionManager](INFO): DefineArg sci2:NeedComms.WaitForPitchUp = 10.000000 min
2019-08-07T16:19:00.681Z,1565194740.681 [MissionManager](INFO): DefineArg sci2:NeedComms.SurfacePitch = 20.000000 arcdeg
2019-08-07T16:19:00.684Z,1565194740.684 [MissionManager](INFO): DefineArg sci2:NeedComms.SurfaceDepthRate = nan m/s
2019-08-07T16:19:00.707Z,1565194740.707 [MissionManager](INFO): DefineArg sci2:NeedComms.SurfaceSpeed = 1.000000 m/s
2019-08-07T16:19:00.710Z,1565194740.710 [MissionManager](INFO): DefineArg sci2:NeedComms.GPSTimeout = 7.000000 min
2019-08-07T16:19:00.713Z,1565194740.713 [MissionManager](INFO): DefineArg sci2:NeedComms.CommsTimeout = 30.000000 min
2019-08-07T16:19:00.719Z,1565194740.719 [sci2:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-08-07T16:19:00.755Z,1565194740.755 [MissionManager](INFO): Inserting Stack: Missions/Insert/StandardEnvelopes.xml
2019-08-07T16:19:00.791Z,1565194740.791 [MissionManager](INFO): DefineArg sci2:StandardEnvelopes.MinAltitude = 5.000000 m
2019-08-07T16:19:00.794Z,1565194740.794 [MissionManager](INFO): DefineArg sci2:StandardEnvelopes.MaxDepth = 200.000000 m
2019-08-07T16:19:00.796Z,1565194740.796 [MissionManager](INFO): DefineArg sci2:StandardEnvelopes.MinOffshore = 2000.000000 m
2019-08-07T16:19:00.812Z,1565194740.812 [sci2:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2019-08-07T16:19:00.819Z,1565194740.819 [sci2:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2019-08-07T16:19:00.839Z,1565194740.839 [sci2:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2019-08-07T16:19:00.879Z,1565194740.879 [sci2:I.Pitch](DEBUG): Construct.
2019-08-07T16:19:00.885Z,1565194740.885 [sci2:J.Buoyancy](DEBUG): Construct Buoyancy.
2019-08-07T16:19:00.888Z,1565194740.888 [sci2:K.SetSpeed](DEBUG): Construct.
2019-08-07T16:19:00.904Z,1565194740.904 [sci2:L.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2019-08-07T16:19:00.966Z,1565194740.966 [sci2:M.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2019-08-07T16:19:00.989Z,1565194740.989 [sci2:N.YoYo](DEBUG): Construct YoYo.
2019-08-07T16:19:01.006Z,1565194741.006 [sci2:Lap:Wpt1:A.Waypoint](DEBUG): Construct Waypoint.
2019-08-07T16:19:01.033Z,1565194741.033 [sci2:Lap:Wpt2:A.Waypoint](DEBUG): Construct Waypoint.
2019-08-07T16:19:01.050Z,1565194741.050 [sci2:Lap:Wpt3:A.Waypoint](DEBUG): Construct Waypoint.
2019-08-07T16:19:01.056Z,1565194741.056 [sci2:Lap:Wpt4:A.Waypoint](DEBUG): Construct Waypoint.
2019-08-07T16:19:01.083Z,1565194741.083 [sci2:Lap:Wpt5:A.Waypoint](DEBUG): Construct Waypoint.
2019-08-07T16:19:01.100Z,1565194741.100 [sci2:Lap:Wpt6:A.Waypoint](DEBUG): Construct Waypoint.
2019-08-07T16:19:01.108Z,1565194741.108 [sci2:Lap:Wpt7:A.Waypoint](DEBUG): Construct Waypoint.
2019-08-07T16:19:01.188Z,1565194741.188 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<!-- ====================
     Generated by TethysL
     ==================== -->
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Control="Tethys/Control"
         xmlns:Guidance="Tethys/Guidance"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd"
       Id="sci2">

    <Description>
        Vehicle yo-yo's to the specified waypoints, with science turned on.
    </Description>
    <DefineArg Name="MissionTimeout"><Description>
        Maximum duration of mission
    </Description><Units:hour/><Value>2</Value></DefineArg>

    <DefineArg Name="NeedCommsTime"><Description>
        How often to surface for commumications
    </Description><Units:minute/><Value>60</Value></DefineArg>

    <DefineArg Name="Repeat"><Description>
        Number of times the vehicle should try to cycle through waypoints..
    </Description><Units:count/><Value>1</Value></DefineArg>

    <DefineArg Name="Lat1"><Description>
        Latitude of waypoint 1. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon1"><Description>
        Longitude of waypoint 1. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lat2"><Description>
        Latitude of waypoint 2. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon2"><Description>
        Longitude of waypoint 2. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lat3"><Description>
        Latitude of waypoint 3. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon3"><Description>
        Longitude of waypoint 3. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lat4"><Description>
        Latitude of waypoint 4. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon4"><Description>
        Longitude of waypoint 4. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lat5"><Description>
        Latitude of waypoint 5. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon5"><Description>
        Longitude of waypoint 5. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lat6"><Description>
        Latitude of waypoint 6. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon6"><Description>
        Longitude of waypoint 6. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lat7"><Description>
        Latitude of waypoint 7. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon7"><Description>
        Longitude of waypoint 7. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Speed"><Description>
        Speed while performing the YoYo behavior.
    </Description><Units:meter_per_second/><Value>1</Value></DefineArg>

    <DefineArg Name="CaptureRadius"><Description>
        Speed while performing the YoYo behavior.
    </Description><Units:meter/><Value>NaN</Value></DefineArg>

    
    <DefineArg Name="YoYoMinDepth"><Description>
        Minimum depth while performing the YoYo behavior.
    </Description><Units:meter/><Value>2</Value></DefineArg>

    <DefineArg Name="YoYoMaxDepth"><Description>
        Maximum depth while performing the YoYo behavior.
    </Description><Units:meter/><Value>200</Value></DefineArg>

    <DefineArg Name="YoYoMinAltitude"><Description>
        Minimum altitude while performing the YoYo behavior (for
        bottom-terminated YoYos).
    </Description><Units:meter/><Value>9</Value></DefineArg>

    <DefineArg Name="YoYoUpPitch"><Description>
        Vehicle up pitch while performing the YoYo behavior.
    </Description><Units:degree/><Value>20</Value></DefineArg>

    <DefineArg Name="YoYoDownPitch"><Description>
        Vehicle down pitch while performing the YoYo behavior.
    </Description><Units:degree/><Value>-20</Value></DefineArg>

    <DefineArg Name="BuoyancyNeutral"><Description>
        Buoyancy bladder position while performing the YoYo behavior. Defaults
        to buoyancyNeutral setting in the Config/Control.cfg file. Set to NaN cc
        for active buoyancy
    </Description><Control:VerticalControl.buoyancyNeutral/></DefineArg>

    <DefineArg Name="MassDefault"><Description>
        Static setting for mass during the mission. Set to NaN mm for active
        mass position
    </Description><Control:VerticalControl.massDefault/></DefineArg>

    <DefineArg Name="MinAltitude"><Description>
        Minimum height above the sea floor for the entire mission.
    </Description><Units:meter/><Value>5</Value></DefineArg>

    <DefineArg Name="MaxDepth"><Description>
        Maximum depth for the entire mission.
    </Description><Units:meter/><Value>205</Value></DefineArg>

    <DefineArg Name="MinOffshore"><Description>
        Minimum offshore distance for the entire mission.
    </Description><Units:kilometer/><Value>2</Value></DefineArg>
    <Timeout Duration="MissionTimeout"/>

    <Insert Filename="Insert/Science.xml">
        <Description>
            Most missions will run the science sensors. If you don't place this
            aggregate above NeedComms, science instruments get turned off on the
            last upcast and while floating on the surface.
        </Description>
        <RedefineArg Name="SampleISUS"><True/></RedefineArg>
        <RedefineArg Name="PeakDetectChlActive"><True/></RedefineArg>
    </Insert>

    <Insert Filename="Insert/NeedComms.xml" Id="NeedComms"/>

    <Assign><Sequence/><Arg Name="NeedComms:DiveInterval"/><Arg Name="NeedCommsTime"/></Assign>

    <Insert Filename="Insert/StandardEnvelopes.xml"/>

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MinAltitude"/><Arg Name="MinAltitude"/></Assign>

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MaxDepth"/><Arg Name="MaxDepth"/></Assign>

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MinOffshore"/><Arg Name="MinOffshore"/></Assign>

    <Call Id="StartingMission" RefId="NeedComms"/>

    <Guidance:Pitch>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Arg Name="MassDefault"/></Setting>
    </Guidance:Pitch>

    <Guidance:Buoyancy>
        <Parallel/>
        <Setting><Guidance:Buoyancy.position/><Arg Name="BuoyancyNeutral"/></Setting>
    </Guidance:Buoyancy>

    <Guidance:SetSpeed>
        <Parallel/>
        <Setting><Guidance:SetSpeed.speed/><Arg Name="Speed"/></Setting>
    </Guidance:SetSpeed>

    <Guidance:DepthEnvelope>
        <Description>
            Another depth envelope for the YoYo behavior. This envelope should
            fall within the limits of the standard safety envelopes in
            Insert/StandardEnvelopes.xml in order to avoid commanding high pitch
            angles for depth-terminated YoYos.
        </Description>
        <Parallel/>
        <Setting><Guidance:DepthEnvelope.minDepth/><Arg Name="YoYoMinDepth"/></Setting>
        <Setting><Guidance:DepthEnvelope.maxDepth/><Arg Name="YoYoMaxDepth"/></Setting>
        <Setting><Guidance:DepthEnvelope.downPitch/><Arg Name="YoYoDownPitch"/></Setting>
        <Setting><Guidance:DepthEnvelope.upPitch/><Arg Name="YoYoUpPitch"/></Setting>
    </Guidance:DepthEnvelope>

    <Guidance:AltitudeEnvelope>
        <Description>
            Another altitude envelope for the YoYo behavior. This envelope
            should fall within the limits of the standard safety envelopes in
            Insert/StandardEnvelopes.xml in order to avoid commanding high pitch
            angles for bottom-terminated YoYos.
        </Description>
        <Parallel/>
        <Setting><Guidance:AltitudeEnvelope.minAltitude/><Arg Name="YoYoMinAltitude"/></Setting>
        <Setting><Guidance:AltitudeEnvelope.upPitch/><Arg Name="YoYoUpPitch"/></Setting>
    </Guidance:AltitudeEnvelope>

    <Guidance:YoYo>
        <Parallel/>
        <Setting><Guidance:YoYo.downPitch/><Arg Name="YoYoDownPitch"/></Setting>
        <Setting><Guidance:YoYo.upPitch/><Arg Name="YoYoUpPitch"/></Setting>
    </Guidance:YoYo>

    <Aggregate Id="Lap">
        <Sequence Repeat="Repeat"/>

        <Aggregate Id="Wpt1">
            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat1"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon1"/></Setting>
                <Setting><Guidance:Waypoint.captureRadius/><Arg Name="CaptureRadius"/></Setting>
            </Guidance:Waypoint>
        </Aggregate>

        <Aggregate Id="Wpt2">
            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat2"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon2"/></Setting>
            </Guidance:Waypoint>
        </Aggregate>

        <Aggregate Id="Wpt3">
            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat3"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon3"/></Setting>
            </Guidance:Waypoint>
        </Aggregate>

        <Aggregate Id="Wpt4">
            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat4"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon4"/></Setting>
            </Guidance:Waypoint>
        </Aggregate>

        <Aggregate Id="Wpt5">
            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat5"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon5"/></Setting>
            </Guidance:Waypoint>
        </Aggregate>

        <Aggregate Id="Wpt6">
            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat6"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon6"/></Setting>
            </Guidance:Waypoint>
        </Aggregate>

        <Aggregate Id="Wpt7">
            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat7"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon7"/></Setting>
            </Guidance:Waypoint>
        </Aggregate>
    </Aggregate>
</Mission>


2019-08-07T16:19:01.189Z,1565194741.189 [CommandLine](IMPORTANT): Loaded ./Missions/Science/sci2.xml
2019-08-07T16:19:08.450Z,1565194748.450 [CommandLine](IMPORTANT): got command set sci2.NeedCommsTime 20.000000 minute
2019-08-07T16:19:08.451Z,1565194748.451 [CommandLine](IMPORTANT): got command set sci2.Lat1 36.797001 degree
2019-08-07T16:19:08.451Z,1565194748.451 [CommandLine](IMPORTANT): got command set sci2.Lon1 -121.847000 degree
2019-08-07T16:19:08.452Z,1565194748.452 [CommandLine](IMPORTANT): got command set sci2.YoYoMaxDepth 20.000000 meter
2019-08-07T16:19:08.453Z,1565194748.453 [CommandLine](IMPORTANT): got command set sci2.MaxDepth 30.000000 meter
2019-08-07T16:19:08.453Z,1565194748.453 [CommandLine](IMPORTANT): got command run 
2019-08-07T16:19:08.456Z,1565194748.456 [CommandLine](IMPORTANT): Running 
2019-08-07T16:19:08.645Z,1565194748.645 [Default] Stopped
2019-08-07T16:19:08.645Z,1565194748.645 [Default](DEBUG): Aggregate::uninitialize Default
2019-08-07T16:19:08.645Z,1565194748.645 [Default:B.GoToSurface] Stopped
2019-08-07T16:19:08.645Z,1565194748.645 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-08-07T16:19:08.645Z,1565194748.645 [Default:CheckIn] Stopped
2019-08-07T16:19:08.654Z,1565194748.654 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-07T16:19:08.654Z,1565194748.654 [Default:CheckIn:Read_Iridium] Stopped
2019-08-07T16:19:08.654Z,1565194748.654 [MissionManager](IMPORTANT): Started mission sci2
2019-08-07T16:19:08.654Z,1565194748.654 [sci2] Running Loop=1
2019-08-07T16:19:08.654Z,1565194748.654 [sci2](DEBUG): Aggregate::initialize sci2
2019-08-07T16:19:08.654Z,1565194748.654 [sci2:Science] Running Loop=1
2019-08-07T16:19:08.654Z,1565194748.654 [sci2:Science](DEBUG): Aggregate::initialize sci2:Science
2019-08-07T16:19:08.655Z,1565194748.655 [sci2:Science:A] Running Loop=1
2019-08-07T16:19:08.655Z,1565194748.655 [sci2:Science:B] Running Loop=1
2019-08-07T16:19:08.655Z,1565194748.655 [sci2:Science:C] Running Loop=1
2019-08-07T16:19:08.655Z,1565194748.655 [sci2:Science:D] Running Loop=1
2019-08-07T16:19:08.655Z,1565194748.655 [sci2:Science:E] Running Loop=1
2019-08-07T16:19:08.655Z,1565194748.655 [sci2:Science:F] Running Loop=1
2019-08-07T16:19:08.655Z,1565194748.655 [sci2:Science:G] Running Loop=1
2019-08-07T16:19:08.655Z,1565194748.655 [sci2:Science:H] Running Loop=1
2019-08-07T16:19:08.655Z,1565194748.655 [sci2:Science:Read_Oil] Running Loop=1
2019-08-07T16:19:08.655Z,1565194748.655 [sci2:Science:PeakDetectChl] Running Loop=1
2019-08-07T16:19:08.655Z,1565194748.655 [sci2:Science:PeakDetectChl](DEBUG): Aggregate::initialize sci2:Science:PeakDetectChl
2019-08-07T16:19:08.655Z,1565194748.655 [sci2:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2019-08-07T16:19:08.655Z,1565194748.655 [sci2:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-08-07T16:19:08.666Z,1565194748.666 [sci2:Science:HighestChlPeakReport] Running Loop=1
2019-08-07T16:19:08.666Z,1565194748.666 [sci2:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize sci2:Science:HighestChlPeakReport
2019-08-07T16:19:08.666Z,1565194748.666 [sci2:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2019-08-07T16:19:08.666Z,1565194748.666 [sci2:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2019-08-07T16:19:08.666Z,1565194748.666 [sci2:Science:PeakDetectNO3] Running Loop=1
2019-08-07T16:19:08.667Z,1565194748.667 [sci2:Science:PeakDetectNO3](DEBUG): Aggregate::initialize sci2:Science:PeakDetectNO3
2019-08-07T16:19:08.667Z,1565194748.667 [sci2:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2019-08-07T16:19:08.667Z,1565194748.667 [sci2:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-08-07T16:19:08.669Z,1565194748.669 [sci2:Science:PeakDetectOil] Running Loop=1
2019-08-07T16:19:08.669Z,1565194748.669 [sci2:Science:PeakDetectOil](DEBUG): Aggregate::initialize sci2:Science:PeakDetectOil
2019-08-07T16:19:08.669Z,1565194748.669 [sci2:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2019-08-07T16:19:08.669Z,1565194748.669 [sci2:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-08-07T16:19:08.676Z,1565194748.676 [sci2:Science:PeakDetectFDOM] Running Loop=1
2019-08-07T16:19:08.676Z,1565194748.676 [sci2:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize sci2:Science:PeakDetectFDOM
2019-08-07T16:19:08.676Z,1565194748.676 [sci2:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1
2019-08-07T16:19:08.676Z,1565194748.676 [sci2:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-08-07T16:19:08.690Z,1565194748.690 [sci2:StandardEnvelopes] Running Loop=1
2019-08-07T16:19:08.690Z,1565194748.690 [sci2:StandardEnvelopes](DEBUG): Aggregate::initialize sci2:StandardEnvelopes
2019-08-07T16:19:08.691Z,1565194748.691 [sci2:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2019-08-07T16:19:08.691Z,1565194748.691 [sci2:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2019-08-07T16:19:08.691Z,1565194748.691 [sci2:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2019-08-07T16:19:08.691Z,1565194748.691 [sci2:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2019-08-07T16:19:08.691Z,1565194748.691 [sci2:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2019-08-07T16:19:08.691Z,1565194748.691 [sci2:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2019-08-07T16:19:08.691Z,1565194748.691 [sci2:I.Pitch] Running Loop=1
2019-08-07T16:19:08.691Z,1565194748.691 [sci2:I.Pitch](DEBUG): Initialize.
2019-08-07T16:19:08.692Z,1565194748.692 [sci2:J.Buoyancy] Running Loop=1
2019-08-07T16:19:08.692Z,1565194748.692 [sci2:J.Buoyancy](DEBUG): Initialize Buoyancy Component.
2019-08-07T16:19:08.692Z,1565194748.692 [sci2:K.SetSpeed] Running Loop=1
2019-08-07T16:19:08.692Z,1565194748.692 [sci2:K.SetSpeed](DEBUG): Initialize.
2019-08-07T16:19:08.692Z,1565194748.692 [sci2:L.DepthEnvelope] Running Loop=1
2019-08-07T16:19:08.692Z,1565194748.692 [sci2:L.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2019-08-07T16:19:08.692Z,1565194748.692 [sci2:M.AltitudeEnvelope] Running Loop=1
2019-08-07T16:19:08.692Z,1565194748.692 [sci2:M.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2019-08-07T16:19:08.693Z,1565194748.693 [sci2:N.YoYo] Running Loop=1
2019-08-07T16:19:08.693Z,1565194748.693 [sci2:N.YoYo](DEBUG): Initialize YoYoComponent.
2019-08-07T16:19:08.693Z,1565194748.693 [sci2:C] Running Loop=1
2019-08-07T16:19:08.702Z,1565194748.702 [sci2:N.YoYo] Running Loop=1
2019-08-07T16:19:08.702Z,1565194748.702 [sci2:M.AltitudeEnvelope] Running Loop=1
2019-08-07T16:19:08.703Z,1565194748.703 [sci2:L.DepthEnvelope] Running Loop=1
2019-08-07T16:19:08.704Z,1565194748.704 [sci2:K.SetSpeed] Running Loop=1
2019-08-07T16:19:08.704Z,1565194748.704 [sci2:J.Buoyancy] Running Loop=1
2019-08-07T16:19:08.705Z,1565194748.705 [sci2:I.Pitch] Running Loop=1
2019-08-07T16:19:08.705Z,1565194748.705 [sci2:StandardEnvelopes] Running Loop=1
2019-08-07T16:19:08.705Z,1565194748.705 [sci2:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2019-08-07T16:19:08.738Z,1565194748.738 [sci2:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2019-08-07T16:19:08.738Z,1565194748.738 [sci2:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2019-08-07T16:19:08.739Z,1565194748.739 [sci2:C] Stopped
2019-08-07T16:19:08.739Z,1565194748.739 [sci2:E] Running Loop=1
2019-08-07T16:19:08.739Z,1565194748.739 [sci2:Science] Running Loop=1
2019-08-07T16:19:08.740Z,1565194748.740 [sci2:Science:PeakDetectFDOM] Stopped
2019-08-07T16:19:08.740Z,1565194748.740 [sci2:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize sci2:Science:PeakDetectFDOM
2019-08-07T16:19:08.740Z,1565194748.740 [sci2:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped
2019-08-07T16:19:08.740Z,1565194748.740 [sci2:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-08-07T16:19:08.740Z,1565194748.740 [sci2:Science:PeakDetectOil] Stopped
2019-08-07T16:19:08.741Z,1565194748.741 [sci2:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize sci2:Science:PeakDetectOil
2019-08-07T16:19:08.741Z,1565194748.741 [sci2:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2019-08-07T16:19:08.741Z,1565194748.741 [sci2:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-08-07T16:19:08.741Z,1565194748.741 [sci2:Science:PeakDetectNO3] Stopped
2019-08-07T16:19:08.741Z,1565194748.741 [sci2:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize sci2:Science:PeakDetectNO3
2019-08-07T16:19:08.741Z,1565194748.741 [sci2:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2019-08-07T16:19:08.741Z,1565194748.741 [sci2:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-08-07T16:19:08.741Z,1565194748.741 [sci2:Science:HighestChlPeakReport] Stopped
2019-08-07T16:19:08.749Z,1565194748.749 [sci2:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize sci2:Science:HighestChlPeakReport
2019-08-07T16:19:08.750Z,1565194748.750 [sci2:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2019-08-07T16:19:08.750Z,1565194748.750 [sci2:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2019-08-07T16:19:08.750Z,1565194748.750 [sci2:Science:PeakDetectChl] Running Loop=1
2019-08-07T16:19:08.750Z,1565194748.750 [sci2:Science:Read_Oil] Stopped
2019-08-07T16:19:08.750Z,1565194748.750 [sci2:Science:H] Stopped
2019-08-07T16:19:08.750Z,1565194748.750 [sci2:Science:G] Running Loop=1
2019-08-07T16:19:08.751Z,1565194748.751 [sci2:Science:G](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2019-08-07T16:19:08.751Z,1565194748.751 [sci2:Science:F] Stopped
2019-08-07T16:19:08.751Z,1565194748.751 [sci2:Science:E] Stopped
2019-08-07T16:19:08.751Z,1565194748.751 [sci2:Science:D] Running Loop=1
2019-08-07T16:19:08.752Z,1565194748.752 [sci2:Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature
2019-08-07T16:19:08.752Z,1565194748.752 [sci2:Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity
2019-08-07T16:19:08.753Z,1565194748.753 [sci2:Science:C] Running Loop=1
2019-08-07T16:19:08.761Z,1565194748.761 [sci2:Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature
2019-08-07T16:19:08.770Z,1565194748.770 [sci2:Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity
2019-08-07T16:19:08.770Z,1565194748.770 [sci2:Science:B] Stopped
2019-08-07T16:19:08.770Z,1565194748.770 [sci2:Science:A] Running Loop=1
2019-08-07T16:19:08.771Z,1565194748.771 [sci2:Science:A](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_oxygen_in_sea_water
2019-08-07T16:19:08.823Z,1565194748.823 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=2
2019-08-07T16:19:08.823Z,1565194748.823 [WetLabsBB2FL](INFO): Powering up
2019-08-07T16:19:08.878Z,1565194748.878 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2019-08-07T16:19:08.879Z,1565194748.879 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2019-08-07T16:19:09.063Z,1565194749.063 [sci2:E] Stopped
2019-08-07T16:19:09.064Z,1565194749.064 [sci2:F] Running Loop=1
2019-08-07T16:19:09.303Z,1565194749.303 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-08-07T16:19:09.440Z,1565194749.440 [sci2:F] Stopped
2019-08-07T16:19:09.440Z,1565194749.440 [sci2:G] Running Loop=1
2019-08-07T16:19:09.861Z,1565194749.861 [sci2:G] Stopped
2019-08-07T16:19:09.862Z,1565194749.862 [sci2:StartingMission] Running Loop=1
2019-08-07T16:19:09.862Z,1565194749.862 [sci2:StartingMission](DEBUG): Aggregate::initialize sci2:StartingMission
2019-08-07T16:19:10.256Z,1565194750.256 [sci2:M.AltitudeEnvelope](ERROR): Altitude Measurement is not Active.
2019-08-07T16:19:10.278Z,1565194750.278 [sci2:StandardEnvelopes:A.AltitudeEnvelope](ERROR): Altitude Measurement is not Active.
2019-08-07T16:19:10.278Z,1565194750.278 [sci2:NeedComms] Running Loop=1
2019-08-07T16:19:10.278Z,1565194750.278 [sci2:NeedComms](DEBUG): Aggregate::initialize sci2:NeedComms
2019-08-07T16:19:10.278Z,1565194750.278 [sci2:NeedComms:B.GoToSurface] Running Loop=1
2019-08-07T16:19:10.279Z,1565194750.279 [sci2:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-08-07T16:19:10.279Z,1565194750.279 [sci2:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2019-08-07T16:19:10.279Z,1565194750.279 [sci2:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2019-08-07T16:19:10.280Z,1565194750.280 [sci2:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2019-08-07T16:19:10.280Z,1565194750.280 [sci2:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-08-07T16:19:10.280Z,1565194750.280 [sci2:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-08-07T16:19:10.281Z,1565194750.281 [sci2:NeedComms:A] Running Loop=1
2019-08-07T16:19:10.286Z,1565194750.286 [sci2:NeedComms:A](INFO): last time_fix was: 1565194722.000000 second since 1970/01/01T00:00:00Z 
2019-08-07T16:19:10.286Z,1565194750.286 [sci2:NeedComms:A] Stopped
2019-08-07T16:19:10.511Z,1565194750.511 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.657700 psu
2019-08-07T16:19:10.777Z,1565194750.777 [sci2:NeedComms:C] Running Loop=1
2019-08-07T16:19:11.124Z,1565194751.124 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:11.139Z,1565194751.139 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.649300 psu
2019-08-07T16:19:11.156Z,1565194751.156 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:11.204Z,1565194751.204 [sci2:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-08-07T16:19:11.327Z,1565194751.327 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.653900 psu
2019-08-07T16:19:11.331Z,1565194751.331 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:11.531Z,1565194751.531 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.653200 psu
2019-08-07T16:19:11.535Z,1565194751.535 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:11.739Z,1565194751.739 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.651100 psu
2019-08-07T16:19:11.743Z,1565194751.743 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:11.943Z,1565194751.943 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.651500 psu
2019-08-07T16:19:11.947Z,1565194751.947 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:12.147Z,1565194752.147 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.652000 psu
2019-08-07T16:19:12.151Z,1565194752.151 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:12.294Z,1565194752.294 [NAL9602](DEBUG): Fix Requested
2019-08-07T16:19:12.314Z,1565194752.314 [CTD_Seabird](ERROR): Failed to parse device response: <!--startlogging-->
2019-08-07T16:19:12.354Z,1565194752.354 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.652200 psu
2019-08-07T16:19:12.364Z,1565194752.364 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:12.555Z,1565194752.555 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.649400 psu
2019-08-07T16:19:12.559Z,1565194752.559 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:12.689Z,1565194752.689 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161906.00,A,3648.14254,N,12147.22772,W,0.194,0.00,070819,,,A*72
2019-08-07T16:19:12.691Z,1565194752.691 [NAL9602](INFO): GPS fix at 20190807T161906: (36.802376, -121.787129)
2019-08-07T16:19:12.763Z,1565194752.763 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.648800 psu
2019-08-07T16:19:12.767Z,1565194752.767 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:12.786Z,1565194752.786 [sci2:NeedComms:C] Stopped
2019-08-07T16:19:12.786Z,1565194752.786 [sci2:NeedComms:D] Running Loop=1
2019-08-07T16:19:12.963Z,1565194752.963 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.648200 psu
2019-08-07T16:19:12.967Z,1565194752.967 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:13.167Z,1565194753.167 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.646500 psu
2019-08-07T16:19:13.171Z,1565194753.171 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:13.206Z,1565194753.206 [sci2:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-08-07T16:19:13.373Z,1565194753.373 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.644400 psu
2019-08-07T16:19:13.378Z,1565194753.378 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:13.590Z,1565194753.590 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.644100 psu
2019-08-07T16:19:13.596Z,1565194753.596 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:13.790Z,1565194753.790 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.642900 psu
2019-08-07T16:19:13.794Z,1565194753.794 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:14.009Z,1565194754.009 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.640200 psu
2019-08-07T16:19:14.012Z,1565194754.012 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:14.210Z,1565194754.210 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.641500 psu
2019-08-07T16:19:14.214Z,1565194754.214 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:14.323Z,1565194754.323 [CTD_Seabird](ERROR): Salinity reading out of range: 16.226942 psu
2019-08-07T16:19:14.414Z,1565194754.414 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.639800 psu
2019-08-07T16:19:14.418Z,1565194754.418 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:14.630Z,1565194754.630 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.638300 psu
2019-08-07T16:19:14.635Z,1565194754.635 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:14.834Z,1565194754.834 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.641200 psu
2019-08-07T16:19:14.838Z,1565194754.838 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:15.207Z,1565194755.207 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.638900 psu
2019-08-07T16:19:15.211Z,1565194755.211 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:15.327Z,1565194755.327 [CTD_Seabird](ERROR): Salinity reading out of range: 16.302233 psu
2019-08-07T16:19:15.411Z,1565194755.411 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.639200 psu
2019-08-07T16:19:15.415Z,1565194755.415 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:15.615Z,1565194755.615 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.644500 psu
2019-08-07T16:19:15.621Z,1565194755.621 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:15.819Z,1565194755.819 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.636500 psu
2019-08-07T16:19:15.823Z,1565194755.823 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:16.023Z,1565194756.023 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.633400 psu
2019-08-07T16:19:16.027Z,1565194756.027 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:16.227Z,1565194756.227 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.633800 psu
2019-08-07T16:19:16.231Z,1565194756.231 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:16.331Z,1565194756.331 [CTD_Seabird](ERROR): Salinity reading out of range: 16.333570 psu
2019-08-07T16:19:16.431Z,1565194756.431 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.635400 psu
2019-08-07T16:19:16.435Z,1565194756.435 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:16.635Z,1565194756.635 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.635000 psu
2019-08-07T16:19:16.641Z,1565194756.641 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:16.839Z,1565194756.839 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.634500 psu
2019-08-07T16:19:16.844Z,1565194756.844 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:17.043Z,1565194757.043 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.633000 psu
2019-08-07T16:19:17.047Z,1565194757.047 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:17.247Z,1565194757.247 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.632400 psu
2019-08-07T16:19:17.251Z,1565194757.251 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:17.335Z,1565194757.335 [CTD_Seabird](ERROR): Salinity reading out of range: 16.323195 psu
2019-08-07T16:19:17.451Z,1565194757.451 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.631700 psu
2019-08-07T16:19:17.455Z,1565194757.455 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:17.461Z,1565194757.461 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190807T151639/Courier0025.lzma
2019-08-07T16:19:17.655Z,1565194757.655 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.629500 psu
2019-08-07T16:19:17.661Z,1565194757.661 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:17.860Z,1565194757.860 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.630600 psu
2019-08-07T16:19:17.868Z,1565194757.868 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:18.063Z,1565194758.063 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.630900 psu
2019-08-07T16:19:18.067Z,1565194758.067 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:18.267Z,1565194758.267 [DataOverHttps](INFO): Moved sent file to Logs/20190807T151639/Courier0025.lzma.bak
2019-08-07T16:19:18.268Z,1565194758.268 [DataOverHttps](IMPORTANT): SBD MOMSN=11534829, MTMSN=20190807T161912
2019-08-07T16:19:18.273Z,1565194758.273 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.629600 psu
2019-08-07T16:19:18.276Z,1565194758.276 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:18.339Z,1565194758.339 [CTD_Seabird](ERROR): Salinity reading out of range: 16.322205 psu
2019-08-07T16:19:18.475Z,1565194758.475 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.623600 psu
2019-08-07T16:19:18.479Z,1565194758.479 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:18.883Z,1565194758.883 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.626400 psu
2019-08-07T16:19:18.887Z,1565194758.887 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:19.087Z,1565194759.087 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.618100 psu
2019-08-07T16:19:19.091Z,1565194759.091 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:19.291Z,1565194759.291 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.624300 psu
2019-08-07T16:19:19.295Z,1565194759.295 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:19.344Z,1565194759.344 [CTD_Seabird](ERROR): Salinity reading out of range: 16.296429 psu
2019-08-07T16:19:19.495Z,1565194759.495 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.624900 psu
2019-08-07T16:19:19.499Z,1565194759.499 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:19.700Z,1565194759.700 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.627500 psu
2019-08-07T16:19:19.705Z,1565194759.705 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:19.903Z,1565194759.903 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.628400 psu
2019-08-07T16:19:19.907Z,1565194759.907 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:20.107Z,1565194760.107 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.629500 psu
2019-08-07T16:19:20.111Z,1565194760.111 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:20.311Z,1565194760.311 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.631600 psu
2019-08-07T16:19:20.315Z,1565194760.315 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:20.352Z,1565194760.352 [CTD_Seabird](ERROR): Salinity reading out of range: 16.286600 psu
2019-08-07T16:19:20.515Z,1565194760.515 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.631500 psu
2019-08-07T16:19:20.521Z,1565194760.521 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:20.720Z,1565194760.720 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.631200 psu
2019-08-07T16:19:20.725Z,1565194760.725 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:20.923Z,1565194760.923 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.632600 psu
2019-08-07T16:19:20.927Z,1565194760.927 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:21.127Z,1565194761.127 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.637900 psu
2019-08-07T16:19:21.131Z,1565194761.131 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:21.331Z,1565194761.331 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.636200 psu
2019-08-07T16:19:21.335Z,1565194761.335 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:21.352Z,1565194761.352 [CTD_Seabird](ERROR): Salinity reading out of range: 16.277058 psu
2019-08-07T16:19:21.739Z,1565194761.739 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.636500 psu
2019-08-07T16:19:21.743Z,1565194761.743 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:21.944Z,1565194761.944 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.635800 psu
2019-08-07T16:19:21.957Z,1565194761.957 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:22.147Z,1565194762.147 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.640300 psu
2019-08-07T16:19:22.151Z,1565194762.151 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:22.352Z,1565194762.352 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.640100 psu
2019-08-07T16:19:22.356Z,1565194762.356 [CTD_Seabird](ERROR): Salinity reading out of range: 16.289957 psu
2019-08-07T16:19:22.363Z,1565194762.363 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:22.555Z,1565194762.555 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.638800 psu
2019-08-07T16:19:22.559Z,1565194762.559 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:22.759Z,1565194762.759 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.638700 psu
2019-08-07T16:19:22.763Z,1565194762.763 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:22.963Z,1565194762.963 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.638300 psu
2019-08-07T16:19:22.967Z,1565194762.967 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:23.167Z,1565194763.167 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.639500 psu
2019-08-07T16:19:23.171Z,1565194763.171 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:23.360Z,1565194763.360 [CTD_Seabird](ERROR): Salinity reading out of range: 16.288383 psu
2019-08-07T16:19:23.372Z,1565194763.372 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.634200 psu
2019-08-07T16:19:23.376Z,1565194763.376 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:23.575Z,1565194763.575 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.650000 psu
2019-08-07T16:19:23.579Z,1565194763.579 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:23.779Z,1565194763.779 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.635500 psu
2019-08-07T16:19:23.783Z,1565194763.783 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:23.983Z,1565194763.983 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.640300 psu
2019-08-07T16:19:23.987Z,1565194763.987 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:24.187Z,1565194764.187 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.640300 psu
2019-08-07T16:19:24.191Z,1565194764.191 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:24.364Z,1565194764.364 [CTD_Seabird](ERROR): Salinity reading out of range: 16.283640 psu
2019-08-07T16:19:24.391Z,1565194764.391 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.641600 psu
2019-08-07T16:19:24.395Z,1565194764.395 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:24.596Z,1565194764.596 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.643600 psu
2019-08-07T16:19:24.600Z,1565194764.600 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:24.799Z,1565194764.799 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.642900 psu
2019-08-07T16:19:24.807Z,1565194764.807 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:25.014Z,1565194765.014 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.644500 psu
2019-08-07T16:19:25.018Z,1565194765.018 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:25.218Z,1565194765.218 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.647600 psu
2019-08-07T16:19:25.222Z,1565194765.222 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:25.237Z,1565194765.237 [DataOverHttps](INFO): Received command:stop
2019-08-07T16:19:25.302Z,1565194765.302 [CommandLine](IMPORTANT): got command stop
2019-08-07T16:19:25.302Z,1565194765.302 [CommandLine](IMPORTANT): Scheduling is paused
2019-08-07T16:19:25.302Z,1565194765.302 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2019-08-07T16:19:25.368Z,1565194765.368 [CTD_Seabird](ERROR): Salinity reading out of range: 16.292728 psu
2019-08-07T16:19:25.435Z,1565194765.435 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.648200 psu
2019-08-07T16:19:25.439Z,1565194765.439 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-08-07T16:19:25.531Z,1565194765.531 [MissionManager](INFO): MissionManager is completed.
2019-08-07T16:19:25.531Z,1565194765.531 [MissionManager](INFO): Uninitializing Mission sci2
2019-08-07T16:19:25.532Z,1565194765.532 [sci2] Stopped
2019-08-07T16:19:25.532Z,1565194765.532 [sci2](DEBUG): Aggregate::uninitialize sci2
2019-08-07T16:19:25.532Z,1565194765.532 [sci2:Science] Stopped
2019-08-07T16:19:25.532Z,1565194765.532 [sci2:Science](DEBUG): Aggregate::uninitialize sci2:Science
2019-08-07T16:19:25.532Z,1565194765.532 [sci2:Science:A] Stopped
2019-08-07T16:19:25.532Z,1565194765.532 [sci2:Science:C] Stopped
2019-08-07T16:19:25.532Z,1565194765.532 [sci2:Science:D] Stopped
2019-08-07T16:19:25.532Z,1565194765.532 [sci2:Science:G] Stopped
2019-08-07T16:19:25.532Z,1565194765.532 [sci2:Science:PeakDetectChl] Stopped
2019-08-07T16:19:25.532Z,1565194765.532 [sci2:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize sci2:Science:PeakDetectChl
2019-08-07T16:19:25.532Z,1565194765.532 [sci2:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2019-08-07T16:19:25.533Z,1565194765.533 [sci2:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-08-07T16:19:25.533Z,1565194765.533 [sci2:NeedComms] Stopped
2019-08-07T16:19:25.533Z,1565194765.533 [sci2:NeedComms](DEBUG): Aggregate::uninitialize sci2:NeedComms
2019-08-07T16:19:25.533Z,1565194765.533 [sci2:NeedComms:B.GoToSurface] Stopped
2019-08-07T16:19:25.533Z,1565194765.533 [sci2:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-08-07T16:19:25.533Z,1565194765.533 [sci2:NeedComms:D] Stopped
2019-08-07T16:19:25.549Z,1565194765.549 [sci2:StandardEnvelopes] Stopped
2019-08-07T16:19:25.550Z,1565194765.550 [sci2:StandardEnvelopes](DEBUG): Aggregate::uninitialize sci2:StandardEnvelopes
2019-08-07T16:19:25.550Z,1565194765.550 [sci2:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2019-08-07T16:19:25.550Z,1565194765.550 [sci2:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2019-08-07T16:19:25.550Z,1565194765.550 [sci2:StandardEnvelopes:B.DepthEnvelope] Stopped
2019-08-07T16:19:25.550Z,1565194765.550 [sci2:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2019-08-07T16:19:25.550Z,1565194765.550 [sci2:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2019-08-07T16:19:25.550Z,1565194765.550 [sci2:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2019-08-07T16:19:25.550Z,1565194765.550 [sci2:StartingMission] Stopped
2019-08-07T16:19:25.551Z,1565194765.551 [sci2:StartingMission](DEBUG): Aggregate::uninitialize sci2:StartingMission
2019-08-07T16:19:25.551Z,1565194765.551 [sci2:I.Pitch] Stopped
2019-08-07T16:19:25.551Z,1565194765.551 [sci2:J.Buoyancy] Stopped
2019-08-07T16:19:25.551Z,1565194765.551 [sci2:J.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2019-08-07T16:19:25.551Z,1565194765.551 [sci2:K.SetSpeed] Stopped
2019-08-07T16:19:25.551Z,1565194765.551 [sci2:K.SetSpeed](DEBUG): Uninitialize.
2019-08-07T16:19:25.551Z,1565194765.551 [sci2:L.DepthEnvelope] Stopped
2019-08-07T16:19:25.551Z,1565194765.551 [sci2:L.DepthEnvelope](DEBUG): Uninitialize.
2019-08-07T16:19:25.551Z,1565194765.551 [sci2:M.AltitudeEnvelope] Stopped
2019-08-07T16:19:25.551Z,1565194765.551 [sci2:M.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2019-08-07T16:19:25.551Z,1565194765.551 [sci2:N.YoYo] Stopped
2019-08-07T16:19:25.551Z,1565194765.551 [sci2:N.YoYo](DEBUG): Uninitialize YoYoComponent.
2019-08-07T16:19:25.922Z,1565194765.922 [MissionManager](IMPORTANT): Started mission Default
2019-08-07T16:19:25.922Z,1565194765.922 [Default] Running Loop=1
2019-08-07T16:19:25.922Z,1565194765.922 [Default](DEBUG): Aggregate::initialize Default
2019-08-07T16:19:25.922Z,1565194765.922 [Default:B.GoToSurface] Running Loop=1
2019-08-07T16:19:25.922Z,1565194765.922 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-08-07T16:19:25.923Z,1565194765.923 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-08-07T16:19:25.923Z,1565194765.923 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-08-07T16:19:25.923Z,1565194765.923 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-08-07T16:19:25.924Z,1565194765.924 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-08-07T16:19:25.924Z,1565194765.924 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-08-07T16:19:25.924Z,1565194765.924 [Default:A.Wait] Running Loop=1
2019-08-07T16:19:25.924Z,1565194765.924 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-08-07T16:19:26.074Z,1565194766.074 [WetLabsBB2FL](INFO): Powering down
2019-08-07T16:19:26.426Z,1565194766.426 [Aanderaa_O2](INFO): Powering down
2019-08-07T16:19:31.093Z,1565194771.093 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190807T151639/Courier0027.lzma
2019-08-07T16:19:31.899Z,1565194771.899 [DataOverHttps](INFO): Moved sent file to Logs/20190807T151639/Courier0027.lzma.bak
2019-08-07T16:19:31.899Z,1565194771.899 [DataOverHttps](INFO): SBD MOMSN=11534832
2019-08-07T16:19:39.247Z,1565194779.247 [Default:A.Wait](INFO): Done Waiting.
2019-08-07T16:19:39.247Z,1565194779.247 [Default:A.Wait] Stopped
2019-08-07T16:19:39.247Z,1565194779.247 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-08-07T16:19:39.657Z,1565194779.657 [Default:CheckIn] Running Loop=1
2019-08-07T16:19:39.657Z,1565194779.657 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-07T16:19:39.658Z,1565194779.658 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-07T16:19:41.257Z,1565194781.257 [NAL9602](DEBUG): Fix Requested
2019-08-07T16:19:41.652Z,1565194781.652 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161935.00,A,3648.14409,N,12147.22851,W,0.175,0.00,070819,,,A*7D
2019-08-07T16:19:41.655Z,1565194781.655 [NAL9602](INFO): GPS fix at 20190807T161935: (36.802402, -121.787142)
2019-08-07T16:19:41.686Z,1565194781.686 [Default:CheckIn:Read_GPS] Stopped
2019-08-07T16:19:41.686Z,1565194781.686 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-07T16:19:50.371Z,1565194790.371 [DataOverHttps](IMPORTANT): SBD MTMSN=20190807T161944
2019-08-07T16:19:56.957Z,1565194796.957 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190807T151639/Courier0031.lzma
2019-08-07T16:19:56.960Z,1565194796.960 [DataOverHttps](INFO): Received command:ibit
2019-08-07T16:19:57.005Z,1565194797.005 [CommandLine](IMPORTANT): got command ibit
2019-08-07T16:19:57.127Z,1565194797.127 [IBIT](IMPORTANT): Beginning Initiated BIT
2019-08-07T16:19:57.127Z,1565194797.127 [IBIT](IMPORTANT): Beginning control surface checks.
2019-08-07T16:19:57.134Z,1565194797.134 [CBIT](IMPORTANT): Beginning ground fault scan
2019-08-07T16:19:57.764Z,1565194797.764 [DataOverHttps](INFO): Moved sent file to Logs/20190807T151639/Courier0031.lzma.bak
2019-08-07T16:19:57.764Z,1565194797.764 [DataOverHttps](INFO): SBD MOMSN=11534835
2019-08-07T16:19:58.261Z,1565194798.261 [NAL9602](DEBUG): Fix Requested
2019-08-07T16:19:58.656Z,1565194798.656 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161952.00,A,3648.14411,N,12147.22779,W,0.117,0.00,070819,,,A*74
2019-08-07T16:19:58.659Z,1565194798.659 [NAL9602](INFO): GPS fix at 20190807T161952: (36.802402, -121.787130)
2019-08-07T16:20:00.690Z,1565194800.690 [NAL9602](DEBUG): Fix Requested
2019-08-07T16:20:01.080Z,1565194801.080 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161955.00,A,3648.14401,N,12147.22764,W,0.078,0.00,070819,,,A*76
2019-08-07T16:20:01.098Z,1565194801.098 [NAL9602](INFO): GPS fix at 20190807T161955: (36.802400, -121.787127)
2019-08-07T16:20:03.542Z,1565194803.542 [NAL9602](DEBUG): Fix Requested
2019-08-07T16:20:03.940Z,1565194803.940 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161958.00,A,3648.14395,N,12147.22755,W,0.156,0.00,070819,,,A*7E
2019-08-07T16:20:03.943Z,1565194803.943 [NAL9602](INFO): GPS fix at 20190807T161958: (36.802399, -121.787126)
2019-08-07T16:20:06.774Z,1565194806.774 [NAL9602](DEBUG): Fix Requested
2019-08-07T16:20:07.168Z,1565194807.168 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162001.00,A,3648.14397,N,12147.22758,W,0.039,0.00,070819,,,A*7F
2019-08-07T16:20:07.175Z,1565194807.175 [NAL9602](INFO): GPS fix at 20190807T162001: (36.802399, -121.787126)
2019-08-07T16:20:08.041Z,1565194808.041 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.006316
CHAN A1 (24V): -0.134026
CHAN A2 (12V): -0.002139
CHAN A3 (5V): -0.001127
CHAN B0 (3.3V): -0.000195
CHAN B1 (3.15aV): -0.000242
CHAN B2 (3.15bV): -0.000190
CHAN B3 (GND): 0.000250
OPEN: -0.000259
Full Scale Calc: 4.765 mA, -1.589 mA
2019-08-07T16:20:09.602Z,1565194809.602 [NAL9602](DEBUG): Fix Requested
2019-08-07T16:20:10.004Z,1565194810.004 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162004.00,A,3648.14407,N,12147.22765,W,0.233,0.00,070819,,,A*72
2019-08-07T16:20:10.006Z,1565194810.006 [NAL9602](INFO): GPS fix at 20190807T162004: (36.802401, -121.787127)
2019-08-07T16:20:10.037Z,1565194810.037 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190807T151639/Courier0034.lzma
2019-08-07T16:20:10.843Z,1565194810.843 [DataOverHttps](INFO): Moved sent file to Logs/20190807T151639/Courier0034.lzma.bak
2019-08-07T16:20:10.843Z,1565194810.843 [DataOverHttps](INFO): SBD MOMSN=11534839
2019-08-07T16:20:12.429Z,1565194812.429 [NAL9602](DEBUG): Fix Requested
2019-08-07T16:20:12.824Z,1565194812.824 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162007.00,A,3648.14414,N,12147.22776,W,0.272,0.00,070819,,,A*74
2019-08-07T16:20:12.827Z,1565194812.827 [NAL9602](INFO): GPS fix at 20190807T162007: (36.802402, -121.787129)
2019-08-07T16:20:15.662Z,1565194815.662 [NAL9602](DEBUG): Fix Requested
2019-08-07T16:20:16.056Z,1565194816.056 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162010.00,A,3648.14420,N,12147.22784,W,0.136,0.00,070819,,,A*7B
2019-08-07T16:20:16.059Z,1565194816.059 [NAL9602](INFO): GPS fix at 20190807T162010: (36.802403, -121.787131)
2019-08-07T16:20:18.489Z,1565194818.489 [NAL9602](DEBUG): Fix Requested
2019-08-07T16:20:18.888Z,1565194818.888 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162013.00,A,3648.14417,N,12147.22779,W,0.136,0.00,070819,,,A*7E
2019-08-07T16:20:18.891Z,1565194818.891 [NAL9602](INFO): GPS fix at 20190807T162013: (36.802403, -121.787130)
2019-08-07T16:20:21.722Z,1565194821.722 [NAL9602](DEBUG): Fix Requested
2019-08-07T16:20:22.120Z,1565194822.120 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162016.00,A,3648.14420,N,12147.22782,W,0.117,0.00,070819,,,A*78
2019-08-07T16:20:22.123Z,1565194822.123 [NAL9602](INFO): GPS fix at 20190807T162016: (36.802403, -121.787130)
2019-08-07T16:20:22.673Z,1565194822.673 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190807T151639/Courier0037.lzma
2019-08-07T16:20:23.479Z,1565194823.479 [DataOverHttps](INFO): Moved sent file to Logs/20190807T151639/Courier0037.lzma.bak
2019-08-07T16:20:23.479Z,1565194823.479 [DataOverHttps](INFO): SBD MOMSN=11534842
2019-08-07T16:20:24.549Z,1565194824.549 [NAL9602](DEBUG): Fix Requested
2019-08-07T16:20:24.944Z,1565194824.944 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162019.00,A,3648.14414,N,12147.22781,W,0.097,0.00,070819,,,A*7A
2019-08-07T16:20:24.947Z,1565194824.947 [NAL9602](INFO): GPS fix at 20190807T162019: (36.802402, -121.787130)
2019-08-07T16:20:27.782Z,1565194827.782 [NAL9602](DEBUG): Fix Requested
2019-08-07T16:20:28.184Z,1565194828.184 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162022.00,A,3648.14405,N,12147.22779,W,0.058,0.00,070819,,,A*76
2019-08-07T16:20:28.187Z,1565194828.187 [NAL9602](INFO): GPS fix at 20190807T162022: (36.802401, -121.787130)
2019-08-07T16:20:30.666Z,1565194830.666 [NAL9602](DEBUG): Fix Requested
2019-08-07T16:20:31.020Z,1565194831.020 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162025.00,A,3648.14401,N,12147.22785,W,0.233,0.00,070819,,,A*79
2019-08-07T16:20:31.023Z,1565194831.023 [NAL9602](INFO): GPS fix at 20190807T162025: (36.802400, -121.787131)
2019-08-07T16:20:33.466Z,1565194833.466 [NAL9602](DEBUG): Fix Requested
2019-08-07T16:20:33.856Z,1565194833.856 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162028.00,A,3648.14408,N,12147.22785,W,0.019,0.00,070819,,,A*77
2019-08-07T16:20:33.863Z,1565194833.863 [NAL9602](INFO): GPS fix at 20190807T162028: (36.802401, -121.787131)
2019-08-07T16:20:35.534Z,1565194835.534 [CommandLine](IMPORTANT): got command ! echo i > /dev/loadB2
2019-08-07T16:20:36.686Z,1565194836.686 [NAL9602](DEBUG): Fix Requested
2019-08-07T16:20:37.084Z,1565194837.084 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162031.00,A,3648.14402,N,12147.22782,W,0.175,0.00,070819,,,A*79
2019-08-07T16:20:37.087Z,1565194837.087 [NAL9602](INFO): GPS fix at 20190807T162031: (36.802400, -121.787130)
2019-08-07T16:20:39.522Z,1565194839.522 [NAL9602](DEBUG): Fix Requested
2019-08-07T16:20:39.908Z,1565194839.908 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162034.00,A,3648.14391,N,12147.22782,W,0.136,0.00,070819,,,A*76
2019-08-07T16:20:39.915Z,1565194839.915 [NAL9602](INFO): GPS fix at 20190807T162034: (36.802399, -121.787130)
2019-08-07T16:20:42.746Z,1565194842.746 [NAL9602](DEBUG): Fix Requested
2019-08-07T16:20:43.140Z,1565194843.140 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162037.00,A,3648.14392,N,12147.22782,W,0.214,0.00,070819,,,A*75
2019-08-07T16:20:43.144Z,1565194843.144 [NAL9602](INFO): GPS fix at 20190807T162037: (36.802399, -121.787130)
2019-08-07T16:20:43.215Z,1565194843.215 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 2
Latitude: 36.802399 Longitude: -121.787132
2019-08-07T16:20:43.596Z,1565194843.596 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 0.000000
2019-08-07T16:20:43.596Z,1565194843.596 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2019-08-07T16:20:43.596Z,1565194843.596 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2019-08-07T16:20:43.975Z,1565194843.975 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2019-08-07T16:20:43.976Z,1565194843.976 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2019-08-07T16:20:43.976Z,1565194843.976 [IBIT](IMPORTANT): Pressure:8.917581 PSI
2019-08-07T16:20:43.976Z,1565194843.976 [IBIT](IMPORTANT): Humidity:4.364546 %
2019-08-07T16:20:44.384Z,1565194844.384 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2019-08-07T16:20:44.384Z,1565194844.384 [IBIT](IMPORTANT): buoyancyNeutral: 200.000000 cc
2019-08-07T16:20:44.384Z,1565194844.384 [IBIT](IMPORTANT): massDefault: -0.400000 cm
2019-08-07T16:20:44.385Z,1565194844.385 [IBIT](IMPORTANT): stopDepth: 205.000000 m
2019-08-07T16:20:44.385Z,1565194844.385 [IBIT](IMPORTANT): abortDepth: 250.000000 m
2019-08-07T16:20:44.385Z,1565194844.385 [IBIT](IMPORTANT): IBIT PASSED
2019-08-07T16:20:47.640Z,1565194847.640 [CommandLine](IMPORTANT): got command gfscan
2019-08-07T16:20:47.671Z,1565194847.671 [CBIT](IMPORTANT): Beginning ground fault scan
2019-08-07T16:20:58.541Z,1565194858.541 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.006311
CHAN A1 (24V): -0.133838
CHAN A2 (12V): -0.002027
CHAN A3 (5V): -0.001366
CHAN B0 (3.3V): 0.000273
CHAN B1 (3.15aV): 0.000208
CHAN B2 (3.15bV): -0.000467
CHAN B3 (GND): 0.000138
OPEN: -0.000292
Full Scale Calc: 4.765 mA, -1.589 mA
2019-08-07T16:21:02.013Z,1565194862.013 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190807T151639/Courier0040.lzma
2019-08-07T16:21:02.820Z,1565194862.820 [DataOverHttps](INFO): Moved sent file to Logs/20190807T151639/Courier0040.lzma.bak
2019-08-07T16:21:02.820Z,1565194862.820 [DataOverHttps](INFO): SBD MOMSN=11534847
2019-08-07T16:21:15.511Z,1565194875.511 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-07T16:21:16.262Z,1565194876.262 [DataOverHttps](INFO): Sending 827 bytes from file Logs/20190807T151639/Express0023.lzma
2019-08-07T16:21:17.067Z,1565194877.067 [DataOverHttps](INFO): Moved sent file to Logs/20190807T151639/Express0023.lzma.bak
2019-08-07T16:21:17.067Z,1565194877.067 [DataOverHttps](INFO): SBD MOMSN=11534849
2019-08-07T16:21:25.924Z,1565194885.924 [CommandLine](IMPORTANT): got command configSet list
2019-08-07T16:21:25.924Z,1565194885.924 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-08-07T16:21:25.925Z,1565194885.925 [CommandLine](IMPORTANT): CANONSampler.loadAtStartup=1 bool;

2019-08-07T16:21:25.925Z,1565194885.925 [CommandLine](IMPORTANT): DAT.ignoreElevationAngle=1 bool;

2019-08-07T16:21:25.925Z,1565194885.925 [CommandLine](IMPORTANT): DAT.loadAtStartup=0 bool;

2019-08-07T16:21:25.926Z,1565194885.926 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup=0 bool;

2019-08-07T16:21:25.926Z,1565194885.926 [CommandLine](IMPORTANT): ESPComponent.loadAtStartup=0 bool;

2019-08-07T16:21:25.926Z,1565194885.926 [CommandLine](IMPORTANT): NAL9602.fastGPSFix=1 bool;

2019-08-07T16:21:25.926Z,1565194885.926 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=200 cubic_centimeter;

2019-08-07T16:21:25.926Z,1565194885.926 [CommandLine](IMPORTANT): VerticalControl.massDefault=-4 millimeter;

2019-08-07T16:21:25.926Z,1565194885.926 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitAft=-31 millimeter;

2019-08-07T16:21:25.926Z,1565194885.926 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitFwd=30 millimeter;

2019-08-07T16:21:29.925Z,1565194889.925 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20190807T151639/Express0024.lzma
2019-08-07T16:21:30.731Z,1565194890.731 [DataOverHttps](INFO): Moved sent file to Logs/20190807T151639/Express0024.lzma.bak
2019-08-07T16:21:30.731Z,1565194890.731 [DataOverHttps](INFO): SBD MOMSN=11534875
2019-08-07T16:21:42.005Z,1565194902.005 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190807T151639/Express0026.lzma
2019-08-07T16:21:42.811Z,1565194902.811 [DataOverHttps](INFO): Moved sent file to Logs/20190807T151639/Express0026.lzma.bak
2019-08-07T16:21:42.811Z,1565194902.811 [DataOverHttps](INFO): SBD MOMSN=11534877
2019-08-07T16:21:53.898Z,1565194913.898 [DataOverHttps](INFO): Sending 298 bytes from file Logs/20190807T151639/Express0029.lzma
2019-08-07T16:21:54.691Z,1565194914.691 [DataOverHttps](INFO): Moved sent file to Logs/20190807T151639/Express0029.lzma.bak
2019-08-07T16:21:54.692Z,1565194914.692 [DataOverHttps](IMPORTANT): SBD MOMSN=11534880, MTMSN=20190807T162148
2019-08-07T16:21:59.777Z,1565194919.777 [DataOverHttps](INFO): Received command:restart app
2019-08-07T16:21:59.838Z,1565194919.838 [CommandLine](IMPORTANT): got command restart application
2019-08-07T16:22:00.842Z,1565194920.842 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-07T16:22:00.842Z,1565194920.842 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-08-07T16:22:01.025Z,1565194921.025 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-08-07T16:22:01.026Z,1565194921.026 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-08-07T16:22:01.026Z,1565194921.026 [CommandLine](INFO): Join timeout helper Thread ID is 1140
2019-08-07T16:22:01.032Z,1565194921.032 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-08-07T16:22:01.032Z,1565194921.032 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-08-07T16:22:01.032Z,1565194921.032 [NavChartDb](INFO): Join timeout helper Thread ID is 1141
2019-08-07T16:22:01.370Z,1565194921.370 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-07T16:22:01.370Z,1565194921.370 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-08-07T16:22:01.373Z,1565194921.373 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2019-08-07T16:22:01.374Z,1565194921.374 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-08-07T16:22:01.374Z,1565194921.374 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1142
2019-08-07T16:22:01.826Z,1565194921.826 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-07T16:22:01.826Z,1565194921.826 [WetLabsBB2FL](INFO): Powering down
2019-08-07T16:22:01.827Z,1565194921.827 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-08-07T16:22:01.834Z,1565194921.834 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2019-08-07T16:22:01.834Z,1565194921.834 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-08-07T16:22:01.834Z,1565194921.834 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1143
2019-08-07T16:22:02.074Z,1565194922.074 [CTD_Seabird](INFO): Powering down
2019-08-07T16:22:02.086Z,1565194922.086 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-07T16:22:02.086Z,1565194922.086 [CTD_Seabird](INFO): Powering down
2019-08-07T16:22:02.098Z,1565194922.098 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-08-07T16:22:02.106Z,1565194922.106 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-08-07T16:22:02.106Z,1565194922.106 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-08-07T16:22:02.106Z,1565194922.106 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 1144
2019-08-07T16:22:02.302Z,1565194922.302 [CTD_NeilBrown](INFO): Powering down
2019-08-07T16:22:02.314Z,1565194922.314 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-07T16:22:02.314Z,1565194922.314 [CTD_NeilBrown](INFO): Powering down
2019-08-07T16:22:02.326Z,1565194922.326 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-08-07T16:22:02.342Z,1565194922.342 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-08-07T16:22:02.342Z,1565194922.342 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-08-07T16:22:02.343Z,1565194922.343 [Radio_Surface](INFO): Join timeout helper Thread ID is 1145
2019-08-07T16:22:02.346Z,1565194922.346 [Radio_Surface](INFO): Powering down
2019-08-07T16:22:02.346Z,1565194922.346 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-07T16:22:02.347Z,1565194922.347 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-08-07T16:22:02.354Z,1565194922.354 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-08-07T16:22:02.354Z,1565194922.354 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-08-07T16:22:02.355Z,1565194922.355 [DataOverHttps](INFO): Join timeout helper Thread ID is 1146
2019-08-07T16:22:05.246Z,1565194925.246 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-07T16:22:05.249Z,1565194925.249 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-08-07T16:22:05.250Z,1565194925.250 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-08-07T16:22:05.250Z,1565194925.250 [logger ThreadHandler](INFO): Thread cancelled.
2019-08-07T16:22:05.251Z,1565194925.251 [logger](INFO): Join timeout helper Thread ID is 1147
2019-08-07T16:22:05.286Z,1565194925.286 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-07T16:22:05.286Z,1565194925.286 [logger ThreadHandler](INFO): Thread cancelled.
2019-08-07T16:22:05.294Z,1565194925.294 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-08-07T16:22:05.294Z,1565194925.294 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-08-07T16:22:05.294Z,1565194925.294 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-08-07T16:22:05.295Z,1565194925.295 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-08-07T16:22:05.295Z,1565194925.295 [controlThread](INFO): Join timeout helper Thread ID is 1148
2019-08-07T16:22:05.602Z,1565194925.602 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-07T16:22:05.602Z,1565194925.602 [controlThread](DEBUG): Uninitializing ControlThread
2019-08-07T16:22:05.602Z,1565194925.602 [AHRS_M2](INFO): Powering down
2019-08-07T16:22:05.674Z,1565194925.674 [NAL9602](INFO): Powering down
2019-08-07T16:22:05.676Z,1565194925.676 [Aanderaa_O2](INFO): Powering down
2019-08-07T16:22:05.678Z,1565194925.678 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-08-07T16:22:05.679Z,1565194925.679 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-08-07T16:22:05.679Z,1565194925.679 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-08-07T16:22:05.680Z,1565194925.680 [MissionManager](INFO): Uninitializing Mission Default
2019-08-07T16:22:05.680Z,1565194925.680 [Default] Stopped
2019-08-07T16:22:05.680Z,1565194925.680 [Default](DEBUG): Aggregate::uninitialize Default
2019-08-07T16:22:05.680Z,1565194925.680 [Default:B.GoToSurface] Stopped
2019-08-07T16:22:05.680Z,1565194925.680 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-08-07T16:22:05.680Z,1565194925.680 [Default:CheckIn] Stopped
2019-08-07T16:22:05.680Z,1565194925.680 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-07T16:22:05.680Z,1565194925.680 [Default:CheckIn:Read_Iridium] Stopped
2019-08-07T16:22:05.683Z,1565194925.683 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-08-07T16:22:05.683Z,1565194925.683 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-08-07T16:22:05.683Z,1565194925.683 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-08-07T16:22:05.683Z,1565194925.683 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-08-07T16:22:05.684Z,1565194925.684 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-08-07T16:22:05.684Z,1565194925.684 [BuoyancyServo](INFO): Powering down
2019-08-07T16:22:05.698Z,1565194925.698 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-08-07T16:22:05.698Z,1565194925.698 [ElevatorServo](INFO): Powering down
2019-08-07T16:22:05.699Z,1565194925.699 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-08-07T16:22:05.699Z,1565194925.699 [MassServo](INFO): Powering down
2019-08-07T16:22:05.700Z,1565194925.700 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-08-07T16:22:05.700Z,1565194925.700 [RudderServo](INFO): Powering down
2019-08-07T16:22:05.700Z,1565194925.700 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-08-07T16:22:05.700Z,1565194925.700 [ThrusterServo](INFO): Powering down
2019-08-07T16:22:05.701Z,1565194925.701 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-08-07T16:22:05.702Z,1565194925.702 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-08-07T16:22:05.702Z,1565194925.702 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-08-07T16:22:05.702Z,1565194925.702 [CBIT](DEBUG): Powering off loads.
2019-08-07T16:22:05.713Z,1565194925.713 [CBIT](DEBUG): Disabling WDT.
2019-08-07T16:22:05.725Z,1565194925.725 [CBIT](DEBUG): Opening all GF detection circuits.
2019-08-07T16:22:05.726Z,1565194925.726 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-08-07T16:22:05.805Z,1565194925.805 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-08-07T16:22:05.811Z,1565194925.811 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-08-07T16:22:05.842Z,1565194925.842 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-08-07T16:22:05.845Z,1565194925.845 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-08-07T16:22:05.848Z,1565194925.848 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-08-07T16:22:05.885Z,1565194925.885 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-08-07T16:22:05.953Z,1565194925.953 [logger ThreadHandler](INFO): Thread cancelled.