2020-11-09T16:24:25.572Z,1604939065.572 [Supervisor](DEBUG): Initializing supervisor.
2020-11-09T16:24:25.575Z,1604939065.575 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-11-09T16:24:25.575Z,1604939065.575 [SyncHandler](INFO): Protected caller Thread ID is 826
2020-11-09T16:24:25.576Z,1604939065.576 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-11-09T16:24:25.577Z,1604939065.577 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-11-09T16:24:25.577Z,1604939065.577 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 827
2020-11-09T16:24:25.580Z,1604939065.580 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-11-09T16:24:25.596Z,1604939065.596 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-11-09T16:24:25.597Z,1604939065.597 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-11-09T16:24:25.598Z,1604939065.598 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 828
2020-11-09T16:24:25.598Z,1604939065.598 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-11-09T16:24:25.599Z,1604939065.599 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-11-09T16:24:25.600Z,1604939065.600 [logger ThreadHandler](INFO): Protected caller Thread ID is 829
2020-11-09T16:24:25.602Z,1604939065.602 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-11-09T16:24:25.602Z,1604939065.602 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-11-09T16:24:25.606Z,1604939065.606 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-11-09T16:24:26.026Z,1604939066.026 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-11-09T16:24:26.028Z,1604939066.028 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-11-09T16:24:26.124Z,1604939066.124 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-11-09T16:24:26.126Z,1604939066.126 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-11-09T16:24:26.441Z,1604939066.441 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-11-09T16:24:26.443Z,1604939066.443 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-11-09T16:24:26.578Z,1604939066.578 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-11-09T16:24:26.580Z,1604939066.580 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-11-09T16:24:26.764Z,1604939066.764 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-11-09T16:24:26.764Z,1604939066.764 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-11-09T16:24:27.296Z,1604939067.296 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-11-09T16:24:27.298Z,1604939067.298 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-11-09T16:24:27.503Z,1604939067.503 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-11-09T16:24:27.505Z,1604939067.505 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-11-09T16:24:27.646Z,1604939067.646 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-11-09T16:24:27.647Z,1604939067.647 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-11-09T16:24:27.831Z,1604939067.831 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-11-09T16:24:27.831Z,1604939067.831 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-11-09T16:24:27.927Z,1604939067.927 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-11-09T16:24:27.928Z,1604939067.928 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2020-11-09T16:24:28.123Z,1604939068.123 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2020-11-09T16:24:28.125Z,1604939068.125 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-11-09T16:24:28.418Z,1604939068.418 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-11-09T16:24:28.419Z,1604939068.419 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-11-09T16:24:28.502Z,1604939068.502 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-11-09T16:24:28.607Z,1604939068.607 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-11-09T16:24:28.608Z,1604939068.608 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-11-09T16:24:29.774Z,1604939069.774 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-11-09T16:24:29.774Z,1604939069.774 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-11-09T16:24:30.178Z,1604939070.178 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-11-09T16:24:30.180Z,1604939070.180 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2020-11-09T16:24:30.182Z,1604939070.182 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2020-11-09T16:24:30.379Z,1604939070.379 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2020-11-09T16:24:30.478Z,1604939070.478 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2020-11-09T16:24:30.574Z,1604939070.574 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2020-11-09T16:24:30.823Z,1604939070.823 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-11-09T16:24:30.824Z,1604939070.824 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2020-11-09T16:24:30.909Z,1604939070.909 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2020-11-09T16:24:31.004Z,1604939071.004 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2020-11-09T16:24:31.114Z,1604939071.114 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2020-11-09T16:24:31.198Z,1604939071.198 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Dock.cfg
2020-11-09T16:24:31.284Z,1604939071.284 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2020-11-09T16:24:31.392Z,1604939071.392 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/workSite.cfg
2020-11-09T16:24:31.485Z,1604939071.485 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2020-11-09T16:24:31.666Z,1604939071.666 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2020-11-09T16:24:31.800Z,1604939071.800 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-11-09T16:24:31.808Z,1604939071.808 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-11-09T16:24:32.363Z,1604939072.363 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-11-09T16:24:32.366Z,1604939072.366 [AHRS_M2](INFO): created writer for : platform_orientation
2020-11-09T16:24:32.367Z,1604939072.367 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-11-09T16:24:32.370Z,1604939072.370 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-11-09T16:24:32.371Z,1604939072.371 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-11-09T16:24:32.373Z,1604939072.373 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-11-09T16:24:32.374Z,1604939072.374 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-11-09T16:24:32.377Z,1604939072.377 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-11-09T16:24:32.518Z,1604939072.518 [AHRS_M2] Loaded
2020-11-09T16:24:32.519Z,1604939072.519 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-11-09T16:24:32.658Z,1604939072.658 [DataOverHttps] Loaded
2020-11-09T16:24:32.659Z,1604939072.659 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-11-09T16:24:32.660Z,1604939072.660 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4077A4E0
2020-11-09T16:24:32.660Z,1604939072.660 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 918
2020-11-09T16:24:32.678Z,1604939072.678 [DDM] Loaded
2020-11-09T16:24:32.678Z,1604939072.678 [ComponentRegistry](DEBUG): SyncComponent "DDM" handled in the control thread.
2020-11-09T16:24:32.694Z,1604939072.694 [Depth_Keller] Loaded
2020-11-09T16:24:32.694Z,1604939072.694 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-11-09T16:24:32.697Z,1604939072.697 [DropWeight] Loaded
2020-11-09T16:24:32.697Z,1604939072.697 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2020-11-09T16:24:32.735Z,1604939072.735 [DUSBL_Hydroid] Loaded
2020-11-09T16:24:32.736Z,1604939072.736 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2020-11-09T16:24:32.767Z,1604939072.767 [Micromodem] Loaded
2020-11-09T16:24:32.768Z,1604939072.768 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2020-11-09T16:24:32.820Z,1604939072.820 [NAL9602] Loaded
2020-11-09T16:24:32.820Z,1604939072.820 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-11-09T16:24:32.845Z,1604939072.845 [Onboard] Loaded
2020-11-09T16:24:32.845Z,1604939072.845 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2020-11-09T16:24:32.846Z,1604939072.846 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 407AA4E0
2020-11-09T16:24:32.846Z,1604939072.846 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 919
2020-11-09T16:24:32.850Z,1604939072.850 [PowerOnly](INFO): Adding load control power supply at /dev/loadC1
2020-11-09T16:24:32.859Z,1604939072.859 [PowerOnly] Loaded
2020-11-09T16:24:32.859Z,1604939072.859 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2020-11-09T16:24:32.870Z,1604939072.870 [Radio_Surface] Loaded
2020-11-09T16:24:32.870Z,1604939072.870 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-11-09T16:24:32.871Z,1604939072.871 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407DA4E0
2020-11-09T16:24:32.872Z,1604939072.872 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 920
2020-11-09T16:24:32.898Z,1604939072.898 [RDI_Pathfinder] Loaded
2020-11-09T16:24:32.898Z,1604939072.898 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2020-11-09T16:24:32.920Z,1604939072.920 [RDI_PathfinderUp] Loaded
2020-11-09T16:24:32.921Z,1604939072.921 [ComponentRegistry](DEBUG): SyncComponent "RDI_PathfinderUp" handled in the control thread.
2020-11-09T16:24:33.672Z,1604939073.672 [BPC1] Loaded
2020-11-09T16:24:33.672Z,1604939073.672 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-11-09T16:24:33.672Z,1604939073.672 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-11-09T16:24:33.673Z,1604939073.673 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-11-09T16:24:33.703Z,1604939073.703 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-11-09T16:24:33.703Z,1604939073.703 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-11-09T16:24:33.799Z,1604939073.799 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-11-09T16:24:33.800Z,1604939073.800 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-11-09T16:24:33.810Z,1604939073.810 [NavChart] Loaded
2020-11-09T16:24:33.810Z,1604939073.810 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-11-09T16:24:33.814Z,1604939073.814 [UniversalFixResidualReporter] Loaded
2020-11-09T16:24:33.814Z,1604939073.814 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-11-09T16:24:33.822Z,1604939073.822 [WorkSite] Loaded
2020-11-09T16:24:33.823Z,1604939073.823 [ComponentRegistry](DEBUG): SyncComponent "WorkSite" handled in the control thread.
2020-11-09T16:24:33.823Z,1604939073.823 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-11-09T16:24:33.824Z,1604939073.824 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2020-11-09T16:24:33.989Z,1604939073.989 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2020-11-09T16:24:33.990Z,1604939073.990 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-11-09T16:24:34.323Z,1604939074.323 [BuoyancyServo] Loaded
2020-11-09T16:24:34.323Z,1604939074.323 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-11-09T16:24:34.341Z,1604939074.341 [ElevatorServo] Loaded
2020-11-09T16:24:34.342Z,1604939074.342 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-11-09T16:24:34.359Z,1604939074.359 [MassServo] Loaded
2020-11-09T16:24:34.359Z,1604939074.359 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-11-09T16:24:34.376Z,1604939074.376 [RudderServo] Loaded
2020-11-09T16:24:34.376Z,1604939074.376 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-11-09T16:24:34.392Z,1604939074.392 [ThrusterServo] Loaded
2020-11-09T16:24:34.392Z,1604939074.392 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-11-09T16:24:34.393Z,1604939074.393 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-11-09T16:24:34.393Z,1604939074.393 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-11-09T16:24:34.664Z,1604939074.664 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2020-11-09T16:24:34.666Z,1604939074.666 [CTD_Seabird](INFO): created writer for : sea_water_density
2020-11-09T16:24:34.667Z,1604939074.667 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2020-11-09T16:24:34.669Z,1604939074.669 [CTD_Seabird](INFO): created writer for : depth
2020-11-09T16:24:34.670Z,1604939074.670 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2020-11-09T16:24:34.672Z,1604939074.672 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2020-11-09T16:24:34.673Z,1604939074.673 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2020-11-09T16:24:34.676Z,1604939074.676 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2020-11-09T16:24:34.676Z,1604939074.676 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2020-11-09T16:24:34.679Z,1604939074.679 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2020-11-09T16:24:34.682Z,1604939074.682 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2020-11-09T16:24:34.773Z,1604939074.773 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2020-11-09T16:24:34.773Z,1604939074.773 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2020-11-09T16:24:34.776Z,1604939074.776 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2020-11-09T16:24:34.776Z,1604939074.776 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): mass_concentration_of_oxygen_in_sea_water
2020-11-09T16:24:34.779Z,1604939074.779 [CTD_Seabird](INFO): created writer for : mass_concentration_of_oxygen_in_sea_water
2020-11-09T16:24:34.779Z,1604939074.779 [CTD_Seabird](DEBUG): LcmSlateWriter::add(DAtaURI): CTD_Seabird.sea_water_dissolved_oxygen_freq
2020-11-09T16:24:34.804Z,1604939074.804 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): dataName: sea_water_dissolved_oxygen_freq
2020-11-09T16:24:34.832Z,1604939074.832 [CTD_Seabird] Loaded
2020-11-09T16:24:34.848Z,1604939074.848 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2020-11-09T16:24:34.849Z,1604939074.849 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409614E0
2020-11-09T16:24:34.849Z,1604939074.849 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 921
2020-11-09T16:24:34.890Z,1604939074.890 [PAR_Licor] Loaded
2020-11-09T16:24:34.891Z,1604939074.891 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-11-09T16:24:34.998Z,1604939074.998 [WetLabsSeaOWL_UV_A] Loaded
2020-11-09T16:24:34.998Z,1604939074.998 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2020-11-09T16:24:35.008Z,1604939075.008 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409914E0
2020-11-09T16:24:35.008Z,1604939075.008 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 922
2020-11-09T16:24:35.009Z,1604939075.009 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-11-09T16:24:35.010Z,1604939075.010 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-11-09T16:24:35.866Z,1604939075.866 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-11-09T16:24:35.867Z,1604939075.867 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-11-09T16:24:35.918Z,1604939075.918 [DepthRateCalculator] Loaded
2020-11-09T16:24:35.918Z,1604939075.918 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-11-09T16:24:35.921Z,1604939075.921 [PitchRateCalculator] Loaded
2020-11-09T16:24:35.921Z,1604939075.921 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-11-09T16:24:35.929Z,1604939075.929 [SpeedCalculator] Loaded
2020-11-09T16:24:35.929Z,1604939075.929 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-11-09T16:24:35.940Z,1604939075.940 [TempGradientCalculator] Loaded
2020-11-09T16:24:35.940Z,1604939075.940 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-11-09T16:24:35.943Z,1604939075.943 [YawRateCalculator] Loaded
2020-11-09T16:24:35.943Z,1604939075.943 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-11-09T16:24:35.961Z,1604939075.961 [ElevatorOffsetCalculator] Loaded
2020-11-09T16:24:35.961Z,1604939075.961 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-11-09T16:24:35.962Z,1604939075.962 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-11-09T16:24:35.962Z,1604939075.962 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-11-09T16:24:36.117Z,1604939076.117 [SBIT](DEBUG): Construct Startup Built In Test.
2020-11-09T16:24:36.128Z,1604939076.128 [SBIT] Loaded
2020-11-09T16:24:36.129Z,1604939076.129 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-11-09T16:24:36.129Z,1604939076.129 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-11-09T16:24:36.142Z,1604939076.142 [IBIT] Loaded
2020-11-09T16:24:36.142Z,1604939076.142 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-11-09T16:24:36.145Z,1604939076.145 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-11-09T16:24:36.240Z,1604939076.240 [CBIT] Loaded
2020-11-09T16:24:36.240Z,1604939076.240 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-11-09T16:24:36.240Z,1604939076.240 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-11-09T16:24:36.241Z,1604939076.241 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-11-09T16:24:36.369Z,1604939076.369 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-11-09T16:24:36.369Z,1604939076.369 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-11-09T16:24:36.491Z,1604939076.491 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-11-09T16:24:36.492Z,1604939076.492 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-11-09T16:24:36.554Z,1604939076.554 [VerticalControl](DEBUG): Construct VerticalControl.
2020-11-09T16:24:36.604Z,1604939076.604 [VerticalControl] Loaded
2020-11-09T16:24:36.604Z,1604939076.604 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-11-09T16:24:36.605Z,1604939076.605 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-11-09T16:24:36.638Z,1604939076.638 [HorizontalControl] Loaded
2020-11-09T16:24:36.639Z,1604939076.639 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-11-09T16:24:36.639Z,1604939076.639 [SpeedControl](DEBUG): Construct SpeedControl.
2020-11-09T16:24:36.641Z,1604939076.641 [SpeedControl] Loaded
2020-11-09T16:24:36.641Z,1604939076.641 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-11-09T16:24:36.642Z,1604939076.642 [LoopControl](DEBUG): Construct LoopControl.
2020-11-09T16:24:36.642Z,1604939076.642 [LoopControl] Loaded
2020-11-09T16:24:36.643Z,1604939076.643 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-11-09T16:24:36.643Z,1604939076.643 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-11-09T16:24:36.644Z,1604939076.644 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-11-09T16:24:36.684Z,1604939076.684 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-11-09T16:24:36.688Z,1604939076.688 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-11-09T16:24:36.689Z,1604939076.689 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-11-09T16:24:36.697Z,1604939076.697 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-11-09T16:24:36.698Z,1604939076.698 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B674E0
2020-11-09T16:24:36.699Z,1604939076.699 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 923
2020-11-09T16:24:36.703Z,1604939076.703 [Supervisor](INFO): Main Thread ID is 822
2020-11-09T16:24:36.703Z,1604939076.703 [Supervisor](DEBUG): Running supervisor.
2020-11-09T16:24:36.704Z,1604939076.704 [CommandLine ThreadHandler](INFO): Handler Thread ID is 924
2020-11-09T16:24:36.706Z,1604939076.706 [controlThread ThreadHandler](INFO): Handler Thread ID is 925
2020-11-09T16:24:36.707Z,1604939076.707 [controlThread](DEBUG): Initializing ControlThread
2020-11-09T16:24:36.715Z,1604939076.715 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-11-09T16:24:36.716Z,1604939076.716 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-11-09T16:24:36.716Z,1604939076.716 [WorkSite](DEBUG): Initializing WorkSite component.
2020-11-09T16:24:36.720Z,1604939076.720 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-11-09T16:24:36.720Z,1604939076.720 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-11-09T16:24:36.721Z,1604939076.721 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-11-09T16:24:36.721Z,1604939076.721 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-11-09T16:24:36.722Z,1604939076.722 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-11-09T16:24:36.722Z,1604939076.722 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-11-09T16:24:36.722Z,1604939076.722 [SBIT](INFO): Initialize SBIT Component.
2020-11-09T16:24:36.723Z,1604939076.723 [SBIT](IMPORTANT): git: 2020-11-06
2020-11-09T16:24:36.723Z,1604939076.723 [SBIT](INFO): git hash: 159c5b66861882d5f99dda1b1932a945ab78dfb6
2020-11-09T16:24:36.723Z,1604939076.723 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-11-09T16:24:36.724Z,1604939076.724 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Thu Aug 6 12:04:53 PDT 2020
2020-11-09T16:24:36.725Z,1604939076.725 [SBIT](INFO): Beginning SBIT in 32.000000 seconds.
2020-11-09T16:24:36.726Z,1604939076.726 [IBIT](INFO): Initialize IBIT Component.
2020-11-09T16:24:36.727Z,1604939076.727 [CBIT](DEBUG): Initialize CBIT Component.
2020-11-09T16:24:36.728Z,1604939076.728 [logger ThreadHandler](INFO): Handler Thread ID is 926
2020-11-09T16:24:36.740Z,1604939076.740 [CBIT](DEBUG): Initialized mux pins.
2020-11-09T16:24:36.740Z,1604939076.740 [CBIT](DEBUG): Initializing the watchdog timer.
2020-11-09T16:24:36.748Z,1604939076.748 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 927
2020-11-09T16:24:36.749Z,1604939076.749 [DataOverHttps](DEBUG): dashIP=128.128.181.155 starts with a digit so assuming it is a numeric IP
2020-11-09T16:24:36.764Z,1604939076.764 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-11-09T16:24:36.764Z,1604939076.764 [CBIT](DEBUG): Initializing heartbeat.
2020-11-09T16:24:36.760Z,1604939076.760 [Onboard ThreadHandler](INFO): Handler Thread ID is 928
2020-11-09T16:24:36.784Z,1604939076.784 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 929
2020-11-09T16:24:36.800Z,1604939076.800 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 930
2020-11-09T16:24:36.801Z,1604939076.801 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2020-11-09T16:24:36.805Z,1604939076.805 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 932
2020-11-09T16:24:36.806Z,1604939076.806 [WetLabsSeaOWL_UV_A](INFO): Powering down
2020-11-09T16:24:36.817Z,1604939076.817 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 933
2020-11-09T16:24:36.825Z,1604939076.825 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-11-09T16:24:36.825Z,1604939076.825 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-11-09T16:24:36.825Z,1604939076.825 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-11-09T16:24:36.825Z,1604939076.825 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-11-09T16:24:36.825Z,1604939076.825 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-11-09T16:24:36.825Z,1604939076.825 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-11-09T16:24:36.826Z,1604939076.826 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-11-09T16:24:36.826Z,1604939076.826 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-11-09T16:24:36.826Z,1604939076.826 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-11-09T16:24:36.826Z,1604939076.826 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-11-09T16:24:36.826Z,1604939076.826 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-11-09T16:24:36.826Z,1604939076.826 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-11-09T16:24:36.826Z,1604939076.826 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-11-09T16:24:36.827Z,1604939076.827 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-11-09T16:24:36.827Z,1604939076.827 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-11-09T16:24:36.827Z,1604939076.827 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-11-09T16:24:36.836Z,1604939076.836 [CBIT](DEBUG): Deactivating GF circuits.
2020-11-09T16:24:36.836Z,1604939076.836 [CBIT](DEBUG): Deactivating emergency mode.
2020-11-09T16:24:36.872Z,1604939076.872 [CBIT](DEBUG): Backplane powered.
2020-11-09T16:24:36.872Z,1604939076.872 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-11-09T16:24:36.874Z,1604939076.874 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-11-09T16:24:36.875Z,1604939076.875 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-11-09T16:24:36.875Z,1604939076.875 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-11-09T16:24:36.876Z,1604939076.876 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-11-09T16:24:36.920Z,1604939076.920 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-11-09T16:24:36.947Z,1604939076.947 [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>


2020-11-09T16:24:36.947Z,1604939076.947 [MissionManager](INFO): Loading Mission: Missions/underIce/DefaultWithUndock.xml
2020-11-09T16:24:37.091Z,1604939077.091 [MissionManager](INFO): DefineArg DefaultWithUndock.ElapsedSinceDefaultStarted = 0.000000 min
2020-11-09T16:24:37.107Z,1604939077.107 [MissionManager](INFO): DefineArg DefaultWithUndock.DetachTimeout = 30.000000 min
2020-11-09T16:24:37.111Z,1604939077.111 [MissionManager](INFO): DefineArg DefaultWithUndock.TransponderCode = 2.000000 count
2020-11-09T16:24:37.130Z,1604939077.130 [MissionManager](INFO): DefineArg DefaultWithUndock.TrackingUpdatePeriod = 2.500000 s
2020-11-09T16:24:37.133Z,1604939077.133 [MissionManager](INFO): DefineArg DefaultWithUndock.NumberOfPings = 1.000000 count
2020-11-09T16:24:37.145Z,1604939077.145 [MissionManager](INFO): DefineArg DefaultWithUndock.DetachModeDDM = 2.000000 count
2020-11-09T16:24:37.146Z,1604939077.146 [DefaultWithUndock:A.Wait](DEBUG): Construct Wait.
2020-11-09T16:24:37.192Z,1604939077.192 [Radio_Surface](INFO): Powering up
2020-11-09T16:24:37.290Z,1604939077.290 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Construct.
2020-11-09T16:24:37.290Z,1604939077.290 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values.
2020-11-09T16:24:37.329Z,1604939077.329 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-11-09T16:24:37.366Z,1604939077.366 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-11-09T16:24:37.369Z,1604939077.369 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-11-09T16:24:37.390Z,1604939077.390 [DefaultWithUndock:E.Execute](DEBUG): Construct Execute.
2020-11-09T16:24:37.408Z,1604939077.408 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Dock="Tethys/Dock"
         xmlns:Estimation="Tethys/Estimation"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Sensor="Tethys/Sensor"
         xmlns:Units="Tethys/Units"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Dock http://okeanids.mbari.org/tethys/Xml/Dock.xsd
                             Tethys/Estimation http://okeanids.mbari.org/tethys/Xml/Estimation.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Sensor http://okeanids.mbari.org/tethys/Xml/Sensor.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="DefaultWithUndock">

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

    <DefineArg Name="DetachTimeout"><Description>
        Maximum time duration for the vehicle to detach form the dock.
    </Description><Units:minute/><Value>30</Value></DefineArg>

    <DefineArg Name="TransponderCode"><Description>
        Dock transponder address.
    </Description><Dock:Dock.transponderCode/></DefineArg>

    <DefineArg Name="TrackingUpdatePeriod"><Description>
        Time duration between acoustic range queries while the
        mission is detaching from the dock.
    </Description><Units:second/><Value>2.5</Value></DefineArg>

    <DefineArg Name="NumberOfPings"><Description>
        Number of pings requested each time.
    </Description><Units:count/><Value>1</Value></DefineArg>

    <DefineArg Name="DetachModeDDM"><Description>
        DDM DETACH mode enumeration (whiskers retracted, latch open).
    </Description><Units:count/><Value>2</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>30</Value></Setting>
    </Guidance:Wait>

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

        <Timeout Duration="DetachTimeout">
            <Syslog Severity="Important">Timed out while trying to detach from dock at current depth of <Universal:depth/><Units:meter/>.</Syslog>
        </Timeout>

        <!-- Acoustic tracking directives -->
        <Estimation:TrackAcousticContact>
            <Parallel/>
            <Setting><Estimation:TrackAcousticContact.contactLabelSetting/><Arg Name="TransponderCode"/></Setting>
            <Setting><Estimation:TrackAcousticContact.numberOfSamplesSetting/><Arg Name="NumberOfPings"/></Setting>
            <Setting><Estimation:TrackAcousticContact.updatePeriodSetting/><Arg Name="TrackingUpdatePeriod"/></Setting>
        </Estimation:TrackAcousticContact>

        <!-- Leave the dock -->
        <Dock:Undock>
            <Sequence/>
        </Dock:Undock>

    </Aggregate>


    <Aggregate Id="SurfaceDefault">

        <Sequence/>

        <Aggregate Id="HoldLatchOpen">

            <While>
                <Universal:depth/>
                <Gt><Control:VerticalControl.surfaceThreshold/></Gt>
            </While>

            <!-- Power the DDM -->
            <ReadData>
                <Sensor:DDM.DDMMode/>
            </ReadData>

            <!-- Hold the DDM in DETACH mode (whiskers retracted, latch open) -->
            <Assign><Parallel/><Sensor:DDM.DDMModeCmd/><Arg Name="DetachModeDDM"/></Assign>

        </Aggregate>

        <!-- This mission assumes open water so from here on it's the same old default that's always used -->
        <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>

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


2020-11-09T16:24:37.413Z,1604939077.413 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,DDM,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,PowerOnly,RDI_Pathfinder,RDI_PathfinderUp,BPC1,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,WorkSite,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2020-11-09T16:24:37.432Z,1604939077.432 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-11-09T16:24:37.512Z,1604939077.512 [DDM](INFO): Powering up
2020-11-09T16:24:37.512Z,1604939077.512 [DDM](DEBUG): Initializing DDM.
2020-11-09T16:24:37.537Z,1604939077.537 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2020-11-09T16:24:37.537Z,1604939077.537 [DUSBL_Hydroid](INFO): Powering up
2020-11-09T16:24:37.538Z,1604939077.538 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2020-11-09T16:24:37.706Z,1604939077.706 [DepthRateCalculator](ERROR): Depth measurement is not active
2020-11-09T16:24:37.763Z,1604939077.763 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-11-09T16:24:37.768Z,1604939077.768 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-11-09T16:24:37.769Z,1604939077.769 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-11-09T16:24:37.776Z,1604939077.776 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-11-09T16:24:37.777Z,1604939077.777 [MassServo](DEBUG): Initializing EZServoServo.
2020-11-09T16:24:37.784Z,1604939077.784 [MassServo](DEBUG): Initializing MassServo.
2020-11-09T16:24:37.785Z,1604939077.785 [RudderServo](DEBUG): Initializing EZServoServo.
2020-11-09T16:24:37.792Z,1604939077.792 [RudderServo](DEBUG): Initializing RudderServo.
2020-11-09T16:24:37.793Z,1604939077.793 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-11-09T16:24:37.800Z,1604939077.800 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-11-09T16:24:37.931Z,1604939077.931 [Micromodem](INFO): Powering up
2020-11-09T16:24:37.931Z,1604939077.931 [Micromodem](DEBUG): Initializing Micromodem.
2020-11-09T16:24:42.714Z,1604939082.714 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2020-11-09T16:24:44.734Z,1604939084.734 [Micromodem](INFO): Nmea in: $CATMG,2020-11-09T16:24:43.921450Z,RTC,RTC*54

2020-11-09T16:24:44.735Z,1604939084.735 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2020-11-09T16:24:43.921450Z,RTC,RTC*54

2020-11-09T16:24:53.317Z,1604939093.317 [DDM](INFO): Dynamic Docking Module:ÿ¿nØ@
2020-11-09T16:24:53.761Z,1604939093.761 [Micromodem](ERROR): Nmea resend: $CCCFG,ALL,0*33

2020-11-09T16:24:54.154Z,1604939094.154 [Micromodem](INFO): Nmea in: $CAERR,162454,NI  ,12,Unknown command*4C

2020-11-09T16:24:54.155Z,1604939094.155 [Micromodem](ERROR): Got error from modem: $CAERR,162454,NI  ,12,Unknown command*4C

2020-11-09T16:24:55.759Z,1604939095.759 [DUSBL_Hydroid](INFO): DUSBL Version:O
2020-11-09T16:25:03.027Z,1604939103.027 [NAL9602](INFO): Powering up NAL9602
2020-11-09T16:25:05.049Z,1604939105.049 [Micromodem](ERROR): Nmea resend: $CCCFG,ALL,0*33

2020-11-09T16:25:05.438Z,1604939105.438 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31

2020-11-09T16:25:05.438Z,1604939105.438 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31

2020-11-09T16:25:05.846Z,1604939105.846 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33

2020-11-09T16:25:05.846Z,1604939105.846 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64

2020-11-09T16:25:06.262Z,1604939106.262 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66

2020-11-09T16:25:06.262Z,1604939106.262 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F

2020-11-09T16:25:06.654Z,1604939106.654 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D

2020-11-09T16:25:06.654Z,1604939106.654 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E

2020-11-09T16:25:07.101Z,1604939107.101 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C

2020-11-09T16:25:07.102Z,1604939107.102 [Micromodem](INFO): Nmea out: $CCCFG,FC0,14500*47

2020-11-09T16:25:07.470Z,1604939107.470 [Micromodem](INFO): Nmea in: $CACFG,FC0,14500*45

2020-11-09T16:25:07.470Z,1604939107.470 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63

2020-11-09T16:25:07.870Z,1604939107.870 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61

2020-11-09T16:25:07.870Z,1604939107.870 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A

2020-11-09T16:25:08.280Z,1604939108.280 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38

2020-11-09T16:25:08.281Z,1604939108.281 [Micromodem](INFO): Nmea out: $CCCLK,2020,11,09,16,25,09*44

2020-11-09T16:25:08.682Z,1604939108.682 [Micromodem](INFO): Nmea in: $CACLK,2020,11,9,16,25,9*46

2020-11-09T16:25:09.120Z,1604939109.120 [Micromodem](INFO): Nmea in: $CATMS,0,2020-11-09T16:25:10Z*7E

2020-11-09T16:25:09.121Z,1604939109.121 [Micromodem](INFO): Nmea in: $CATMG,2020-11-09T16:25:10.027235Z,USER_CMD,RTC*18

2020-11-09T16:25:09.185Z,1604939109.185 [SBIT](IMPORTANT): Beginning Startup BIT
2020-11-09T16:25:09.197Z,1604939109.197 [CBIT](IMPORTANT): Beginning ground fault scan
2020-11-09T16:25:13.926Z,1604939113.926 [NAL9602](INFO): NAL9602 initialized
2020-11-09T16:25:20.114Z,1604939120.114 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.010015
CHAN A1 (24V): -0.028635
CHAN A2 (12V): -0.007635
CHAN A3 (5V): -0.001995
CHAN B0 (3.3V): -0.000001
CHAN B1 (3.15aV): 0.000164
CHAN B2 (3.15bV): -0.000072
CHAN B3 (GND): 0.002180
OPEN: 0.005273
Full Scale Calc: 4.765 mA, -1.589 mA
2020-11-09T16:26:03.271Z,1604939163.271 [SBIT](IMPORTANT): SBIT PASSED
2020-11-09T16:26:03.271Z,1604939163.271 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-11-09T16:26:03.272Z,1604939163.272 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=200 milliliter;

2020-11-09T16:26:03.647Z,1604939163.647 [WorkSite](IMPORTANT): Reading workSite position from Data/workSite.cfg
2020-11-09T16:26:03.668Z,1604939163.668 [WorkSite](IMPORTANT): WorkSite fix at 20201109T162219: (41.552760, -70.709690)
2020-11-09T16:26:03.670Z,1604939163.670 [MissionManager](IMPORTANT): Started mission Startup
2020-11-09T16:26:03.670Z,1604939163.670 [Startup] Running Loop=1
2020-11-09T16:26:03.670Z,1604939163.670 [Startup](DEBUG): Aggregate::initialize Startup
2020-11-09T16:26:03.670Z,1604939163.670 [Startup:A.GoToSurface] Running Loop=1
2020-11-09T16:26:03.670Z,1604939163.670 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-11-09T16:26:03.671Z,1604939163.671 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-11-09T16:26:03.671Z,1604939163.671 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-11-09T16:26:03.676Z,1604939163.676 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-11-09T16:26:03.676Z,1604939163.676 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-11-09T16:26:03.677Z,1604939163.677 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-11-09T16:26:03.678Z,1604939163.678 [Startup:StartupSatComms] Running Loop=1
2020-11-09T16:26:03.678Z,1604939163.678 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-11-09T16:26:03.678Z,1604939163.678 [Startup:StartupSatComms:A] Running Loop=1
2020-11-09T16:26:04.093Z,1604939164.093 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-11-09T16:27:03.849Z,1604939223.849 [Startup:StartupSatComms:A](INFO): Timed out from 2020-11-09T16:26:03.7Z
2020-11-09T16:27:03.849Z,1604939223.849 [Startup:StartupSatComms:A] Stopped
2020-11-09T16:27:03.849Z,1604939223.849 [Startup:StartupSatComms:B] Running Loop=1
2020-11-09T16:27:04.263Z,1604939224.263 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-11-09T16:28:01.590Z,1604939281.590 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004705
2020-11-09T16:28:04.065Z,1604939284.065 [Startup:StartupSatComms:B](INFO): Timed out from 2020-11-09T16:27:03.8Z
2020-11-09T16:28:04.065Z,1604939284.065 [Startup:StartupSatComms:B] Stopped
2020-11-09T16:28:04.065Z,1604939284.065 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-11-09T16:28:04.065Z,1604939284.065 [Startup:StartupSatComms] Stopped
2020-11-09T16:28:04.065Z,1604939284.065 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-11-09T16:28:04.066Z,1604939284.066 [Startup](INFO): Completed Startup
2020-11-09T16:28:04.066Z,1604939284.066 [MissionManager](INFO): Startup is completed.
2020-11-09T16:28:04.066Z,1604939284.066 [MissionManager](INFO): Uninitializing Mission Startup
2020-11-09T16:28:04.066Z,1604939284.066 [Startup] Stopped
2020-11-09T16:28:04.067Z,1604939284.067 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-11-09T16:28:04.067Z,1604939284.067 [Startup:A.GoToSurface] Stopped
2020-11-09T16:28:04.067Z,1604939284.067 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-11-09T16:28:04.454Z,1604939284.454 [MissionManager](IMPORTANT): Started mission DefaultWithUndock
2020-11-09T16:28:04.454Z,1604939284.454 [DefaultWithUndock] Running Loop=1
2020-11-09T16:28:04.454Z,1604939284.454 [DefaultWithUndock](DEBUG): Aggregate::initialize DefaultWithUndock
2020-11-09T16:28:04.454Z,1604939284.454 [DefaultWithUndock:A.Wait] Running Loop=1
2020-11-09T16:28:04.454Z,1604939284.454 [DefaultWithUndock:A.Wait](DEBUG): Initialize Wait Component.
2020-11-09T16:28:05.611Z,1604939285.611 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20201109T160038/Courier0010.lzma
2020-11-09T16:28:06.614Z,1604939286.614 [DataOverHttps](INFO): Moved sent file to Logs/20201109T160038/Courier0010.lzma.bak
2020-11-09T16:28:06.614Z,1604939286.614 [DataOverHttps](INFO): SBD MOMSN=54977
2020-11-09T16:28:34.765Z,1604939314.765 [DefaultWithUndock:A.Wait](INFO): Done Waiting.
2020-11-09T16:28:34.766Z,1604939314.766 [DefaultWithUndock:A.Wait] Stopped
2020-11-09T16:28:34.766Z,1604939314.766 [DefaultWithUndock:A.Wait](DEBUG): Uninitialize Wait Component.
2020-11-09T16:28:34.766Z,1604939314.766 [DefaultWithUndock:LeaveDock] Running Loop=1
2020-11-09T16:28:34.766Z,1604939314.766 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::initialize DefaultWithUndock:LeaveDock
2020-11-09T16:28:34.766Z,1604939314.766 [DefaultWithUndock:LeaveDock:A.] Running Loop=1
2020-11-09T16:28:34.766Z,1604939314.766 [DefaultWithUndock:LeaveDock:A.](INFO): Initializing TrackAcousticContact.
2020-11-09T16:28:34.766Z,1604939314.766 [DefaultWithUndock:LeaveDock:B.Undock] Running Loop=1
2020-11-09T16:28:34.766Z,1604939314.766 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize.
2020-11-09T16:28:34.767Z,1604939314.767 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values.
2020-11-09T16:28:35.150Z,1604939315.150 [DefaultWithUndock:LeaveDock:A.] Running Loop=1
2020-11-09T16:28:35.540Z,1604939315.540 [PowerOnly](INFO): Powering up loadControl
2020-11-09T16:28:37.594Z,1604939317.594 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-11-09T16:28:38.387Z,1604939318.387 [Micromodem](INFO): Nmea out: $CCPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*76

2020-11-09T16:28:38.792Z,1604939318.792 [Micromodem](INFO): Nmea in: $SNPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6B

2020-11-09T16:28:39.634Z,1604939319.634 [Micromodem](INFO): Nmea in: $SNTTA,,,,,162839.43*5E

2020-11-09T16:28:39.679Z,1604939319.679 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detaching from dock.
2020-11-09T16:28:40.181Z,1604939320.181 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detected possible detachment. Starting timer.
2020-11-09T16:28:40.182Z,1604939320.182 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-11-09T16:28:42.061Z,1604939322.061 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-11-09T16:28:42.864Z,1604939322.864 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-11-09T16:28:43.639Z,1604939323.639 [Micromodem](INFO): Nmea out: $CCPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*76

2020-11-09T16:28:44.068Z,1604939324.068 [Micromodem](INFO): Nmea in: $SNPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6B

2020-11-09T16:28:44.878Z,1604939324.878 [Micromodem](INFO): Nmea in: $SNTTA,,,,,162844.69*5C

2020-11-09T16:28:45.677Z,1604939325.677 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-11-09T16:28:47.277Z,1604939327.277 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-11-09T16:28:48.528Z,1604939328.528 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-11-09T16:28:49.299Z,1604939329.299 [Micromodem](INFO): Nmea out: $CCPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*76

2020-11-09T16:28:49.700Z,1604939329.700 [Micromodem](INFO): Nmea in: $SNPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6B

2020-11-09T16:28:50.518Z,1604939330.518 [Micromodem](INFO): Nmea in: $SNTTA,,,,,162850.35*50

2020-11-09T16:28:51.349Z,1604939331.349 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-11-09T16:28:52.133Z,1604939332.133 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-11-09T16:28:52.925Z,1604939332.925 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-11-09T16:28:53.878Z,1604939333.878 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-11-09T16:28:54.542Z,1604939334.542 [Micromodem](INFO): Nmea out: $CCPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*76

2020-11-09T16:28:54.958Z,1604939334.958 [Micromodem](INFO): Nmea in: $SNPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6B

2020-11-09T16:28:55.782Z,1604939335.782 [Micromodem](INFO): Nmea in: $SNTTA,,,,,162855.59*5F

2020-11-09T16:28:56.609Z,1604939336.609 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-11-09T16:28:58.189Z,1604939338.189 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-11-09T16:28:59.447Z,1604939339.447 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-11-09T16:29:00.198Z,1604939340.198 [Micromodem](INFO): Nmea out: $CCPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*76

2020-11-09T16:29:00.295Z,1604939340.295 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detached at range: nan m. Transitioning DDM to standby.
2020-11-09T16:29:00.604Z,1604939340.604 [Micromodem](INFO): Nmea in: $SNPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6B

2020-11-09T16:29:01.434Z,1604939341.434 [Micromodem](INFO): Nmea in: $SNTTA,,,,,162901.24*55

2020-11-09T16:29:02.263Z,1604939342.263 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-11-09T16:29:03.118Z,1604939343.118 [DefaultWithUndock:LeaveDock:B.Undock](INFO): DDM at standby.
2020-11-09T16:29:03.459Z,1604939343.459 [DefaultWithUndock:LeaveDock:B.Undock](IMPORTANT): Undocking sequence complete.
2020-11-09T16:29:03.459Z,1604939343.459 [DefaultWithUndock:LeaveDock:B.Undock] Stopped
2020-11-09T16:29:03.460Z,1604939343.460 [DefaultWithUndock:LeaveDock](INFO): Completed DefaultWithUndock:LeaveDock
2020-11-09T16:29:03.460Z,1604939343.460 [DefaultWithUndock:LeaveDock] Stopped
2020-11-09T16:29:03.460Z,1604939343.460 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::uninitialize DefaultWithUndock:LeaveDock
2020-11-09T16:29:03.460Z,1604939343.460 [DefaultWithUndock:LeaveDock:A.] Stopped
2020-11-09T16:29:03.460Z,1604939343.460 [DefaultWithUndock:SurfaceDefault] Running Loop=1
2020-11-09T16:29:03.460Z,1604939343.460 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault
2020-11-09T16:29:03.460Z,1604939343.460 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen] Running Loop=1
2020-11-09T16:29:03.461Z,1604939343.461 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:HoldLatchOpen
2020-11-09T16:29:03.461Z,1604939343.461 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:A] Running Loop=1
2020-11-09T16:29:03.461Z,1604939343.461 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:B] Running Loop=1
2020-11-09T16:29:03.461Z,1604939343.461 [DefaultWithUndock:SurfaceDefault:B.GoToSurface] Running Loop=1
2020-11-09T16:29:03.461Z,1604939343.461 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-11-09T16:29:03.461Z,1604939343.461 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-11-09T16:29:03.461Z,1604939343.461 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-11-09T16:29:03.462Z,1604939343.462 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-11-09T16:29:03.462Z,1604939343.462 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-11-09T16:29:03.463Z,1604939343.463 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-11-09T16:29:03.833Z,1604939343.833 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=1
2020-11-09T16:29:03.833Z,1604939343.833 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T16:29:03.833Z,1604939343.833 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-11-09T16:29:03.833Z,1604939343.833 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen] Stopped
2020-11-09T16:29:03.833Z,1604939343.833 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:HoldLatchOpen
2020-11-09T16:29:03.833Z,1604939343.833 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:A] Stopped
2020-11-09T16:29:03.833Z,1604939343.833 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:B] Stopped
2020-11-09T16:29:04.259Z,1604939344.259 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-11-09T16:29:22.069Z,1604939362.069 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2020-11-09T16:30:06.846Z,1604939406.846 [PowerOnly](INFO): Powering down loadControl
2020-11-09T16:30:16.538Z,1604939416.538 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-11-09T16:32:55.758Z,1604939575.758 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-11-09T16:32:55.766Z,1604939575.766 [BPC1](INFO): Received data from all battery sticks.
2020-11-09T16:34:04.067Z,1604939644.067 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS](INFO): Timed out from 2020-11-09T16:29:03.8Z
2020-11-09T16:34:04.067Z,1604939644.067 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-11-09T16:34:04.067Z,1604939644.067 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-11-09T16:34:04.416Z,1604939644.416 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-11-09T16:34:08.131Z,1604939648.131 [DataOverHttps](INFO): Sending 255 bytes from file Logs/20201109T162425/Courier0000.lzma
2020-11-09T16:34:09.129Z,1604939649.129 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Courier0000.lzma.bak
2020-11-09T16:34:09.130Z,1604939649.130 [DataOverHttps](INFO): SBD MOMSN=54979
2020-11-09T16:34:18.187Z,1604939658.187 [DataOverHttps](INFO): Sending 180 bytes from file Logs/20201109T162425/Courier0004.lzma
2020-11-09T16:34:19.189Z,1604939659.189 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Courier0004.lzma.bak
2020-11-09T16:34:19.190Z,1604939659.190 [DataOverHttps](INFO): SBD MOMSN=54983
2020-11-09T16:34:28.227Z,1604939668.227 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20201109T160038/Express0011.lzma
2020-11-09T16:34:29.230Z,1604939669.230 [DataOverHttps](INFO): Moved sent file to Logs/20201109T160038/Express0011.lzma.bak
2020-11-09T16:34:29.230Z,1604939669.230 [DataOverHttps](INFO): SBD MOMSN=54985
2020-11-09T16:34:34.737Z,1604939674.737 [NAL9602](INFO): Not Powering down - fast GPS
2020-11-09T16:34:38.269Z,1604939678.269 [DataOverHttps](INFO): Sending 729 bytes from file Logs/20201109T162425/Express0001.lzma
2020-11-09T16:34:39.270Z,1604939679.270 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Express0001.lzma.bak
2020-11-09T16:34:39.270Z,1604939679.270 [DataOverHttps](INFO): SBD MOMSN=54987
2020-11-09T16:34:48.308Z,1604939688.308 [DataOverHttps](INFO): Sending 259 bytes from file Logs/20201109T162425/Express0005.lzma
2020-11-09T16:34:49.310Z,1604939689.310 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Express0005.lzma.bak
2020-11-09T16:34:49.310Z,1604939689.310 [DataOverHttps](INFO): SBD MOMSN=55001
2020-11-09T16:34:50.494Z,1604939690.494 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-11-09T16:34:50.494Z,1604939690.494 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-11-09T16:34:50.495Z,1604939690.495 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-11-09T16:39:51.113Z,1604939991.113 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](INFO): Done Waiting.
2020-11-09T16:39:51.113Z,1604939991.113 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2020-11-09T16:39:51.113Z,1604939991.113 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-11-09T16:39:51.113Z,1604939991.113 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Running Loop=1
2020-11-09T16:39:51.517Z,1604939991.517 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Stopped
2020-11-09T16:39:51.517Z,1604939991.517 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Running Loop=1
2020-11-09T16:39:51.906Z,1604939991.906 [DefaultWithUndock:SurfaceDefault:CheckIn:E](IMPORTANT): Default mission has been running for 11.784382 min 
2020-11-09T16:39:51.906Z,1604939991.906 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Stopped
2020-11-09T16:39:51.906Z,1604939991.906 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Completed DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T16:39:51.906Z,1604939991.906 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-11-09T16:39:51.907Z,1604939991.907 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T16:39:51.907Z,1604939991.907 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Running loop #2
2020-11-09T16:39:51.907Z,1604939991.907 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=2
2020-11-09T16:39:51.907Z,1604939991.907 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T16:39:51.907Z,1604939991.907 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-11-09T16:39:53.502Z,1604939993.502 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-11-09T16:39:53.502Z,1604939993.502 [NAL9602] Data Fault, FailCount= 1
2020-11-09T16:39:53.502Z,1604939993.502 [NAL9602](ERROR): Data Fault
2020-11-09T16:39:53.521Z,1604939993.521 [CBIT](ERROR): Data Fault in component: NAL9602
2020-11-09T16:39:53.908Z,1604939993.908 [NAL9602](INFO): Powering down
2020-11-09T16:39:54.776Z,1604939994.776 [CBIT](INFO): Clearing failed state for component NAL9602
2020-11-09T16:39:54.776Z,1604939994.776 [NAL9602] No Fault, FailCount= 1
2020-11-09T16:40:24.202Z,1604940024.202 [NAL9602](INFO): Powering up NAL9602
2020-11-09T16:40:35.116Z,1604940035.116 [NAL9602](INFO): NAL9602 initialized
2020-11-09T16:43:33.296Z,1604940213.296 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-11-09T16:44:52.124Z,1604940292.124 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS](INFO): Timed out from 2020-11-09T16:39:51.9Z
2020-11-09T16:44:52.124Z,1604940292.124 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-11-09T16:44:52.124Z,1604940292.124 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-11-09T16:44:55.815Z,1604940295.815 [DataOverHttps](INFO): Sending 51 bytes from file Logs/20201109T162425/Courier0007.lzma
2020-11-09T16:44:56.821Z,1604940296.821 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Courier0007.lzma.bak
2020-11-09T16:44:56.821Z,1604940296.821 [DataOverHttps](INFO): SBD MOMSN=55006
2020-11-09T16:45:05.855Z,1604940305.855 [DataOverHttps](INFO): Sending 209 bytes from file Logs/20201109T162425/Express0008.lzma
2020-11-09T16:45:06.858Z,1604940306.858 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Express0008.lzma.bak
2020-11-09T16:45:06.858Z,1604940306.858 [DataOverHttps](INFO): SBD MOMSN=55008
2020-11-09T16:45:07.895Z,1604940307.895 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-11-09T16:45:07.895Z,1604940307.895 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-11-09T16:45:07.904Z,1604940307.904 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-11-09T16:45:38.930Z,1604940338.930 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-11-09T16:45:39.372Z,1604940339.372 [RDI_Pathfinder](ERROR): only read -1 of 4 data items
2020-11-09T16:46:09.637Z,1604940369.637 [NAL9602](INFO): Not Powering down - fast GPS
2020-11-09T16:47:08.249Z,1604940428.249 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude
2020-11-09T16:48:03.166Z,1604940483.166 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-11-09T16:48:13.263Z,1604940493.263 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-11-09T16:48:41.957Z,1604940521.957 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2020-11-09T16:48:43.181Z,1604940523.181 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2020-11-09T16:50:08.486Z,1604940608.486 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](INFO): Done Waiting.
2020-11-09T16:50:08.486Z,1604940608.486 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2020-11-09T16:50:08.486Z,1604940608.486 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-11-09T16:50:08.486Z,1604940608.486 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Running Loop=1
2020-11-09T16:50:08.862Z,1604940608.862 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Stopped
2020-11-09T16:50:08.862Z,1604940608.862 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Running Loop=1
2020-11-09T16:50:09.269Z,1604940609.269 [DefaultWithUndock:SurfaceDefault:CheckIn:E](IMPORTANT): Default mission has been running for 22.073468 min 
2020-11-09T16:50:09.269Z,1604940609.269 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Stopped
2020-11-09T16:50:09.270Z,1604940609.270 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Completed DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T16:50:09.270Z,1604940609.270 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-11-09T16:50:09.270Z,1604940609.270 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T16:50:09.270Z,1604940609.270 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Running loop #3
2020-11-09T16:50:09.270Z,1604940609.270 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=3
2020-11-09T16:50:09.270Z,1604940609.270 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T16:50:09.270Z,1604940609.270 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-11-09T16:50:42.005Z,1604940642.005 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2020-11-09T16:50:42.080Z,1604940642.080 [NAL9602](FAULT): received: 
+CSQ:0

OK
2020-11-09T16:50:42.080Z,1604940642.080 [NAL9602] Data Fault, FailCount= 2
2020-11-09T16:50:42.080Z,1604940642.080 [NAL9602](ERROR): Data Fault
2020-11-09T16:50:42.118Z,1604940642.118 [CBIT](ERROR): Data Fault in component: NAL9602
2020-11-09T16:50:42.374Z,1604940642.374 [NAL9602](INFO): Powering down
2020-11-09T16:50:43.215Z,1604940643.215 [CBIT](INFO): Clearing failed state for component NAL9602
2020-11-09T16:50:43.215Z,1604940643.215 [NAL9602] No Fault, FailCount= 2
2020-11-09T16:51:12.678Z,1604940672.678 [NAL9602](INFO): Powering up NAL9602
2020-11-09T16:51:23.586Z,1604940683.586 [NAL9602](INFO): NAL9602 initialized
2020-11-09T16:51:24.388Z,1604940684.388 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-11-09T16:51:24.388Z,1604940684.388 [NAL9602] Data Fault, FailCount= 3
2020-11-09T16:51:24.388Z,1604940684.388 [NAL9602](ERROR): Data Fault
2020-11-09T16:51:24.431Z,1604940684.431 [CBIT](ERROR): Data Fault in component: NAL9602
2020-11-09T16:51:24.798Z,1604940684.798 [NAL9602](INFO): Powering down
2020-11-09T16:51:25.625Z,1604940685.625 [CBIT](INFO): Clearing failed state for component NAL9602
2020-11-09T16:51:25.625Z,1604940685.625 [NAL9602] No Fault, FailCount= 3
2020-11-09T16:51:28.441Z,1604940688.441 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-11-09T16:51:55.102Z,1604940715.102 [NAL9602](INFO): Powering up NAL9602
2020-11-09T16:52:06.025Z,1604940726.025 [NAL9602](INFO): NAL9602 initialized
2020-11-09T16:54:00.815Z,1604940840.815 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude
2020-11-09T16:55:09.452Z,1604940909.452 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS](INFO): Timed out from 2020-11-09T16:50:09.3Z
2020-11-09T16:55:09.452Z,1604940909.452 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-11-09T16:55:09.452Z,1604940909.452 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-11-09T16:55:13.058Z,1604940913.058 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-11-09T16:55:13.335Z,1604940913.335 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20201109T162425/Courier0010.lzma
2020-11-09T16:55:14.338Z,1604940914.338 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Courier0010.lzma.bak
2020-11-09T16:55:14.338Z,1604940914.338 [DataOverHttps](INFO): SBD MOMSN=55012
2020-11-09T16:55:21.959Z,1604940921.959 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2020-11-09T16:55:23.375Z,1604940923.375 [DataOverHttps](INFO): Sending 243 bytes from file Logs/20201109T162425/Express0011.lzma
2020-11-09T16:55:24.386Z,1604940924.386 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Express0011.lzma.bak
2020-11-09T16:55:24.386Z,1604940924.386 [DataOverHttps](INFO): SBD MOMSN=55014
2020-11-09T16:55:25.595Z,1604940925.595 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-11-09T16:55:25.596Z,1604940925.596 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-11-09T16:55:25.596Z,1604940925.596 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-11-09T16:55:43.804Z,1604940943.804 [NAL9602](INFO): Not Powering down - fast GPS
2020-11-09T17:00:26.182Z,1604941226.182 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](INFO): Done Waiting.
2020-11-09T17:00:26.182Z,1604941226.182 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2020-11-09T17:00:26.183Z,1604941226.183 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-11-09T17:00:26.183Z,1604941226.183 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Running Loop=1
2020-11-09T17:00:26.588Z,1604941226.588 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Stopped
2020-11-09T17:00:26.588Z,1604941226.588 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Running Loop=1
2020-11-09T17:00:27.011Z,1604941227.011 [DefaultWithUndock:SurfaceDefault:CheckIn:E](IMPORTANT): Default mission has been running for 32.368899 min 
2020-11-09T17:00:27.011Z,1604941227.011 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Stopped
2020-11-09T17:00:27.011Z,1604941227.011 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Completed DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T17:00:27.011Z,1604941227.011 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-11-09T17:00:27.012Z,1604941227.012 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T17:00:27.012Z,1604941227.012 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Running loop #4
2020-11-09T17:00:27.012Z,1604941227.012 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=4
2020-11-09T17:00:27.012Z,1604941227.012 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T17:00:27.012Z,1604941227.012 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-11-09T17:00:59.694Z,1604941259.694 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2020-11-09T17:00:59.772Z,1604941259.772 [NAL9602](FAULT): received: 
+CSQ:0

OK
2020-11-09T17:00:59.772Z,1604941259.772 [NAL9602] Data Fault, FailCount= 4
2020-11-09T17:00:59.772Z,1604941259.772 [NAL9602](ERROR): Data Fault
2020-11-09T17:00:59.848Z,1604941259.848 [CBIT](ERROR): Data Fault in component: NAL9602
2020-11-09T17:01:00.113Z,1604941260.113 [NAL9602](INFO): Powering down
2020-11-09T17:01:00.965Z,1604941260.965 [CBIT](INFO): Clearing failed state for component NAL9602
2020-11-09T17:01:00.965Z,1604941260.965 [NAL9602] No Fault, FailCount= 4
2020-11-09T17:01:30.394Z,1604941290.394 [NAL9602](INFO): Powering up NAL9602
2020-11-09T17:01:41.310Z,1604941301.310 [NAL9602](INFO): NAL9602 initialized
2020-11-09T17:05:27.200Z,1604941527.200 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS](INFO): Timed out from 2020-11-09T17:00:27.0Z
2020-11-09T17:05:27.201Z,1604941527.201 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-11-09T17:05:27.201Z,1604941527.201 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-11-09T17:05:30.956Z,1604941530.956 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20201109T162425/Courier0013.lzma
2020-11-09T17:05:31.193Z,1604941531.193 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-11-09T17:05:31.962Z,1604941531.962 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Courier0013.lzma.bak
2020-11-09T17:05:31.962Z,1604941531.962 [DataOverHttps](INFO): SBD MOMSN=55020
2020-11-09T17:05:41.011Z,1604941541.011 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20201109T162425/Express0014.lzma
2020-11-09T17:05:42.010Z,1604941542.010 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Express0014.lzma.bak
2020-11-09T17:05:42.010Z,1604941542.010 [DataOverHttps](INFO): SBD MOMSN=55022
2020-11-09T17:05:43.336Z,1604941543.336 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-11-09T17:05:43.336Z,1604941543.336 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-11-09T17:05:43.336Z,1604941543.336 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-11-09T17:06:01.889Z,1604941561.889 [NAL9602](INFO): Not Powering down - fast GPS
2020-11-09T17:07:34.048Z,1604941654.048 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-11-09T17:09:49.375Z,1604941789.375 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2020-11-09T17:10:43.932Z,1604941843.932 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](INFO): Done Waiting.
2020-11-09T17:10:43.932Z,1604941843.932 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2020-11-09T17:10:43.932Z,1604941843.932 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-11-09T17:10:43.932Z,1604941843.932 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Running Loop=1
2020-11-09T17:10:44.334Z,1604941844.334 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Stopped
2020-11-09T17:10:44.334Z,1604941844.334 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Running Loop=1
2020-11-09T17:10:44.766Z,1604941844.766 [DefaultWithUndock:SurfaceDefault:CheckIn:E](IMPORTANT): Default mission has been running for 42.664669 min 
2020-11-09T17:10:44.766Z,1604941844.766 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Stopped
2020-11-09T17:10:44.766Z,1604941844.766 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Completed DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T17:10:44.766Z,1604941844.766 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-11-09T17:10:44.766Z,1604941844.766 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T17:10:44.766Z,1604941844.766 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Running loop #5
2020-11-09T17:10:44.766Z,1604941844.766 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=5
2020-11-09T17:10:44.766Z,1604941844.766 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T17:10:44.766Z,1604941844.766 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-11-09T17:10:46.330Z,1604941846.330 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-11-09T17:10:46.330Z,1604941846.330 [NAL9602] Data Fault, FailCount= 5
2020-11-09T17:10:46.330Z,1604941846.330 [NAL9602](ERROR): Data Fault
2020-11-09T17:10:46.399Z,1604941846.399 [CBIT](ERROR): Data Fault in component: NAL9602
2020-11-09T17:10:46.404Z,1604941846.404 [CBIT](CRITICAL): Data Fault in component: NAL9602
2020-11-09T17:10:46.734Z,1604941846.734 [NAL9602](INFO): Powering down
2020-11-09T17:10:46.751Z,1604941846.751 [CommandLine](FAULT): Scheduling is paused
2020-11-09T17:10:46.752Z,1604941846.752 [CBIT](INFO): Critical error at 20201109T171046
2020-11-09T17:10:46.752Z,1604941846.752 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2020-11-09T17:11:52.189Z,1604941912.189 [RDI_Pathfinder](ERROR): only read 1 of 4 data items
2020-11-09T17:12:45.925Z,1604941965.925 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2020-11-09T17:12:46.373Z,1604941966.373 [CBIT](INFO): Clearing failed state for component NAL9602
2020-11-09T17:12:46.373Z,1604941966.373 [NAL9602] No Fault, FailCount= 5
2020-11-09T17:12:46.722Z,1604941966.722 [NAL9602](INFO): Powering up NAL9602
2020-11-09T17:12:57.630Z,1604941977.630 [NAL9602](INFO): NAL9602 initialized
2020-11-09T17:14:39.449Z,1604942079.449 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-11-09T17:15:44.981Z,1604942144.981 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS](INFO): Timed out from 2020-11-09T17:10:44.8Z
2020-11-09T17:15:44.981Z,1604942144.981 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-11-09T17:15:44.981Z,1604942144.981 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-11-09T17:15:48.555Z,1604942148.555 [DataOverHttps](INFO): Sending 118 bytes from file Logs/20201109T162425/Courier0016.lzma
2020-11-09T17:15:49.561Z,1604942149.561 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Courier0016.lzma.bak
2020-11-09T17:15:49.562Z,1604942149.562 [DataOverHttps](INFO): SBD MOMSN=55027
2020-11-09T17:15:58.600Z,1604942158.600 [DataOverHttps](INFO): Sending 264 bytes from file Logs/20201109T162425/Express0017.lzma
2020-11-09T17:15:59.602Z,1604942159.602 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Express0017.lzma.bak
2020-11-09T17:15:59.602Z,1604942159.602 [DataOverHttps](INFO): SBD MOMSN=55030
2020-11-09T17:16:00.940Z,1604942160.940 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-11-09T17:16:00.940Z,1604942160.940 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-11-09T17:16:00.940Z,1604942160.940 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-11-09T17:16:59.148Z,1604942219.148 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude
2020-11-09T17:18:01.293Z,1604942281.293 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-11-09T17:18:20.293Z,1604942300.293 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items
2020-11-09T17:18:32.004Z,1604942312.004 [NAL9602](INFO): Not Powering down - fast GPS
2020-11-09T17:21:01.509Z,1604942461.509 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](INFO): Done Waiting.
2020-11-09T17:21:01.509Z,1604942461.509 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2020-11-09T17:21:01.509Z,1604942461.509 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-11-09T17:21:01.509Z,1604942461.509 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Running Loop=1
2020-11-09T17:21:01.903Z,1604942461.903 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Stopped
2020-11-09T17:21:01.903Z,1604942461.903 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Running Loop=1
2020-11-09T17:21:02.313Z,1604942462.313 [DefaultWithUndock:SurfaceDefault:CheckIn:E](IMPORTANT): Default mission has been running for 52.957475 min 
2020-11-09T17:21:02.313Z,1604942462.313 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Stopped
2020-11-09T17:21:02.313Z,1604942462.313 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Completed DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T17:21:02.313Z,1604942462.313 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-11-09T17:21:02.313Z,1604942462.313 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T17:21:02.313Z,1604942462.313 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Running loop #6
2020-11-09T17:21:02.313Z,1604942462.313 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=6
2020-11-09T17:21:02.313Z,1604942462.313 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T17:21:02.313Z,1604942462.313 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-11-09T17:21:35.010Z,1604942495.010 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2020-11-09T17:21:35.084Z,1604942495.084 [NAL9602](FAULT): received: 
+CSQ:0

OK
2020-11-09T17:21:35.084Z,1604942495.084 [NAL9602] Data Fault, FailCount= 1
2020-11-09T17:21:35.084Z,1604942495.084 [NAL9602](ERROR): Data Fault
2020-11-09T17:21:35.165Z,1604942495.165 [CBIT](ERROR): Data Fault in component: NAL9602
2020-11-09T17:21:35.414Z,1604942495.414 [NAL9602](INFO): Powering down
2020-11-09T17:21:36.305Z,1604942496.305 [CBIT](INFO): Clearing failed state for component NAL9602
2020-11-09T17:21:36.305Z,1604942496.305 [NAL9602] No Fault, FailCount= 1
2020-11-09T17:22:05.718Z,1604942525.718 [NAL9602](INFO): Powering up NAL9602
2020-11-09T17:22:16.626Z,1604942536.626 [NAL9602](INFO): NAL9602 initialized
2020-11-09T17:22:24.767Z,1604942544.767 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items
2020-11-09T17:26:02.484Z,1604942762.484 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS](INFO): Timed out from 2020-11-09T17:21:02.3Z
2020-11-09T17:26:02.484Z,1604942762.484 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-11-09T17:26:02.484Z,1604942762.484 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-11-09T17:26:06.106Z,1604942766.106 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-11-09T17:26:06.147Z,1604942766.147 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20201109T162425/Courier0019.lzma
2020-11-09T17:26:07.150Z,1604942767.150 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Courier0019.lzma.bak
2020-11-09T17:26:07.150Z,1604942767.150 [DataOverHttps](INFO): SBD MOMSN=55036
2020-11-09T17:26:16.187Z,1604942776.187 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20201109T162425/Express0020.lzma
2020-11-09T17:26:17.190Z,1604942777.190 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Express0020.lzma.bak
2020-11-09T17:26:17.190Z,1604942777.190 [DataOverHttps](INFO): SBD MOMSN=55038
2020-11-09T17:26:18.270Z,1604942778.270 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-11-09T17:26:18.270Z,1604942778.270 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-11-09T17:26:18.271Z,1604942778.271 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-11-09T17:26:36.825Z,1604942796.825 [NAL9602](INFO): Not Powering down - fast GPS
2020-11-09T17:26:45.303Z,1604942805.303 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-11-09T17:26:55.006Z,1604942815.006 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-11-09T17:31:18.827Z,1604943078.827 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](INFO): Done Waiting.
2020-11-09T17:31:18.827Z,1604943078.827 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2020-11-09T17:31:18.827Z,1604943078.827 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-11-09T17:31:18.828Z,1604943078.828 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Running Loop=1
2020-11-09T17:31:19.245Z,1604943079.245 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Stopped
2020-11-09T17:31:19.245Z,1604943079.245 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Running Loop=1
2020-11-09T17:31:19.650Z,1604943079.650 [DefaultWithUndock:SurfaceDefault:CheckIn:E](IMPORTANT): Default mission has been running for 63.246509 min 
2020-11-09T17:31:19.650Z,1604943079.650 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Stopped
2020-11-09T17:31:19.650Z,1604943079.650 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Completed DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T17:31:19.650Z,1604943079.650 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-11-09T17:31:19.650Z,1604943079.650 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T17:31:19.650Z,1604943079.650 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Running loop #7
2020-11-09T17:31:19.650Z,1604943079.650 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=7
2020-11-09T17:31:19.651Z,1604943079.651 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T17:31:19.651Z,1604943079.651 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-11-09T17:31:21.242Z,1604943081.242 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-11-09T17:31:21.242Z,1604943081.242 [NAL9602] Data Fault, FailCount= 2
2020-11-09T17:31:21.242Z,1604943081.242 [NAL9602](ERROR): Data Fault
2020-11-09T17:31:21.291Z,1604943081.291 [CBIT](ERROR): Data Fault in component: NAL9602
2020-11-09T17:31:21.646Z,1604943081.646 [NAL9602](INFO): Powering down
2020-11-09T17:31:22.475Z,1604943082.475 [CBIT](INFO): Clearing failed state for component NAL9602
2020-11-09T17:31:22.476Z,1604943082.476 [NAL9602] No Fault, FailCount= 2
2020-11-09T17:31:51.984Z,1604943111.984 [NAL9602](INFO): Powering up NAL9602
2020-11-09T17:32:02.869Z,1604943122.869 [NAL9602](INFO): NAL9602 initialized
2020-11-09T17:32:29.124Z,1604943149.124 [NAL9602](INFO): SBD MO Status=0, MOMSN=11716, MT Status=0, MTMSN=0
2020-11-09T17:32:29.124Z,1604943149.124 [NAL9602](INFO): No messages in MT queue
2020-11-09T17:32:32.762Z,1604943152.762 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173231.00,A,4131.45624,N,07040.30943,W,0.039,0.00,091120,,,A*70
2020-11-09T17:32:32.766Z,1604943152.766 [NAL9602](INFO): GPS fix at 20201109T173231: (41.524271, -70.671824)
2020-11-09T17:32:32.801Z,1604943152.801 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-11-09T17:32:32.801Z,1604943152.801 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-11-09T17:32:36.751Z,1604943156.751 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20201109T162425/Courier0022.lzma
2020-11-09T17:32:37.754Z,1604943157.754 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Courier0022.lzma.bak
2020-11-09T17:32:37.754Z,1604943157.754 [DataOverHttps](INFO): SBD MOMSN=55043
2020-11-09T17:32:46.800Z,1604943166.800 [DataOverHttps](INFO): Sending 229 bytes from file Logs/20201109T162425/Express0023.lzma
2020-11-09T17:32:47.794Z,1604943167.794 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Express0023.lzma.bak
2020-11-09T17:32:47.794Z,1604943167.794 [DataOverHttps](INFO): SBD MOMSN=55046
2020-11-09T17:32:48.928Z,1604943168.928 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-11-09T17:32:48.928Z,1604943168.928 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-11-09T17:32:48.928Z,1604943168.928 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-11-09T17:32:49.342Z,1604943169.342 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-11-09T17:33:05.478Z,1604943185.478 [NAL9602](INFO): Not Powering down - fast GPS
2020-11-09T17:36:22.741Z,1604943382.741 [CommandLine](IMPORTANT): got command ibit
2020-11-09T17:36:23.093Z,1604943383.093 [IBIT](IMPORTANT): Beginning Initiated BIT
2020-11-09T17:36:23.094Z,1604943383.094 [IBIT](IMPORTANT): Beginning control surface checks.
2020-11-09T17:36:23.101Z,1604943383.101 [CBIT](IMPORTANT): Beginning ground fault scan
2020-11-09T17:36:24.656Z,1604943384.656 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173623.00,A,4131.45754,N,07040.31023,W,0.019,0.00,091120,,,A*7D
2020-11-09T17:36:24.658Z,1604943384.658 [NAL9602](INFO): GPS fix at 20201109T173623: (41.524292, -70.671837)
2020-11-09T17:36:34.044Z,1604943394.044 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.009518
CHAN A1 (24V): -0.028447
CHAN A2 (12V): -0.007603
CHAN A3 (5V): -0.001827
CHAN B0 (3.3V): 0.000267
CHAN B1 (3.15aV): -0.000123
CHAN B2 (3.15bV): 0.000223
CHAN B3 (GND): 0.002019
OPEN: 0.005598
Full Scale Calc: 4.765 mA, -1.589 mA
2020-11-09T17:36:36.817Z,1604943396.817 [NAL9602](INFO): SBD MO Status=0, MOMSN=11717, MT Status=0, MTMSN=0
2020-11-09T17:36:36.817Z,1604943396.817 [NAL9602](INFO): No messages in MT queue
2020-11-09T17:36:36.817Z,1604943396.817 [NAL9602](INFO): Failure count cleared after critical for NAL9602
2020-11-09T17:36:37.991Z,1604943397.991 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173637.00,A,4131.45690,N,07040.30950,W,0.175,0.00,091120,,,A*76
2020-11-09T17:36:37.993Z,1604943397.993 [NAL9602](INFO): GPS fix at 20201109T173637: (41.524282, -70.671825)
2020-11-09T17:36:40.812Z,1604943400.812 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173640.00,A,4131.45684,N,07040.30932,W,0.136,0.00,091120,,,A*70
2020-11-09T17:36:40.814Z,1604943400.814 [NAL9602](INFO): GPS fix at 20201109T173640: (41.524281, -70.671822)
2020-11-09T17:36:44.048Z,1604943404.048 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173643.00,A,4131.45670,N,07040.30907,W,0.019,0.00,091120,,,A*72
2020-11-09T17:36:44.050Z,1604943404.050 [NAL9602](INFO): GPS fix at 20201109T173643: (41.524278, -70.671818)
2020-11-09T17:36:46.876Z,1604943406.876 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173646.00,A,4131.45671,N,07040.30898,W,0.019,0.00,091120,,,A*71
2020-11-09T17:36:46.878Z,1604943406.878 [NAL9602](INFO): GPS fix at 20201109T173646: (41.524279, -70.671816)
2020-11-09T17:36:49.703Z,1604943409.703 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173649.00,A,4131.45694,N,07040.30901,W,0.058,0.00,091120,,,A*71
2020-11-09T17:36:49.713Z,1604943409.713 [NAL9602](INFO): GPS fix at 20201109T173649: (41.524282, -70.671817)
2020-11-09T17:36:52.962Z,1604943412.962 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173652.00,A,4131.45708,N,07040.30907,W,0.078,0.00,091120,,,A*7B
2020-11-09T17:36:52.969Z,1604943412.969 [NAL9602](INFO): GPS fix at 20201109T173652: (41.524285, -70.671818)
2020-11-09T17:36:55.780Z,1604943415.780 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173655.00,A,4131.45727,N,07040.30929,W,0.058,0.00,091120,,,A*7F
2020-11-09T17:36:55.782Z,1604943415.782 [NAL9602](INFO): GPS fix at 20201109T173655: (41.524288, -70.671821)
2020-11-09T17:36:58.992Z,1604943418.992 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173658.00,A,4131.45742,N,07040.30947,W,0.156,0.00,091120,,,A*76
2020-11-09T17:36:58.994Z,1604943418.994 [NAL9602](INFO): GPS fix at 20201109T173658: (41.524290, -70.671824)
2020-11-09T17:37:01.823Z,1604943421.823 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173701.00,A,4131.45753,N,07040.30963,W,0.078,0.00,091120,,,A*70
2020-11-09T17:37:01.826Z,1604943421.826 [NAL9602](INFO): GPS fix at 20201109T173701: (41.524292, -70.671827)
2020-11-09T17:37:05.052Z,1604943425.052 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173704.00,A,4131.45764,N,07040.30975,W,0.058,0.00,091120,,,A*74
2020-11-09T17:37:05.054Z,1604943425.054 [NAL9602](INFO): GPS fix at 20201109T173704: (41.524294, -70.671829)
2020-11-09T17:37:07.907Z,1604943427.907 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173707.00,A,4131.45766,N,07040.30979,W,0.058,0.00,091120,,,A*79
2020-11-09T17:37:07.921Z,1604943427.921 [NAL9602](INFO): GPS fix at 20201109T173707: (41.524294, -70.671830)
2020-11-09T17:37:09.563Z,1604943429.563 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 3
Latitude: 41.524296 Longitude: -70.671829
2020-11-09T17:37:09.919Z,1604943429.919 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 362.684998
Voltage: 16.611000
2020-11-09T17:37:09.919Z,1604943429.919 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2020-11-09T17:37:09.920Z,1604943429.920 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2020-11-09T17:37:10.397Z,1604943430.397 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2020-11-09T17:37:10.397Z,1604943430.397 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2020-11-09T17:37:10.397Z,1604943430.397 [IBIT](IMPORTANT): Pressure:6.594876 PSI
2020-11-09T17:37:10.398Z,1604943430.398 [IBIT](IMPORTANT): Humidity:14.937126 %
2020-11-09T17:37:10.767Z,1604943430.767 [IBIT](IMPORTANT): Vehicle Pitch:-0.575637 degrees
2020-11-09T17:37:10.767Z,1604943430.767 [IBIT](IMPORTANT): Vehicle  Roll:0.032006 degrees
2020-11-09T17:37:10.772Z,1604943430.772 [IBIT](IMPORTANT): Vehicle  Heading:253.410706 degrees
2020-11-09T17:37:11.169Z,1604943431.169 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2020-11-09T17:37:11.169Z,1604943431.169 [IBIT](IMPORTANT): buoyancyNeutral: 200.000000 cc
2020-11-09T17:37:11.169Z,1604943431.169 [IBIT](IMPORTANT): massDefault: 0.300000 cm
2020-11-09T17:37:11.170Z,1604943431.170 [IBIT](IMPORTANT): stopDepth: 12.000000 m
2020-11-09T17:37:11.170Z,1604943431.170 [IBIT](IMPORTANT): abortDepth: 16.000000 m
2020-11-09T17:37:11.170Z,1604943431.170 [IBIT](IMPORTANT): IBIT PASSED
2020-11-09T17:37:40.202Z,1604943460.202 [NAL9602](INFO): Not Powering down - fast GPS
2020-11-09T17:37:49.623Z,1604943469.623 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](INFO): Done Waiting.
2020-11-09T17:37:49.623Z,1604943469.623 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2020-11-09T17:37:49.623Z,1604943469.623 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-11-09T17:37:49.623Z,1604943469.623 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Running Loop=1
2020-11-09T17:37:49.916Z,1604943469.916 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Stopped
2020-11-09T17:37:49.916Z,1604943469.916 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Running Loop=1
2020-11-09T17:37:50.385Z,1604943470.385 [DefaultWithUndock:SurfaceDefault:CheckIn:E](IMPORTANT): Default mission has been running for 69.757690 min 
2020-11-09T17:37:50.385Z,1604943470.385 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Stopped
2020-11-09T17:37:50.385Z,1604943470.385 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Completed DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T17:37:50.385Z,1604943470.385 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-11-09T17:37:50.385Z,1604943470.385 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T17:37:50.386Z,1604943470.386 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Running loop #8
2020-11-09T17:37:50.386Z,1604943470.386 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=8
2020-11-09T17:37:50.386Z,1604943470.386 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T17:37:50.386Z,1604943470.386 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-11-09T17:37:52.333Z,1604943472.333 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173751.00,A,4131.45855,N,07040.31018,W,0.039,0.00,091120,,,A*7D
2020-11-09T17:37:52.335Z,1604943472.335 [NAL9602](INFO): GPS fix at 20201109T173751: (41.524309, -70.671836)
2020-11-09T17:37:52.356Z,1604943472.356 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-11-09T17:37:52.356Z,1604943472.356 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-11-09T17:37:56.103Z,1604943476.103 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20201109T162425/Courier0025.lzma
2020-11-09T17:37:57.106Z,1604943477.106 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Courier0025.lzma.bak
2020-11-09T17:37:57.106Z,1604943477.106 [DataOverHttps](INFO): SBD MOMSN=55053
2020-11-09T17:38:06.145Z,1604943486.145 [DataOverHttps](INFO): Sending 765 bytes from file Logs/20201109T162425/Express0026.lzma
2020-11-09T17:38:07.146Z,1604943487.146 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Express0026.lzma.bak
2020-11-09T17:38:07.146Z,1604943487.146 [DataOverHttps](INFO): SBD MOMSN=55056
2020-11-09T17:38:08.179Z,1604943488.179 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-11-09T17:38:08.179Z,1604943488.179 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-11-09T17:38:08.179Z,1604943488.179 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-11-09T17:38:31.915Z,1604943511.915 [NAL9602](INFO): SBD MO Status=0, MOMSN=11718, MT Status=0, MTMSN=0
2020-11-09T17:38:31.916Z,1604943511.916 [NAL9602](INFO): No messages in MT queue
2020-11-09T17:39:02.617Z,1604943542.617 [NAL9602](INFO): Not Powering down - fast GPS
2020-11-09T17:39:34.139Z,1604943574.139 [RDI_Pathfinder](ERROR): only read -1 of 4 data items
2020-11-09T17:39:44.738Z,1604943584.738 [CommandLine](IMPORTANT): got command failComponent
2020-11-09T17:39:44.739Z,1604943584.739 [CommandLine](IMPORTANT): Failed components:
2020-11-09T17:39:44.739Z,1604943584.739 [CommandLine](IMPORTANT): No failed Components.
2020-11-09T17:40:15.361Z,1604943615.361 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-11-09T17:40:15.363Z,1604943615.363 [BPC1](INFO): Received data from all battery sticks.
2020-11-09T17:41:45.846Z,1604943705.846 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2020-11-09T17:42:06.063Z,1604943726.063 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items
2020-11-09T17:43:08.679Z,1604943788.679 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](INFO): Done Waiting.
2020-11-09T17:43:08.680Z,1604943788.680 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2020-11-09T17:43:08.680Z,1604943788.680 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-11-09T17:43:08.680Z,1604943788.680 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Running Loop=1
2020-11-09T17:43:09.123Z,1604943789.123 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Stopped
2020-11-09T17:43:09.123Z,1604943789.123 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Running Loop=1
2020-11-09T17:43:09.513Z,1604943789.513 [DefaultWithUndock:SurfaceDefault:CheckIn:E](IMPORTANT): Default mission has been running for 75.077808 min 
2020-11-09T17:43:09.513Z,1604943789.513 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Stopped
2020-11-09T17:43:09.513Z,1604943789.513 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Completed DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T17:43:09.513Z,1604943789.513 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-11-09T17:43:09.513Z,1604943789.513 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T17:43:09.514Z,1604943789.514 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Running loop #9
2020-11-09T17:43:09.514Z,1604943789.514 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=9
2020-11-09T17:43:09.514Z,1604943789.514 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T17:43:09.514Z,1604943789.514 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-11-09T17:43:11.498Z,1604943791.498 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174310.00,A,4131.46170,N,07040.31167,W,0.039,0.00,091120,,,A*7F
2020-11-09T17:43:11.505Z,1604943791.505 [NAL9602](INFO): GPS fix at 20201109T174310: (41.524362, -70.671861)
2020-11-09T17:43:11.515Z,1604943791.515 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-11-09T17:43:11.515Z,1604943791.515 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-11-09T17:43:15.419Z,1604943795.419 [DataOverHttps](INFO): Sending 83 bytes from file Logs/20201109T162425/Courier0028.lzma
2020-11-09T17:43:16.422Z,1604943796.422 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Courier0028.lzma.bak
2020-11-09T17:43:16.422Z,1604943796.422 [DataOverHttps](INFO): SBD MOMSN=55082
2020-11-09T17:43:25.467Z,1604943805.467 [DataOverHttps](INFO): Sending 178 bytes from file Logs/20201109T162425/Express0029.lzma
2020-11-09T17:43:26.470Z,1604943806.470 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Express0029.lzma.bak
2020-11-09T17:43:26.470Z,1604943806.470 [DataOverHttps](INFO): SBD MOMSN=55085
2020-11-09T17:43:26.851Z,1604943806.851 [NAL9602](INFO): SBD MO Status=0, MOMSN=11719, MT Status=0, MTMSN=0
2020-11-09T17:43:26.851Z,1604943806.851 [NAL9602](INFO): No messages in MT queue
2020-11-09T17:43:27.667Z,1604943807.667 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-11-09T17:43:27.667Z,1604943807.667 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-11-09T17:43:27.668Z,1604943807.668 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-11-09T17:43:57.552Z,1604943837.552 [NAL9602](INFO): Not Powering down - fast GPS
2020-11-09T17:46:11.291Z,1604943971.291 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-11-09T17:46:16.135Z,1604943976.135 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-11-09T17:46:41.186Z,1604944001.186 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2020-11-09T17:48:28.299Z,1604944108.299 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](INFO): Done Waiting.
2020-11-09T17:48:28.299Z,1604944108.299 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2020-11-09T17:48:28.299Z,1604944108.299 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-11-09T17:48:28.299Z,1604944108.299 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Running Loop=1
2020-11-09T17:48:28.656Z,1604944108.656 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Stopped
2020-11-09T17:48:28.656Z,1604944108.656 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Running Loop=1
2020-11-09T17:48:29.064Z,1604944109.064 [DefaultWithUndock:SurfaceDefault:CheckIn:E](IMPORTANT): Default mission has been running for 80.403353 min 
2020-11-09T17:48:29.065Z,1604944109.065 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Stopped
2020-11-09T17:48:29.065Z,1604944109.065 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Completed DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T17:48:29.065Z,1604944109.065 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-11-09T17:48:29.065Z,1604944109.065 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T17:48:29.066Z,1604944109.066 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Running loop #10
2020-11-09T17:48:29.066Z,1604944109.066 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=10
2020-11-09T17:48:29.066Z,1604944109.066 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T17:48:29.066Z,1604944109.066 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-11-09T17:48:31.101Z,1604944111.101 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174830.00,A,4131.45762,N,07040.31081,W,0.136,0.00,091120,,,A*77
2020-11-09T17:48:31.103Z,1604944111.103 [NAL9602](INFO): GPS fix at 20201109T174830: (41.524294, -70.671847)
2020-11-09T17:48:31.172Z,1604944111.172 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-11-09T17:48:31.172Z,1604944111.172 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-11-09T17:48:34.747Z,1604944114.747 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20201109T162425/Courier0031.lzma
2020-11-09T17:48:35.749Z,1604944115.749 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Courier0031.lzma.bak
2020-11-09T17:48:35.750Z,1604944115.750 [DataOverHttps](INFO): SBD MOMSN=55092
2020-11-09T17:48:47.795Z,1604944127.795 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20201109T162425/Express0032.lzma
2020-11-09T17:48:48.798Z,1604944128.798 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Express0032.lzma.bak
2020-11-09T17:48:48.798Z,1604944128.798 [DataOverHttps](INFO): SBD MOMSN=55095
2020-11-09T17:48:50.112Z,1604944130.112 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-11-09T17:48:50.112Z,1604944130.112 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-11-09T17:48:50.112Z,1604944130.112 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-11-09T17:48:58.543Z,1604944138.543 [NAL9602](INFO): SBD MO Status=2, MOMSN=11720, MT Status=2, MTMSN=0
2020-11-09T17:48:58.544Z,1604944138.544 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-11-09T17:49:17.127Z,1604944157.127 [NAL9602](INFO): SBD MO Status=2, MOMSN=11720, MT Status=2, MTMSN=0
2020-11-09T17:49:17.146Z,1604944157.146 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-11-09T17:49:27.631Z,1604944167.631 [NAL9602](INFO): SBD MO Status=0, MOMSN=11720, MT Status=0, MTMSN=0
2020-11-09T17:49:27.632Z,1604944167.632 [NAL9602](INFO): No messages in MT queue
2020-11-09T17:49:58.330Z,1604944198.330 [NAL9602](INFO): Not Powering down - fast GPS
2020-11-09T17:52:06.004Z,1604944326.004 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2020-11-09T17:53:50.662Z,1604944430.662 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](INFO): Done Waiting.
2020-11-09T17:53:50.662Z,1604944430.662 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2020-11-09T17:53:50.662Z,1604944430.662 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-11-09T17:53:50.662Z,1604944430.662 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Running Loop=1
2020-11-09T17:53:51.082Z,1604944431.082 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Stopped
2020-11-09T17:53:51.082Z,1604944431.082 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Running Loop=1
2020-11-09T17:53:51.476Z,1604944431.476 [DefaultWithUndock:SurfaceDefault:CheckIn:E](IMPORTANT): Default mission has been running for 85.777124 min 
2020-11-09T17:53:51.476Z,1604944431.476 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Stopped
2020-11-09T17:53:51.476Z,1604944431.476 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Completed DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T17:53:51.476Z,1604944431.476 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-11-09T17:53:51.476Z,1604944431.476 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T17:53:51.477Z,1604944431.477 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Running loop #11
2020-11-09T17:53:51.477Z,1604944431.477 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=11
2020-11-09T17:53:51.477Z,1604944431.477 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T17:53:51.477Z,1604944431.477 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-11-09T17:53:53.472Z,1604944433.472 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175352.00,A,4131.45634,N,07040.31164,W,0.117,0.00,091120,,,A*72
2020-11-09T17:53:53.474Z,1604944433.474 [NAL9602](INFO): GPS fix at 20201109T175352: (41.524272, -70.671861)
2020-11-09T17:53:53.485Z,1604944433.485 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-11-09T17:53:53.485Z,1604944433.485 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-11-09T17:53:57.095Z,1604944437.095 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20201109T162425/Courier0034.lzma
2020-11-09T17:53:58.101Z,1604944438.101 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Courier0034.lzma.bak
2020-11-09T17:53:58.101Z,1604944438.101 [DataOverHttps](INFO): SBD MOMSN=55099
2020-11-09T17:54:07.135Z,1604944447.135 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20201109T162425/Express0035.lzma
2020-11-09T17:54:08.139Z,1604944448.139 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Express0035.lzma.bak
2020-11-09T17:54:08.140Z,1604944448.140 [DataOverHttps](INFO): SBD MOMSN=55103
2020-11-09T17:54:09.249Z,1604944449.249 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-11-09T17:54:09.249Z,1604944449.249 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-11-09T17:54:09.249Z,1604944449.249 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-11-09T17:54:12.863Z,1604944452.863 [NAL9602](INFO): SBD MO Status=0, MOMSN=11721, MT Status=0, MTMSN=0
2020-11-09T17:54:12.863Z,1604944452.863 [NAL9602](INFO): No messages in MT queue
2020-11-09T17:54:43.562Z,1604944483.562 [NAL9602](INFO): Not Powering down - fast GPS
2020-11-09T17:55:20.868Z,1604944520.868 [RDI_PathfinderUp](ERROR): only read -1 of 1 data item for altitude
2020-11-09T17:59:09.815Z,1604944749.815 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](INFO): Done Waiting.
2020-11-09T17:59:09.816Z,1604944749.816 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2020-11-09T17:59:09.816Z,1604944749.816 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-11-09T17:59:09.816Z,1604944749.816 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Running Loop=1
2020-11-09T17:59:10.234Z,1604944750.234 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Stopped
2020-11-09T17:59:10.234Z,1604944750.234 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Running Loop=1
2020-11-09T17:59:10.661Z,1604944750.661 [DefaultWithUndock:SurfaceDefault:CheckIn:E](IMPORTANT): Default mission has been running for 91.096330 min 
2020-11-09T17:59:10.661Z,1604944750.661 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Stopped
2020-11-09T17:59:10.662Z,1604944750.662 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Completed DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T17:59:10.662Z,1604944750.662 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-11-09T17:59:10.662Z,1604944750.662 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T17:59:10.662Z,1604944750.662 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Running loop #12
2020-11-09T17:59:10.662Z,1604944750.662 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=12
2020-11-09T17:59:10.662Z,1604944750.662 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T17:59:10.662Z,1604944750.662 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-11-09T17:59:12.633Z,1604944752.633 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175911.00,A,4131.45717,N,07040.30826,W,0.000,69.51,091120,,,A*4D
2020-11-09T17:59:12.635Z,1604944752.635 [NAL9602](INFO): GPS fix at 20201109T175911: (41.524286, -70.671804)
2020-11-09T17:59:12.645Z,1604944752.645 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-11-09T17:59:12.645Z,1604944752.645 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-11-09T17:59:19.493Z,1604944759.493 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.295780
2020-11-09T17:59:50.640Z,1604944790.640 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-11-09T18:00:04.355Z,1604944804.355 [NAL9602](INFO): SBD MO Status=2, MOMSN=11722, MT Status=2, MTMSN=0
2020-11-09T18:00:04.355Z,1604944804.355 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-11-09T18:00:22.128Z,1604944822.128 [NAL9602](INFO): SBD MO Status=0, MOMSN=11722, MT Status=0, MTMSN=0
2020-11-09T18:00:22.129Z,1604944822.129 [NAL9602](INFO): No messages in MT queue
2020-11-09T18:00:25.780Z,1604944825.780 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-11-09T18:00:49.691Z,1604944849.691 [NAL9602](INFO): SBD MO Status=1, MOMSN=11723, MT Status=0, MTMSN=0
2020-11-09T18:00:49.748Z,1604944849.748 [NAL9602](INFO): Sent 72 bytes from file Logs/20201109T162425/Courier0037.lzma
2020-11-09T18:00:49.748Z,1604944849.748 [NAL9602](INFO): Packets left to send: 0
2020-11-09T18:01:00.928Z,1604944860.928 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-11-09T18:01:08.355Z,1604944868.355 [NAL9602](INFO): SBD MO Status=1, MOMSN=11724, MT Status=0, MTMSN=0
2020-11-09T18:01:08.405Z,1604944868.405 [NAL9602](INFO): Sent 120 bytes from file Logs/20201109T162425/Express0038.lzma
2020-11-09T18:01:08.405Z,1604944868.405 [NAL9602](INFO): Packets left to send: 0
2020-11-09T18:01:18.052Z,1604944878.052 [NAL9602](INFO): SBD MO Status=0, MOMSN=11725, MT Status=0, MTMSN=0
2020-11-09T18:01:18.161Z,1604944878.161 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-11-09T18:01:18.161Z,1604944878.161 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-11-09T18:01:18.161Z,1604944878.161 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-11-09T18:01:36.069Z,1604944896.069 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-11-09T18:01:48.749Z,1604944908.749 [NAL9602](INFO): Not Powering down - fast GPS
2020-11-09T18:02:11.232Z,1604944931.232 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-11-09T18:02:46.380Z,1604944966.380 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-11-09T18:02:58.432Z,1604944978.432 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003033
2020-11-09T18:06:02.067Z,1604945162.067 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-11-09T18:06:12.175Z,1604945172.175 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-11-09T18:06:18.647Z,1604945178.647 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](INFO): Done Waiting.
2020-11-09T18:06:18.647Z,1604945178.647 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2020-11-09T18:06:18.647Z,1604945178.647 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-11-09T18:06:18.647Z,1604945178.647 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Running Loop=1
2020-11-09T18:06:19.067Z,1604945179.067 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Stopped
2020-11-09T18:06:19.067Z,1604945179.067 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Running Loop=1
2020-11-09T18:06:19.499Z,1604945179.499 [DefaultWithUndock:SurfaceDefault:CheckIn:E](IMPORTANT): Default mission has been running for 98.243538 min 
2020-11-09T18:06:19.499Z,1604945179.499 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Stopped
2020-11-09T18:06:19.499Z,1604945179.499 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Completed DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:06:19.499Z,1604945179.499 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-11-09T18:06:19.504Z,1604945179.504 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:06:19.504Z,1604945179.504 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Running loop #13
2020-11-09T18:06:19.504Z,1604945179.504 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=13
2020-11-09T18:06:19.504Z,1604945179.504 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:06:19.504Z,1604945179.504 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-11-09T18:06:21.456Z,1604945181.456 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180620.00,A,4131.46093,N,07040.30939,W,0.078,69.51,091120,,,A*42
2020-11-09T18:06:21.458Z,1604945181.458 [NAL9602](INFO): GPS fix at 20201109T180620: (41.524349, -70.671823)
2020-11-09T18:06:21.469Z,1604945181.469 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-11-09T18:06:21.469Z,1604945181.469 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-11-09T18:06:22.269Z,1604945182.269 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2020-11-09T18:06:25.315Z,1604945185.315 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20201109T162425/Courier0040.lzma
2020-11-09T18:06:26.318Z,1604945186.318 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Courier0040.lzma.bak
2020-11-09T18:06:26.318Z,1604945186.318 [DataOverHttps](INFO): SBD MOMSN=55114
2020-11-09T18:06:35.355Z,1604945195.355 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20201109T162425/Express0041.lzma
2020-11-09T18:06:36.358Z,1604945196.358 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Express0041.lzma.bak
2020-11-09T18:06:36.358Z,1604945196.358 [DataOverHttps](INFO): SBD MOMSN=55117
2020-11-09T18:06:37.635Z,1604945197.635 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-11-09T18:06:37.636Z,1604945197.636 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-11-09T18:06:37.636Z,1604945197.636 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-11-09T18:06:38.831Z,1604945198.831 [NAL9602](INFO): SBD MO Status=0, MOMSN=11726, MT Status=0, MTMSN=0
2020-11-09T18:06:38.831Z,1604945198.831 [NAL9602](INFO): No messages in MT queue
2020-11-09T18:07:09.533Z,1604945229.533 [NAL9602](INFO): Not Powering down - fast GPS
2020-11-09T18:11:38.308Z,1604945498.308 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](INFO): Done Waiting.
2020-11-09T18:11:38.308Z,1604945498.308 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2020-11-09T18:11:38.308Z,1604945498.308 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-11-09T18:11:38.309Z,1604945498.309 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Running Loop=1
2020-11-09T18:11:38.637Z,1604945498.637 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Stopped
2020-11-09T18:11:38.637Z,1604945498.637 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Running Loop=1
2020-11-09T18:11:39.058Z,1604945499.058 [DefaultWithUndock:SurfaceDefault:CheckIn:E](IMPORTANT): Default mission has been running for 103.569710 min 
2020-11-09T18:11:39.058Z,1604945499.058 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Stopped
2020-11-09T18:11:39.058Z,1604945499.058 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Completed DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:11:39.058Z,1604945499.058 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-11-09T18:11:39.058Z,1604945499.058 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:11:39.058Z,1604945499.058 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Running loop #14
2020-11-09T18:11:39.058Z,1604945499.058 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=14
2020-11-09T18:11:39.059Z,1604945499.059 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:11:39.059Z,1604945499.059 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-11-09T18:11:41.039Z,1604945501.039 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181140.00,A,4131.46146,N,07040.30870,W,0.000,285.19,091120,,,A*74
2020-11-09T18:11:41.041Z,1604945501.041 [NAL9602](INFO): GPS fix at 20201109T181140: (41.524358, -70.671812)
2020-11-09T18:11:41.136Z,1604945501.136 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-11-09T18:11:41.137Z,1604945501.137 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-11-09T18:11:44.644Z,1604945504.644 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20201109T162425/Courier0043.lzma
2020-11-09T18:11:45.646Z,1604945505.646 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Courier0043.lzma.bak
2020-11-09T18:11:45.646Z,1604945505.646 [DataOverHttps](INFO): SBD MOMSN=55121
2020-11-09T18:11:54.683Z,1604945514.683 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20201109T162425/Express0044.lzma
2020-11-09T18:11:55.686Z,1604945515.686 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Express0044.lzma.bak
2020-11-09T18:11:55.686Z,1604945515.686 [DataOverHttps](INFO): SBD MOMSN=55124
2020-11-09T18:11:57.083Z,1604945517.083 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-11-09T18:11:57.088Z,1604945517.088 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-11-09T18:11:57.092Z,1604945517.092 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-11-09T18:12:05.483Z,1604945525.483 [NAL9602](INFO): SBD MO Status=0, MOMSN=11727, MT Status=0, MTMSN=0
2020-11-09T18:12:05.483Z,1604945525.483 [NAL9602](INFO): No messages in MT queue
2020-11-09T18:12:36.191Z,1604945556.191 [NAL9602](INFO): Not Powering down - fast GPS
2020-11-09T18:16:57.591Z,1604945817.591 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](INFO): Done Waiting.
2020-11-09T18:16:57.591Z,1604945817.591 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2020-11-09T18:16:57.591Z,1604945817.591 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-11-09T18:16:57.591Z,1604945817.591 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Running Loop=1
2020-11-09T18:16:58.015Z,1604945818.015 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Stopped
2020-11-09T18:16:58.015Z,1604945818.015 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Running Loop=1
2020-11-09T18:16:58.422Z,1604945818.422 [DefaultWithUndock:SurfaceDefault:CheckIn:E](IMPORTANT): Default mission has been running for 108.892684 min 
2020-11-09T18:16:58.422Z,1604945818.422 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Stopped
2020-11-09T18:16:58.422Z,1604945818.422 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Completed DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:16:58.423Z,1604945818.423 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-11-09T18:16:58.423Z,1604945818.423 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:16:58.423Z,1604945818.423 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Running loop #15
2020-11-09T18:16:58.423Z,1604945818.423 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=15
2020-11-09T18:16:58.423Z,1604945818.423 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:16:58.423Z,1604945818.423 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-11-09T18:17:00.408Z,1604945820.408 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181659.00,A,4131.46734,N,07040.31285,W,0.078,350.76,091120,,,A*76
2020-11-09T18:17:00.410Z,1604945820.410 [NAL9602](INFO): GPS fix at 20201109T181659: (41.524456, -70.671881)
2020-11-09T18:17:00.440Z,1604945820.440 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-11-09T18:17:00.440Z,1604945820.440 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-11-09T18:17:03.987Z,1604945823.987 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20201109T162425/Courier0046.lzma
2020-11-09T18:17:04.990Z,1604945824.990 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Courier0046.lzma.bak
2020-11-09T18:17:04.990Z,1604945824.990 [DataOverHttps](INFO): SBD MOMSN=55128
2020-11-09T18:17:14.027Z,1604945834.027 [DataOverHttps](INFO): Sending 122 bytes from file Logs/20201109T162425/Express0047.lzma
2020-11-09T18:17:15.030Z,1604945835.030 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Express0047.lzma.bak
2020-11-09T18:17:15.030Z,1604945835.030 [DataOverHttps](INFO): SBD MOMSN=55131
2020-11-09T18:17:16.198Z,1604945836.198 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-11-09T18:17:16.198Z,1604945836.198 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-11-09T18:17:16.198Z,1604945836.198 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-11-09T18:17:16.571Z,1604945836.571 [NAL9602](INFO): SBD MO Status=0, MOMSN=11728, MT Status=0, MTMSN=0
2020-11-09T18:17:16.571Z,1604945836.571 [NAL9602](INFO): No messages in MT queue
2020-11-09T18:17:47.270Z,1604945867.270 [NAL9602](INFO): Not Powering down - fast GPS
2020-11-09T18:22:03.039Z,1604946123.039 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2020-11-09T18:22:16.770Z,1604946136.770 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](INFO): Done Waiting.
2020-11-09T18:22:16.770Z,1604946136.770 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2020-11-09T18:22:16.770Z,1604946136.770 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-11-09T18:22:16.770Z,1604946136.770 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Running Loop=1
2020-11-09T18:22:17.199Z,1604946137.199 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Stopped
2020-11-09T18:22:17.199Z,1604946137.199 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Running Loop=1
2020-11-09T18:22:17.556Z,1604946137.556 [DefaultWithUndock:SurfaceDefault:CheckIn:E](IMPORTANT): Default mission has been running for 114.212410 min 
2020-11-09T18:22:17.556Z,1604946137.556 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Stopped
2020-11-09T18:22:17.556Z,1604946137.556 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Completed DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:22:17.556Z,1604946137.556 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-11-09T18:22:17.556Z,1604946137.556 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:22:17.557Z,1604946137.557 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Running loop #16
2020-11-09T18:22:17.557Z,1604946137.557 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=16
2020-11-09T18:22:17.557Z,1604946137.557 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:22:17.557Z,1604946137.557 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-11-09T18:22:19.568Z,1604946139.568 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182218.00,A,4131.46781,N,07040.31237,W,0.156,350.76,091120,,,D*7B
2020-11-09T18:22:19.570Z,1604946139.570 [NAL9602](INFO): GPS fix at 20201109T182218: (41.524464, -70.671873)
2020-11-09T18:22:19.590Z,1604946139.590 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-11-09T18:22:19.591Z,1604946139.591 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-11-09T18:22:23.307Z,1604946143.307 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20201109T162425/Courier0049.lzma
2020-11-09T18:22:24.310Z,1604946144.310 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Courier0049.lzma.bak
2020-11-09T18:22:24.310Z,1604946144.310 [DataOverHttps](INFO): SBD MOMSN=55135
2020-11-09T18:22:33.347Z,1604946153.347 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20201109T162425/Express0050.lzma
2020-11-09T18:22:34.350Z,1604946154.350 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Express0050.lzma.bak
2020-11-09T18:22:34.350Z,1604946154.350 [DataOverHttps](INFO): SBD MOMSN=55138
2020-11-09T18:22:35.767Z,1604946155.767 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-11-09T18:22:35.767Z,1604946155.767 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-11-09T18:22:35.768Z,1604946155.768 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-11-09T18:25:33.131Z,1604946333.131 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-11-09T18:25:35.920Z,1604946335.920 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2020-11-09T18:25:37.125Z,1604946337.125 [NAL9602](INFO): SBD MO Status=0, MOMSN=11729, MT Status=0, MTMSN=0
2020-11-09T18:25:37.125Z,1604946337.125 [NAL9602](INFO): No messages in MT queue
2020-11-09T18:25:43.186Z,1604946343.186 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-11-09T18:25:48.043Z,1604946348.043 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude
2020-11-09T18:25:53.287Z,1604946353.287 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-11-09T18:26:07.826Z,1604946367.826 [NAL9602](INFO): Not Powering down - fast GPS
2020-11-09T18:27:36.342Z,1604946456.342 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](INFO): Done Waiting.
2020-11-09T18:27:36.342Z,1604946456.342 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2020-11-09T18:27:36.343Z,1604946456.343 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-11-09T18:27:36.343Z,1604946456.343 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Running Loop=1
2020-11-09T18:27:36.745Z,1604946456.745 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Stopped
2020-11-09T18:27:36.745Z,1604946456.745 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Running Loop=1
2020-11-09T18:27:37.175Z,1604946457.175 [DefaultWithUndock:SurfaceDefault:CheckIn:E](IMPORTANT): Default mission has been running for 119.538175 min 
2020-11-09T18:27:37.175Z,1604946457.175 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Stopped
2020-11-09T18:27:37.175Z,1604946457.175 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Completed DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:27:37.175Z,1604946457.175 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-11-09T18:27:37.184Z,1604946457.184 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:27:37.184Z,1604946457.184 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Running loop #17
2020-11-09T18:27:37.184Z,1604946457.184 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=17
2020-11-09T18:27:37.184Z,1604946457.184 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:27:37.184Z,1604946457.184 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-11-09T18:27:39.135Z,1604946459.135 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182738.00,A,4131.46352,N,07040.31239,W,0.039,350.76,091120,,,D*70
2020-11-09T18:27:39.141Z,1604946459.141 [NAL9602](INFO): GPS fix at 20201109T182738: (41.524392, -70.671873)
2020-11-09T18:27:39.214Z,1604946459.214 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-11-09T18:27:39.214Z,1604946459.214 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-11-09T18:27:42.655Z,1604946462.655 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20201109T162425/Courier0052.lzma
2020-11-09T18:27:43.658Z,1604946463.658 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Courier0052.lzma.bak
2020-11-09T18:27:43.658Z,1604946463.658 [DataOverHttps](INFO): SBD MOMSN=55142
2020-11-09T18:27:52.713Z,1604946472.713 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20201109T162425/Express0053.lzma
2020-11-09T18:27:53.709Z,1604946473.709 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Express0053.lzma.bak
2020-11-09T18:27:53.710Z,1604946473.710 [DataOverHttps](INFO): SBD MOMSN=55145
2020-11-09T18:27:55.144Z,1604946475.144 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-11-09T18:27:55.144Z,1604946475.144 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-11-09T18:27:55.144Z,1604946475.144 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-11-09T18:27:56.705Z,1604946476.705 [NAL9602](INFO): SBD MO Status=0, MOMSN=11730, MT Status=0, MTMSN=0
2020-11-09T18:27:56.705Z,1604946476.705 [NAL9602](INFO): No messages in MT queue
2020-11-09T18:28:27.402Z,1604946507.402 [NAL9602](INFO): Not Powering down - fast GPS
2020-11-09T18:29:32.850Z,1604946572.850 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CAREV,182923,COPR
$CAREV,182933,AUV,2.0.32731*19
 expected 79
2020-11-09T18:32:55.801Z,1604946775.801 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](INFO): Done Waiting.
2020-11-09T18:32:55.801Z,1604946775.801 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2020-11-09T18:32:55.801Z,1604946775.801 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-11-09T18:32:55.801Z,1604946775.801 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Running Loop=1
2020-11-09T18:32:56.215Z,1604946776.215 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Stopped
2020-11-09T18:32:56.215Z,1604946776.215 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Running Loop=1
2020-11-09T18:32:56.584Z,1604946776.584 [DefaultWithUndock:SurfaceDefault:CheckIn:E](IMPORTANT): Default mission has been running for 124.862679 min 
2020-11-09T18:32:56.585Z,1604946776.585 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Stopped
2020-11-09T18:32:56.585Z,1604946776.585 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Completed DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:32:56.585Z,1604946776.585 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-11-09T18:32:56.585Z,1604946776.585 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:32:56.585Z,1604946776.585 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Running loop #18
2020-11-09T18:32:56.585Z,1604946776.585 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=18
2020-11-09T18:32:56.585Z,1604946776.585 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:32:56.585Z,1604946776.585 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-11-09T18:32:58.592Z,1604946778.592 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183257.00,A,4131.36912,N,07040.39465,W,7.387,219.32,091120,,,D*7E
2020-11-09T18:32:58.594Z,1604946778.594 [NAL9602](INFO): GPS fix at 20201109T183257: (41.522819, -70.673244)
2020-11-09T18:32:58.620Z,1604946778.620 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-11-09T18:32:58.620Z,1604946778.620 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-11-09T18:33:03.023Z,1604946783.023 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20201109T162425/Courier0055.lzma
2020-11-09T18:33:04.026Z,1604946784.026 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Courier0055.lzma.bak
2020-11-09T18:33:04.026Z,1604946784.026 [DataOverHttps](INFO): SBD MOMSN=55149
2020-11-09T18:33:13.063Z,1604946793.063 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20201109T162425/Express0056.lzma
2020-11-09T18:33:14.066Z,1604946794.066 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Express0056.lzma.bak
2020-11-09T18:33:14.066Z,1604946794.066 [DataOverHttps](INFO): SBD MOMSN=55152
2020-11-09T18:33:15.178Z,1604946795.178 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-11-09T18:33:15.178Z,1604946795.178 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-11-09T18:33:15.178Z,1604946795.178 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-11-09T18:33:30.507Z,1604946810.507 [NAL9602](INFO): SBD MO Status=0, MOMSN=11731, MT Status=0, MTMSN=0
2020-11-09T18:33:30.507Z,1604946810.507 [NAL9602](INFO): No messages in MT queue
2020-11-09T18:34:01.210Z,1604946841.210 [NAL9602](INFO): Not Powering down - fast GPS
2020-11-09T18:38:15.801Z,1604947095.801 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](INFO): Done Waiting.
2020-11-09T18:38:15.801Z,1604947095.801 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2020-11-09T18:38:15.801Z,1604947095.801 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-11-09T18:38:15.801Z,1604947095.801 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Running Loop=1
2020-11-09T18:38:16.181Z,1604947096.181 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Stopped
2020-11-09T18:38:16.181Z,1604947096.181 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Running Loop=1
2020-11-09T18:38:16.583Z,1604947096.583 [DefaultWithUndock:SurfaceDefault:CheckIn:E](IMPORTANT): Default mission has been running for 130.195451 min 
2020-11-09T18:38:16.583Z,1604947096.583 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Stopped
2020-11-09T18:38:16.583Z,1604947096.583 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Completed DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:38:16.583Z,1604947096.583 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-11-09T18:38:16.583Z,1604947096.583 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:38:16.583Z,1604947096.583 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Running loop #19
2020-11-09T18:38:16.583Z,1604947096.583 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=19
2020-11-09T18:38:16.583Z,1604947096.583 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:38:16.583Z,1604947096.583 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-11-09T18:38:18.610Z,1604947098.610 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183817.00,A,4131.69748,N,07041.64056,W,24.629,335.66,091120,,,D*48
2020-11-09T18:38:18.616Z,1604947098.616 [NAL9602](INFO): GPS fix at 20201109T183817: (41.528291, -70.694009)
2020-11-09T18:38:18.630Z,1604947098.630 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-11-09T18:38:18.630Z,1604947098.630 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-11-09T18:38:22.319Z,1604947102.319 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20201109T162425/Courier0058.lzma
2020-11-09T18:38:23.322Z,1604947103.322 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Courier0058.lzma.bak
2020-11-09T18:38:23.322Z,1604947103.322 [DataOverHttps](INFO): SBD MOMSN=55156
2020-11-09T18:38:41.395Z,1604947121.395 [DataOverHttps](INFO): Sending 137 bytes from file Logs/20201109T162425/Express0059.lzma
2020-11-09T18:38:42.398Z,1604947122.398 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Express0059.lzma.bak
2020-11-09T18:38:42.398Z,1604947122.398 [DataOverHttps](INFO): SBD MOMSN=55159
2020-11-09T18:38:42.423Z,1604947122.423 [NAL9602](INFO): SBD MO Status=2, MOMSN=11732, MT Status=2, MTMSN=0
2020-11-09T18:38:42.423Z,1604947122.423 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-11-09T18:38:43.655Z,1604947123.655 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-11-09T18:38:43.655Z,1604947123.655 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-11-09T18:38:43.655Z,1604947123.655 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-11-09T18:38:59.391Z,1604947139.391 [NAL9602](INFO): SBD MO Status=0, MOMSN=11732, MT Status=0, MTMSN=0
2020-11-09T18:38:59.391Z,1604947139.391 [NAL9602](INFO): No messages in MT queue
2020-11-09T18:39:30.114Z,1604947170.114 [NAL9602](INFO): Not Powering down - fast GPS
2020-11-09T18:41:43.027Z,1604947303.027 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-11-09T18:43:44.283Z,1604947424.283 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](INFO): Done Waiting.
2020-11-09T18:43:44.283Z,1604947424.283 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2020-11-09T18:43:44.283Z,1604947424.283 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-11-09T18:43:44.283Z,1604947424.283 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Running Loop=1
2020-11-09T18:43:44.699Z,1604947424.699 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Stopped
2020-11-09T18:43:44.699Z,1604947424.699 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Running Loop=1
2020-11-09T18:43:45.135Z,1604947425.135 [DefaultWithUndock:SurfaceDefault:CheckIn:E](IMPORTANT): Default mission has been running for 135.670736 min 
2020-11-09T18:43:45.135Z,1604947425.135 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Stopped
2020-11-09T18:43:45.144Z,1604947425.144 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Completed DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:43:45.144Z,1604947425.144 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-11-09T18:43:45.144Z,1604947425.144 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:43:45.144Z,1604947425.144 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Running loop #20
2020-11-09T18:43:45.145Z,1604947425.145 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=20
2020-11-09T18:43:45.145Z,1604947425.145 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:43:45.145Z,1604947425.145 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-11-09T18:43:47.083Z,1604947427.083 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184346.00,A,4133.10387,N,07042.47296,W,16.600,321.62,091120,,,D*4C
2020-11-09T18:43:47.086Z,1604947427.086 [NAL9602](INFO): GPS fix at 20201109T184346: (41.551731, -70.707883)
2020-11-09T18:43:47.165Z,1604947427.165 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-11-09T18:43:47.165Z,1604947427.165 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-11-09T18:43:50.687Z,1604947430.687 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20201109T162425/Courier0061.lzma
2020-11-09T18:43:51.690Z,1604947431.690 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Courier0061.lzma.bak
2020-11-09T18:43:51.690Z,1604947431.690 [DataOverHttps](INFO): SBD MOMSN=55163
2020-11-09T18:44:02.747Z,1604947442.747 [DataOverHttps](INFO): Sending 137 bytes from file Logs/20201109T162425/Express0062.lzma
2020-11-09T18:44:03.742Z,1604947443.742 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Express0062.lzma.bak
2020-11-09T18:44:03.742Z,1604947443.742 [DataOverHttps](INFO): SBD MOMSN=55166
2020-11-09T18:44:04.784Z,1604947444.784 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-11-09T18:44:04.784Z,1604947444.784 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-11-09T18:44:04.784Z,1604947444.784 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-11-09T18:44:09.906Z,1604947449.906 [NAL9602](INFO): SBD MO Status=2, MOMSN=11733, MT Status=2, MTMSN=0
2020-11-09T18:44:09.906Z,1604947449.906 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-11-09T18:44:22.419Z,1604947462.419 [NAL9602](INFO): SBD MO Status=0, MOMSN=11733, MT Status=0, MTMSN=0
2020-11-09T18:44:22.419Z,1604947462.419 [NAL9602](INFO): No messages in MT queue
2020-11-09T18:44:44.241Z,1604947484.241 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-11-09T18:44:53.123Z,1604947493.123 [NAL9602](INFO): Not Powering down - fast GPS
2020-11-09T18:45:10.000Z,1604947510.000 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-11-09T18:45:10.001Z,1604947510.001 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.239597
2020-11-09T18:45:45.140Z,1604947545.140 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-11-09T18:46:20.304Z,1604947580.304 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-11-09T18:46:55.456Z,1604947615.456 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-11-09T18:47:30.596Z,1604947650.596 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-11-09T18:47:39.609Z,1604947659.609 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-11-09T18:47:39.611Z,1604947659.611 [BPC1](INFO): Received data from all battery sticks.
2020-11-09T18:47:40.648Z,1604947660.648 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003065
2020-11-09T18:49:05.254Z,1604947745.254 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](INFO): Done Waiting.
2020-11-09T18:49:05.254Z,1604947745.254 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2020-11-09T18:49:05.254Z,1604947745.254 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-11-09T18:49:05.254Z,1604947745.254 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Running Loop=1
2020-11-09T18:49:05.664Z,1604947745.664 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Stopped
2020-11-09T18:49:05.664Z,1604947745.664 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Running Loop=1
2020-11-09T18:49:06.091Z,1604947746.091 [DefaultWithUndock:SurfaceDefault:CheckIn:E](IMPORTANT): Default mission has been running for 141.020085 min 
2020-11-09T18:49:06.091Z,1604947746.091 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Stopped
2020-11-09T18:49:06.092Z,1604947746.092 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Completed DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:49:06.092Z,1604947746.092 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-11-09T18:49:06.092Z,1604947746.092 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:49:06.092Z,1604947746.092 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Running loop #21
2020-11-09T18:49:06.092Z,1604947746.092 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=21
2020-11-09T18:49:06.092Z,1604947746.092 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:49:06.092Z,1604947746.092 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-11-09T18:49:08.069Z,1604947748.069 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184907.00,A,4133.08309,N,07042.51581,W,3.577,306.93,091120,,,D*76
2020-11-09T18:49:08.075Z,1604947748.075 [NAL9602](INFO): GPS fix at 20201109T184907: (41.551385, -70.708597)
2020-11-09T18:49:08.139Z,1604947748.139 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-11-09T18:49:08.139Z,1604947748.139 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-11-09T18:49:15.059Z,1604947755.059 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.262180
2020-11-09T18:49:24.623Z,1604947764.623 [NAL9602](INFO): SBD MO Status=0, MOMSN=11734, MT Status=0, MTMSN=0
2020-11-09T18:49:24.624Z,1604947764.624 [NAL9602](INFO): No messages in MT queue
2020-11-09T18:49:40.160Z,1604947780.160 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003070
2020-11-09T18:49:43.531Z,1604947783.531 [NAL9602](INFO): SBD MO Status=1, MOMSN=11735, MT Status=0, MTMSN=0
2020-11-09T18:49:43.584Z,1604947783.584 [NAL9602](INFO): Sent 83 bytes from file Logs/20201109T162425/Courier0064.lzma
2020-11-09T18:49:43.584Z,1604947783.584 [NAL9602](INFO): Packets left to send: 0
2020-11-09T18:49:44.207Z,1604947784.207 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20201109T162425/Express0065.lzma
2020-11-09T18:49:45.182Z,1604947785.182 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Express0065.lzma.bak
2020-11-09T18:49:45.182Z,1604947785.182 [DataOverHttps](INFO): SBD MOMSN=55171
2020-11-09T18:49:46.359Z,1604947786.359 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-11-09T18:49:46.359Z,1604947786.359 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-11-09T18:49:46.364Z,1604947786.364 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-11-09T18:50:14.218Z,1604947814.218 [NAL9602](INFO): Not Powering down - fast GPS
2020-11-09T18:54:46.988Z,1604948086.988 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](INFO): Done Waiting.
2020-11-09T18:54:46.989Z,1604948086.989 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2020-11-09T18:54:46.989Z,1604948086.989 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-11-09T18:54:46.989Z,1604948086.989 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Running Loop=1
2020-11-09T18:54:47.358Z,1604948087.358 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Stopped
2020-11-09T18:54:47.358Z,1604948087.358 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Running Loop=1
2020-11-09T18:54:47.764Z,1604948087.764 [DefaultWithUndock:SurfaceDefault:CheckIn:E](IMPORTANT): Default mission has been running for 146.715055 min 
2020-11-09T18:54:47.764Z,1604948087.764 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Stopped
2020-11-09T18:54:47.764Z,1604948087.764 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Completed DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:54:47.764Z,1604948087.764 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-11-09T18:54:47.764Z,1604948087.764 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:54:47.765Z,1604948087.765 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Running loop #22
2020-11-09T18:54:47.765Z,1604948087.765 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=22
2020-11-09T18:54:47.765Z,1604948087.765 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:54:47.765Z,1604948087.765 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-11-09T18:54:49.778Z,1604948089.778 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185449.00,A,4133.14587,N,07042.50915,W,1.536,187.39,091120,,,A*74
2020-11-09T18:54:49.780Z,1604948089.780 [NAL9602](INFO): GPS fix at 20201109T185449: (41.552431, -70.708486)
2020-11-09T18:54:49.790Z,1604948089.790 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-11-09T18:54:49.790Z,1604948089.790 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-11-09T18:54:53.451Z,1604948093.451 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20201109T162425/Courier0067.lzma
2020-11-09T18:54:54.454Z,1604948094.454 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Courier0067.lzma.bak
2020-11-09T18:54:54.454Z,1604948094.454 [DataOverHttps](INFO): SBD MOMSN=55177
2020-11-09T18:55:03.491Z,1604948103.491 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20201109T162425/Express0068.lzma
2020-11-09T18:55:04.494Z,1604948104.494 [DataOverHttps](INFO): Moved sent file to Logs/20201109T162425/Express0068.lzma.bak
2020-11-09T18:55:04.494Z,1604948104.494 [DataOverHttps](INFO): SBD MOMSN=55180
2020-11-09T18:55:05.562Z,1604948105.562 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-11-09T18:55:05.562Z,1604948105.562 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-11-09T18:55:05.562Z,1604948105.562 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-11-09T18:55:07.143Z,1604948107.143 [NAL9602](INFO): SBD MO Status=2, MOMSN=11736, MT Status=2, MTMSN=0
2020-11-09T18:55:07.143Z,1604948107.143 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-11-09T18:55:36.223Z,1604948136.223 [NAL9602](INFO): SBD MO Status=0, MOMSN=11736, MT Status=0, MTMSN=0
2020-11-09T18:55:36.223Z,1604948136.223 [NAL9602](INFO): No messages in MT queue
2020-11-09T18:56:06.933Z,1604948166.933 [NAL9602](INFO): Not Powering down - fast GPS
2020-11-09T18:58:12.282Z,1604948292.282 [CommandLine](IMPORTANT): got command restart application
2020-11-09T18:58:13.285Z,1604948293.285 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2020-11-09T18:58:13.286Z,1604948293.286 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-11-09T18:58:13.464Z,1604948293.464 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2020-11-09T18:58:13.464Z,1604948293.464 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-11-09T18:58:13.465Z,1604948293.465 [CommandLine](INFO): Join timeout helper Thread ID is 1441
2020-11-09T18:58:13.465Z,1604948293.465 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2020-11-09T18:58:13.465Z,1604948293.465 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-11-09T18:58:13.466Z,1604948293.466 [NavChartDb](INFO): Join timeout helper Thread ID is 1442
2020-11-09T18:58:13.540Z,1604948293.540 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2020-11-09T18:58:13.540Z,1604948293.540 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-11-09T18:58:13.548Z,1604948293.548 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2020-11-09T18:58:13.548Z,1604948293.548 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-11-09T18:58:13.548Z,1604948293.548 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 1443
2020-11-09T18:58:13.572Z,1604948293.572 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2020-11-09T18:58:13.572Z,1604948293.572 [WetLabsSeaOWL_UV_A](INFO): Powering down
2020-11-09T18:58:13.573Z,1604948293.573 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-11-09T18:58:13.592Z,1604948293.592 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2020-11-09T18:58:13.592Z,1604948293.592 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-11-09T18:58:13.592Z,1604948293.592 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1444
2020-11-09T18:58:14.380Z,1604948294.380 [CTD_Seabird](INFO): Powering down
2020-11-09T18:58:14.392Z,1604948294.392 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2020-11-09T18:58:14.392Z,1604948294.392 [CTD_Seabird](INFO): Powering down
2020-11-09T18:58:14.404Z,1604948294.404 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-11-09T18:58:14.404Z,1604948294.404 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2020-11-09T18:58:14.404Z,1604948294.404 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-11-09T18:58:14.405Z,1604948294.405 [Radio_Surface](INFO): Join timeout helper Thread ID is 1445
2020-11-09T18:58:14.729Z,1604948294.729 [Radio_Surface](INFO): Powering down
2020-11-09T18:58:14.732Z,1604948294.732 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2020-11-09T18:58:14.733Z,1604948294.733 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-11-09T18:58:14.753Z,1604948294.753 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2020-11-09T18:58:14.753Z,1604948294.753 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-11-09T18:58:14.753Z,1604948294.753 [Onboard](INFO): Join timeout helper Thread ID is 1446
2020-11-09T18:58:15.285Z,1604948295.285 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2020-11-09T18:58:19.536Z,1604948299.536 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2020-11-09T18:58:19.536Z,1604948299.536 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-11-09T18:58:19.541Z,1604948299.541 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2020-11-09T18:58:19.541Z,1604948299.541 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-11-09T18:58:19.541Z,1604948299.541 [DataOverHttps](INFO): Join timeout helper Thread ID is 1447
2020-11-09T18:58:20.304Z,1604948300.304 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2020-11-09T18:58:20.304Z,1604948300.304 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-11-09T18:58:20.325Z,1604948300.325 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2020-11-09T18:58:20.325Z,1604948300.325 [logger ThreadHandler](INFO): Thread cancelled.
2020-11-09T18:58:20.325Z,1604948300.325 [logger](INFO): Join timeout helper Thread ID is 1448
2020-11-09T18:58:20.359Z,1604948300.359 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2020-11-09T18:58:20.359Z,1604948300.359 [logger ThreadHandler](INFO): Thread cancelled.
2020-11-09T18:58:20.361Z,1604948300.361 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2020-11-09T18:58:20.361Z,1604948300.361 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-11-09T18:58:20.361Z,1604948300.361 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2020-11-09T18:58:20.361Z,1604948300.361 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-11-09T18:58:20.361Z,1604948300.361 [controlThread](INFO): Join timeout helper Thread ID is 1449
2020-11-09T18:58:20.636Z,1604948300.636 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2020-11-09T18:58:20.636Z,1604948300.636 [controlThread](DEBUG): Uninitializing ControlThread
2020-11-09T18:58:20.636Z,1604948300.636 [AHRS_M2](INFO): Powering down
2020-11-09T18:58:20.709Z,1604948300.709 [DDM](INFO): Powering down
2020-11-09T18:58:20.780Z,1604948300.780 [DUSBL_Hydroid](INFO): Powering down
2020-11-09T18:58:20.852Z,1604948300.852 [Micromodem](INFO): Powering down
2020-11-09T18:58:20.949Z,1604948300.949 [NAL9602](INFO): Powering down
2020-11-09T18:58:21.020Z,1604948301.020 [RDI_Pathfinder](INFO): Powering down
2020-11-09T18:58:21.092Z,1604948301.092 [RDI_PathfinderUp](INFO): Powering down
2020-11-09T18:58:21.093Z,1604948301.093 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2020-11-09T18:58:21.094Z,1604948301.094 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2020-11-09T18:58:21.095Z,1604948301.095 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2020-11-09T18:58:21.095Z,1604948301.095 [MissionManager](INFO): Uninitializing Mission DefaultWithUndock
2020-11-09T18:58:21.095Z,1604948301.095 [DefaultWithUndock] Stopped
2020-11-09T18:58:21.095Z,1604948301.095 [DefaultWithUndock](DEBUG): Aggregate::uninitialize DefaultWithUndock
2020-11-09T18:58:21.096Z,1604948301.096 [DefaultWithUndock:SurfaceDefault] Stopped
2020-11-09T18:58:21.096Z,1604948301.096 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault
2020-11-09T18:58:21.096Z,1604948301.096 [DefaultWithUndock:SurfaceDefault:B.GoToSurface] Stopped
2020-11-09T18:58:21.096Z,1604948301.096 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-11-09T18:58:21.096Z,1604948301.096 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-11-09T18:58:21.096Z,1604948301.096 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T18:58:21.096Z,1604948301.096 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2020-11-09T18:58:21.096Z,1604948301.096 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-11-09T18:58:21.102Z,1604948301.102 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2020-11-09T18:58:21.102Z,1604948301.102 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2020-11-09T18:58:21.103Z,1604948301.103 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2020-11-09T18:58:21.103Z,1604948301.103 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2020-11-09T18:58:21.103Z,1604948301.103 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2020-11-09T18:58:21.103Z,1604948301.103 [BuoyancyServo](INFO): Powering down
2020-11-09T18:58:21.116Z,1604948301.116 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2020-11-09T18:58:21.116Z,1604948301.116 [ElevatorServo](INFO): Powering down
2020-11-09T18:58:21.117Z,1604948301.117 [MassServo](DEBUG): Uninitialize Mass Servo.
2020-11-09T18:58:21.117Z,1604948301.117 [MassServo](INFO): Powering down
2020-11-09T18:58:21.118Z,1604948301.118 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-11-09T18:58:21.118Z,1604948301.118 [RudderServo](INFO): Powering down
2020-11-09T18:58:21.118Z,1604948301.118 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2020-11-09T18:58:21.119Z,1604948301.119 [ThrusterServo](INFO): Powering down
2020-11-09T18:58:21.119Z,1604948301.119 [SBIT](DEBUG): Uninitialize SBIT Component.
2020-11-09T18:58:21.120Z,1604948301.120 [IBIT](DEBUG): Uninitialize IBIT Component.
2020-11-09T18:58:21.120Z,1604948301.120 [CBIT](DEBUG): Uninitialize CBIT Component.
2020-11-09T18:58:21.120Z,1604948301.120 [CBIT](DEBUG): Powering off loads.
2020-11-09T18:58:21.132Z,1604948301.132 [CBIT](DEBUG): Disabling WDT.
2020-11-09T18:58:21.144Z,1604948301.144 [CBIT](DEBUG): Opening all GF detection circuits.
2020-11-09T18:58:21.145Z,1604948301.145 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-11-09T18:58:21.200Z,1604948301.200 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-11-09T18:58:21.203Z,1604948301.203 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-11-09T18:58:21.212Z,1604948301.212 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-11-09T18:58:21.260Z,1604948301.260 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-11-09T18:58:21.263Z,1604948301.263 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-11-09T18:58:21.322Z,1604948301.322 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-11-09T18:58:21.391Z,1604948301.391 [logger ThreadHandler](INFO): Thread cancelled.