2018-09-19T21:17:48.410Z,1537391868.410 [Supervisor](DEBUG): Initializing supervisor.
2018-09-19T21:17:48.413Z,1537391868.413 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-09-19T21:17:48.414Z,1537391868.414 [SyncHandler](INFO): Protected caller Thread ID is 2617
2018-09-19T21:17:48.414Z,1537391868.414 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-09-19T21:17:48.415Z,1537391868.415 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-09-19T21:17:48.415Z,1537391868.415 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2618
2018-09-19T21:17:48.419Z,1537391868.419 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-09-19T21:17:48.431Z,1537391868.431 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-09-19T21:17:48.432Z,1537391868.432 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-09-19T21:17:48.433Z,1537391868.432 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2619
2018-09-19T21:17:48.433Z,1537391868.433 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-09-19T21:17:48.434Z,1537391868.434 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-09-19T21:17:48.435Z,1537391868.435 [logger ThreadHandler](INFO): Protected caller Thread ID is 2620
2018-09-19T21:17:48.437Z,1537391868.437 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-09-19T21:17:48.437Z,1537391868.437 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-09-19T21:17:48.439Z,1537391868.439 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-09-19T21:17:48.784Z,1537391868.784 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-09-19T21:17:48.784Z,1537391868.784 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-09-19T21:17:48.989Z,1537391868.989 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-09-19T21:17:48.990Z,1537391868.990 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-09-19T21:17:49.295Z,1537391869.295 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-09-19T21:17:49.296Z,1537391869.296 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-09-19T21:17:49.437Z,1537391869.437 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-09-19T21:17:49.438Z,1537391869.438 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-09-19T21:17:49.537Z,1537391869.537 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-09-19T21:17:49.537Z,1537391869.537 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-09-19T21:17:50.016Z,1537391870.016 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-09-19T21:17:50.017Z,1537391870.017 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-09-19T21:17:50.468Z,1537391870.468 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-09-19T21:17:50.469Z,1537391870.469 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-09-19T21:17:50.971Z,1537391870.971 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-09-19T21:17:50.972Z,1537391870.972 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-09-19T21:17:51.377Z,1537391871.377 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-09-19T21:17:51.378Z,1537391871.378 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-09-19T21:17:51.477Z,1537391871.477 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-09-19T21:17:51.478Z,1537391871.478 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-09-19T21:17:51.688Z,1537391871.688 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-09-19T21:17:51.688Z,1537391871.688 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-09-19T21:17:51.894Z,1537391871.894 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-09-19T21:17:51.894Z,1537391871.894 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-09-19T21:17:52.249Z,1537391872.249 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-09-19T21:17:52.250Z,1537391872.250 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-09-19T21:17:52.394Z,1537391872.394 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-09-19T21:17:52.395Z,1537391872.395 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-09-19T21:17:52.478Z,1537391872.478 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2018-09-19T21:17:52.479Z,1537391872.479 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2018-09-19T21:17:52.582Z,1537391872.582 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2018-09-19T21:17:52.704Z,1537391872.704 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2018-09-19T21:17:52.799Z,1537391872.799 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2018-09-19T21:17:52.885Z,1537391872.885 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2018-09-19T21:17:53.046Z,1537391873.046 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2018-09-19T21:17:53.226Z,1537391873.226 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2018-09-19T21:17:53.303Z,1537391873.303 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2018-09-19T21:17:53.535Z,1537391873.535 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-09-19T21:17:53.535Z,1537391873.535 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2018-09-19T21:17:53.619Z,1537391873.619 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2018-09-19T21:17:53.711Z,1537391873.711 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2018-09-19T21:17:53.814Z,1537391873.814 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2018-09-19T21:17:53.944Z,1537391873.944 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2018-09-19T21:17:53.945Z,1537391873.945 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-09-19T21:17:53.961Z,1537391873.961 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-09-19T21:17:54.199Z,1537391874.199 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-09-19T21:17:54.200Z,1537391874.200 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-09-19T21:17:54.242Z,1537391874.242 [DepthRateCalculator] Loaded
2018-09-19T21:17:54.243Z,1537391874.243 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-09-19T21:17:54.249Z,1537391874.249 [PitchRateCalculator] Loaded
2018-09-19T21:17:54.249Z,1537391874.249 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-09-19T21:17:54.265Z,1537391874.265 [SpeedCalculator] Loaded
2018-09-19T21:17:54.266Z,1537391874.266 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-09-19T21:17:54.287Z,1537391874.287 [TempGradientCalculator] Loaded
2018-09-19T21:17:54.287Z,1537391874.287 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-09-19T21:17:54.303Z,1537391874.303 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2018-09-19T21:17:54.303Z,1537391874.303 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2018-09-19T21:17:54.309Z,1537391874.309 [YawRateCalculator] Loaded
2018-09-19T21:17:54.309Z,1537391874.309 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-09-19T21:17:54.350Z,1537391874.350 [ElevatorOffsetCalculator] Loaded
2018-09-19T21:17:54.350Z,1537391874.350 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-09-19T21:17:54.350Z,1537391874.350 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-09-19T21:17:54.351Z,1537391874.351 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-09-19T21:17:54.415Z,1537391874.415 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-09-19T21:17:54.416Z,1537391874.416 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-09-19T21:17:54.530Z,1537391874.530 [BuoyancyServo] Loaded
2018-09-19T21:17:54.530Z,1537391874.530 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-09-19T21:17:54.531Z,1537391874.531 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-09-19T21:17:54.532Z,1537391874.532 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-09-19T21:17:54.545Z,1537391874.545 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-09-19T21:17:54.546Z,1537391874.546 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-09-19T21:17:54.645Z,1537391874.645 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-09-19T21:17:54.646Z,1537391874.646 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-09-19T21:17:54.945Z,1537391874.945 [DataOverHttps] Loaded
2018-09-19T21:17:54.945Z,1537391874.945 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-09-19T21:17:54.959Z,1537391874.959 [Depth_Keller] Loaded
2018-09-19T21:17:54.959Z,1537391874.959 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-09-19T21:17:54.964Z,1537391874.964 [DropWeight] Loaded
2018-09-19T21:17:54.964Z,1537391874.964 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-09-19T21:17:55.063Z,1537391875.063 [NAL9602] Loaded
2018-09-19T21:17:55.063Z,1537391875.063 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-09-19T21:17:55.080Z,1537391875.080 [Onboard] Loaded
2018-09-19T21:17:55.080Z,1537391875.080 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-09-19T21:17:55.090Z,1537391875.090 [Radio_Surface] Loaded
2018-09-19T21:17:55.091Z,1537391875.091 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-09-19T21:17:55.092Z,1537391875.092 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4088F4E0
2018-09-19T21:17:55.092Z,1537391875.092 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2702
2018-09-19T21:17:55.140Z,1537391875.140 [PNI_TCM] Loaded
2018-09-19T21:17:55.140Z,1537391875.140 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-09-19T21:17:55.164Z,1537391875.164 [BPC1](INFO): BPC1A: got serial number for stick 1: 0138
2018-09-19T21:17:55.165Z,1537391875.165 [BPC1](INFO): BPC1A: got serial number for stick 2: 0125
2018-09-19T21:17:55.166Z,1537391875.166 [BPC1](INFO): BPC1A: got serial number for stick 3: 00EF
2018-09-19T21:17:55.167Z,1537391875.167 [BPC1](INFO): BPC1A: got serial number for stick 4: 0158
2018-09-19T21:17:55.168Z,1537391875.168 [BPC1](INFO): BPC1A: got serial number for stick 5: 0088
2018-09-19T21:17:55.168Z,1537391875.168 [BPC1](INFO): BPC1A: got serial number for stick 6: 00A3
2018-09-19T21:17:55.169Z,1537391875.169 [BPC1](INFO): BPC1A: got serial number for stick 7: 012D
2018-09-19T21:17:55.170Z,1537391875.170 [BPC1](INFO): BPC1A: got serial number for stick 8: 00E7
2018-09-19T21:17:55.171Z,1537391875.171 [BPC1](INFO): BPC1A: got serial number for stick 9: 0100
2018-09-19T21:17:55.171Z,1537391875.171 [BPC1](INFO): BPC1A: got serial number for stick 10: 00B9
2018-09-19T21:17:55.172Z,1537391875.172 [BPC1](INFO): BPC1A: got serial number for stick 11: 008C
2018-09-19T21:17:55.173Z,1537391875.173 [BPC1](INFO): BPC1A: got serial number for stick 12: 0117
2018-09-19T21:17:55.174Z,1537391875.174 [BPC1](INFO): BPC1A: got serial number for stick 13: 00E4
2018-09-19T21:17:55.174Z,1537391875.174 [BPC1](INFO): BPC1A: got serial number for stick 14: 011D
2018-09-19T21:17:55.175Z,1537391875.175 [BPC1](INFO): BPC1A: got serial number for stick 15: 014E
2018-09-19T21:17:55.176Z,1537391875.176 [BPC1](INFO): BPC1A: got serial number for stick 16: 00EC
2018-09-19T21:17:55.177Z,1537391875.177 [BPC1](INFO): BPC1A: got serial number for stick 17: 008A
2018-09-19T21:17:55.177Z,1537391875.177 [BPC1](INFO): BPC1A: got serial number for stick 18: 0140
2018-09-19T21:17:55.178Z,1537391875.178 [BPC1](INFO): BPC1A: got serial number for stick 19: 00E5
2018-09-19T21:17:55.179Z,1537391875.179 [BPC1](INFO): BPC1A: got serial number for stick 20: 00E0
2018-09-19T21:17:55.180Z,1537391875.180 [BPC1](INFO): BPC1A: got serial number for stick 21: 00CD
2018-09-19T21:17:55.180Z,1537391875.180 [BPC1](INFO): BPC1A: got serial number for stick 22: 009F
2018-09-19T21:17:55.181Z,1537391875.181 [BPC1](INFO): BPC1A: got serial number for stick 23: 009C
2018-09-19T21:17:55.182Z,1537391875.182 [BPC1](INFO): BPC1A: got serial number for stick 24: 00A6
2018-09-19T21:17:55.182Z,1537391875.182 [BPC1](INFO): BPC1A: got serial number for stick 25: 00E8
2018-09-19T21:17:55.183Z,1537391875.183 [BPC1](INFO): BPC1A: got serial number for stick 26: 00D1
2018-09-19T21:17:55.184Z,1537391875.184 [BPC1](INFO): BPC1A: got serial number for stick 27: 00F3
2018-09-19T21:17:55.185Z,1537391875.185 [BPC1](INFO): BPC1A: got serial number for stick 28: 0092
2018-09-19T21:17:55.185Z,1537391875.185 [BPC1](INFO): BPC1A: got serial number for stick 29: 00AD
2018-09-19T21:17:55.186Z,1537391875.186 [BPC1](INFO): BPC1A: got serial number for stick 30: 00E9
2018-09-19T21:17:55.187Z,1537391875.187 [BPC1](INFO): BPC1A: got serial number for stick 31: 0126
2018-09-19T21:17:55.188Z,1537391875.188 [BPC1](INFO): BPC1B: got serial number for stick 32: 0157
2018-09-19T21:17:55.189Z,1537391875.189 [BPC1](INFO): BPC1B: got serial number for stick 33: 00F1
2018-09-19T21:17:55.190Z,1537391875.190 [BPC1](INFO): BPC1B: got serial number for stick 34: 00BF
2018-09-19T21:17:55.191Z,1537391875.191 [BPC1](INFO): BPC1B: got serial number for stick 35: 0089
2018-09-19T21:17:55.191Z,1537391875.191 [BPC1](INFO): BPC1B: got serial number for stick 36: 00C2
2018-09-19T21:17:55.192Z,1537391875.192 [BPC1](INFO): BPC1B: got serial number for stick 37: 00CA
2018-09-19T21:17:55.193Z,1537391875.193 [BPC1](INFO): BPC1B: got serial number for stick 38: 011A
2018-09-19T21:17:55.194Z,1537391875.194 [BPC1](INFO): BPC1B: got serial number for stick 39: 00FD
2018-09-19T21:17:55.194Z,1537391875.194 [BPC1](INFO): BPC1B: got serial number for stick 40: 0095
2018-09-19T21:17:55.195Z,1537391875.195 [BPC1](INFO): BPC1B: got serial number for stick 41: 00BE
2018-09-19T21:17:55.196Z,1537391875.196 [BPC1](INFO): BPC1B: got serial number for stick 42: 0086
2018-09-19T21:17:55.197Z,1537391875.197 [BPC1](INFO): BPC1B: got serial number for stick 43: 00AE
2018-09-19T21:17:55.197Z,1537391875.197 [BPC1](INFO): BPC1B: got serial number for stick 44: 00CB
2018-09-19T21:17:55.198Z,1537391875.198 [BPC1](INFO): BPC1B: got serial number for stick 45: 00F7
2018-09-19T21:17:55.199Z,1537391875.199 [BPC1](INFO): BPC1B: got serial number for stick 46: 00A1
2018-09-19T21:17:55.200Z,1537391875.200 [BPC1](INFO): BPC1B: got serial number for stick 47: 00F0
2018-09-19T21:17:55.200Z,1537391875.200 [BPC1](INFO): BPC1B: got serial number for stick 48: 00C9
2018-09-19T21:17:55.201Z,1537391875.201 [BPC1](INFO): BPC1B: got serial number for stick 49: 0103
2018-09-19T21:17:55.202Z,1537391875.202 [BPC1](INFO): BPC1B: got serial number for stick 50: 0152
2018-09-19T21:17:55.203Z,1537391875.203 [BPC1](INFO): BPC1B: got serial number for stick 51: 014A
2018-09-19T21:17:55.203Z,1537391875.203 [BPC1](INFO): BPC1B: got serial number for stick 52: 0114
2018-09-19T21:17:55.204Z,1537391875.204 [BPC1](INFO): BPC1B: got serial number for stick 53: 015E
2018-09-19T21:17:55.205Z,1537391875.205 [BPC1](INFO): BPC1B: got serial number for stick 54: 008E
2018-09-19T21:17:55.206Z,1537391875.206 [BPC1](INFO): BPC1B: got serial number for stick 55: 00AC
2018-09-19T21:17:55.206Z,1537391875.206 [BPC1](INFO): BPC1B: got serial number for stick 56: 0091
2018-09-19T21:17:55.207Z,1537391875.207 [BPC1](INFO): BPC1B: got serial number for stick 57: 0153
2018-09-19T21:17:55.208Z,1537391875.208 [BPC1](INFO): BPC1B: got serial number for stick 58: 00AF
2018-09-19T21:17:55.208Z,1537391875.208 [BPC1](INFO): BPC1B: got serial number for stick 59: 0151
2018-09-19T21:17:55.209Z,1537391875.209 [BPC1](INFO): BPC1B: got serial number for stick 60: 00DC
2018-09-19T21:17:55.210Z,1537391875.210 [BPC1](INFO): BPC1B: got serial number for stick 61: 00BA
2018-09-19T21:17:55.211Z,1537391875.211 [BPC1](INFO): BPC1B: got serial number for stick 62: 00DA
2018-09-19T21:17:57.452Z,1537391877.452 [BPC1] Loaded
2018-09-19T21:17:57.452Z,1537391877.452 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-09-19T21:17:57.452Z,1537391877.452 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-09-19T21:17:57.453Z,1537391877.453 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-09-19T21:17:57.582Z,1537391877.582 [SBIT](DEBUG): Construct Startup Built In Test.
2018-09-19T21:17:57.605Z,1537391877.605 [SBIT] Loaded
2018-09-19T21:17:57.605Z,1537391877.605 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-09-19T21:17:57.606Z,1537391877.606 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-09-19T21:17:57.618Z,1537391877.618 [IBIT] Loaded
2018-09-19T21:17:57.618Z,1537391877.618 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-09-19T21:17:57.621Z,1537391877.621 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-09-19T21:17:57.772Z,1537391877.772 [CBIT] Loaded
2018-09-19T21:17:57.772Z,1537391877.772 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-09-19T21:17:57.772Z,1537391877.772 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-09-19T21:17:57.773Z,1537391877.773 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-09-19T21:17:57.921Z,1537391877.921 [Aanderaa_O2] Loaded
2018-09-19T21:17:57.922Z,1537391877.922 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-09-19T21:17:57.000Z,1537391878.000 [CTD_NeilBrown] Loaded
2018-09-19T21:17:58.000Z,1537391878.000 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2018-09-19T21:17:58.001Z,1537391878.001 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 409534E0
2018-09-19T21:17:58.002Z,1537391878.002 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 2703
2018-09-19T21:17:58.053Z,1537391878.053 [CTD_Seabird] Loaded
2018-09-19T21:17:58.053Z,1537391878.053 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2018-09-19T21:17:58.054Z,1537391878.054 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409834E0
2018-09-19T21:17:58.055Z,1537391878.055 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 2704
2018-09-19T21:17:58.072Z,1537391878.072 [ESPComponent] Loaded
2018-09-19T21:17:58.072Z,1537391878.072 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2018-09-19T21:17:58.087Z,1537391878.087 [PAR_Licor] Loaded
2018-09-19T21:17:58.087Z,1537391878.087 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-09-19T21:17:58.136Z,1537391878.136 [WetLabsBB2FL] Loaded
2018-09-19T21:17:58.137Z,1537391878.137 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-09-19T21:17:58.138Z,1537391878.138 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409B34E0
2018-09-19T21:17:58.138Z,1537391878.138 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 2705
2018-09-19T21:17:58.139Z,1537391878.139 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-09-19T21:17:58.139Z,1537391878.139 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-09-19T21:17:58.208Z,1537391878.208 [VerticalControl](DEBUG): Construct VerticalControl.
2018-09-19T21:17:58.301Z,1537391878.301 [VerticalControl] Loaded
2018-09-19T21:17:58.301Z,1537391878.301 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-09-19T21:17:58.302Z,1537391878.302 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-09-19T21:17:58.363Z,1537391878.363 [HorizontalControl] Loaded
2018-09-19T21:17:58.363Z,1537391878.363 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-09-19T21:17:58.364Z,1537391878.364 [SpeedControl](DEBUG): Construct SpeedControl.
2018-09-19T21:17:58.369Z,1537391878.369 [SpeedControl] Loaded
2018-09-19T21:17:58.370Z,1537391878.370 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-09-19T21:17:58.370Z,1537391878.370 [LoopControl](DEBUG): Construct LoopControl.
2018-09-19T21:17:58.371Z,1537391878.371 [LoopControl] Loaded
2018-09-19T21:17:58.371Z,1537391878.371 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-09-19T21:17:58.371Z,1537391878.371 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-09-19T21:17:58.372Z,1537391878.372 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-09-19T21:17:58.396Z,1537391878.396 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-09-19T21:17:58.397Z,1537391878.397 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-09-19T21:17:58.488Z,1537391878.488 [DeadReckonUsingSpeedCalculator] Loaded
2018-09-19T21:17:58.488Z,1537391878.488 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-09-19T21:17:58.504Z,1537391878.504 [NavChart] Loaded
2018-09-19T21:17:58.505Z,1537391878.505 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-09-19T21:17:58.509Z,1537391878.509 [UniversalFixResidualReporter] Loaded
2018-09-19T21:17:58.509Z,1537391878.509 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-09-19T21:17:58.509Z,1537391878.509 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-09-19T21:17:58.513Z,1537391878.513 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-09-19T21:17:58.514Z,1537391878.514 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-09-19T21:17:58.521Z,1537391878.521 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-09-19T21:17:58.522Z,1537391878.522 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A3F4E0
2018-09-19T21:17:58.522Z,1537391878.522 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2706
2018-09-19T21:17:58.527Z,1537391878.527 [Supervisor](INFO): Main Thread ID is 9268
2018-09-19T21:17:58.527Z,1537391878.527 [Supervisor](DEBUG): Running supervisor.
2018-09-19T21:17:58.528Z,1537391878.528 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2707
2018-09-19T21:17:58.530Z,1537391878.530 [controlThread ThreadHandler](INFO): Handler Thread ID is 2708
2018-09-19T21:17:58.531Z,1537391878.531 [controlThread](DEBUG): Initializing ControlThread
2018-09-19T21:17:58.532Z,1537391878.532 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-09-19T21:17:58.532Z,1537391878.532 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-09-19T21:17:58.532Z,1537391878.532 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-09-19T21:17:58.533Z,1537391878.533 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-09-19T21:17:58.533Z,1537391878.533 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2018-09-19T21:17:58.534Z,1537391878.534 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-09-19T21:17:58.535Z,1537391878.535 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-09-19T21:17:58.539Z,1537391878.539 [SBIT](INFO): Initialize SBIT Component.
2018-09-19T21:17:58.540Z,1537391878.540 [SBIT](IMPORTANT): git: 2018-09-04-21-gd54d9fc
2018-09-19T21:17:58.540Z,1537391878.540 [SBIT](INFO): git hash: d54d9fc12f891c3a6b7eed365ed7708e78930892
2018-09-19T21:17:58.541Z,1537391878.541 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-09-19T21:17:58.542Z,1537391878.542 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
Kernel Reported: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-09-19T21:17:58.543Z,1537391878.543 [SBIT](INFO): Beginning SBIT in 160.000000 seconds.
2018-09-19T21:17:58.543Z,1537391878.543 [IBIT](INFO): Initialize IBIT Component.
2018-09-19T21:17:58.544Z,1537391878.544 [CBIT](DEBUG): Initialize CBIT Component.
2018-09-19T21:17:58.545Z,1537391878.545 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2018-09-19T21:17:58.546Z,1537391878.546 [logger ThreadHandler](INFO): Handler Thread ID is 2709
2018-09-19T21:17:58.565Z,1537391878.565 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2710
2018-09-19T21:17:58.571Z,1537391878.571 [Radio_Surface](INFO): Powering up
2018-09-19T21:17:58.577Z,1537391878.577 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 2711
2018-09-19T21:17:58.578Z,1537391878.578 [CTD_NeilBrown](INFO): Powering down
2018-09-19T21:17:58.609Z,1537391878.609 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 2712
2018-09-19T21:17:58.610Z,1537391878.610 [CTD_Seabird](INFO): Initializing
2018-09-19T21:17:58.610Z,1537391878.610 [CTD_Seabird](INFO): Checking LCM
2018-09-19T21:17:58.619Z,1537391878.619 [CTD_Seabird](INFO): LCM OK
2018-09-19T21:17:58.619Z,1537391878.619 [CTD_Seabird](INFO): Powering up
2018-09-19T21:17:58.625Z,1537391878.625 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 2713
2018-09-19T21:17:58.626Z,1537391878.626 [WetLabsBB2FL](INFO): Powering down
2018-09-19T21:17:58.657Z,1537391878.657 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-09-19T21:17:58.659Z,1537391878.659 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-09-19T21:17:58.659Z,1537391878.659 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-09-19T21:17:58.660Z,1537391878.660 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-09-19T21:17:58.660Z,1537391878.660 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-09-19T21:17:58.661Z,1537391878.661 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-09-19T21:17:58.661Z,1537391878.661 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-09-19T21:17:58.662Z,1537391878.662 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-09-19T21:17:58.662Z,1537391878.662 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-09-19T21:17:58.663Z,1537391878.663 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-09-19T21:17:58.673Z,1537391878.673 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2714
2018-09-19T21:17:58.676Z,1537391878.676 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-09-19T21:17:58.677Z,1537391878.677 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-09-19T21:17:58.677Z,1537391878.677 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-09-19T21:17:58.677Z,1537391878.677 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-09-19T21:17:58.677Z,1537391878.677 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-09-19T21:17:58.677Z,1537391878.677 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-09-19T21:17:58.678Z,1537391878.678 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-09-19T21:17:58.678Z,1537391878.678 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-09-19T21:17:58.678Z,1537391878.678 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-09-19T21:17:58.678Z,1537391878.678 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-09-19T21:17:58.678Z,1537391878.678 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-09-19T21:17:58.679Z,1537391878.679 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-09-19T21:17:58.679Z,1537391878.679 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-09-19T21:17:58.679Z,1537391878.679 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-09-19T21:17:58.679Z,1537391878.679 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-09-19T21:17:58.679Z,1537391878.679 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-09-19T21:17:58.721Z,1537391878.721 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-09-19T21:17:58.761Z,1537391878.761 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

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

    <Aggregate Id="StartupSatComms">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2018-09-19T21:17:58.761Z,1537391878.761 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-09-19T21:17:58.842Z,1537391878.842 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-09-19T21:17:58.843Z,1537391878.843 [Default:A.Wait](DEBUG): Construct Wait.
2018-09-19T21:17:58.861Z,1537391878.861 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-09-19T21:17:58.888Z,1537391878.888 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-09-19T21:17:58.890Z,1537391878.890 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-09-19T21:17:58.910Z,1537391878.910 [Default:E.Execute](DEBUG): Construct Execute.
2018-09-19T21:17:58.930Z,1537391878.930 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2018-09-19T21:17:58.935Z,1537391878.935 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,Aanderaa_O2,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-09-19T21:17:58.974Z,1537391878.974 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-09-19T21:17:59.017Z,1537391879.017 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2018-09-19T21:17:59.344Z,1537391879.344 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-09-19T21:17:59.457Z,1537391879.457 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-19T21:17:59.573Z,1537391879.573 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-09-19T21:17:59.581Z,1537391879.581 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-09-19T21:17:59.625Z,1537391879.625 [CommandLine](FAULT): Scheduling is paused
2018-09-19T21:17:59.626Z,1537391879.626 [CBIT](INFO): Critical error at 20180919T211758
2018-09-19T21:17:59.626Z,1537391879.626 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2018-09-19T21:17:59.819Z,1537391879.819 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2018-09-19T21:17:59.819Z,1537391879.819 [DropWeight] Hardware Fault, FailCount= 1
2018-09-19T21:17:59.819Z,1537391879.819 [DropWeight](ERROR): Hardware Fault
2018-09-19T21:17:59.885Z,1537391879.885 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-19T21:17:59.900Z,1537391879.900 [CBIT](INFO): Critical error at 20180919T211759
2018-09-19T21:17:59.903Z,1537391879.903 [CBIT](ERROR): Hardware Fault in component: DropWeight
2018-09-19T21:17:59.903Z,1537391879.903 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2018-09-19T21:18:00.133Z,1537391880.133 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-19T21:18:00.481Z,1537391880.481 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2018-09-19T21:18:00.481Z,1537391880.481 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2018-09-19T21:18:00.481Z,1537391880.481 [BuoyancyServo] Communications Fault, FailCount= 1
2018-09-19T21:18:00.481Z,1537391880.481 [BuoyancyServo](ERROR): Communications Fault
2018-09-19T21:18:00.483Z,1537391880.483 [CBIT](INFO): Critical error at 20180919T211759
2018-09-19T21:18:00.486Z,1537391880.486 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2018-09-19T21:18:00.550Z,1537391880.550 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-19T21:18:00.570Z,1537391880.570 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-09-19T21:18:00.571Z,1537391880.571 [BuoyancyServo](INFO): Powering down
2018-09-19T21:18:00.945Z,1537391880.945 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-19T21:18:01.337Z,1537391881.337 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-19T21:18:01.734Z,1537391881.734 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-19T21:18:02.172Z,1537391882.172 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-19T21:18:02.665Z,1537391882.665 [Aanderaa_O2](INFO): Powering down
2018-09-19T21:18:02.844Z,1537391882.844 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2018-09-19T21:18:02.844Z,1537391882.844 [BuoyancyServo] No Fault, FailCount= 1
2018-09-19T21:18:03.005Z,1537391883.005 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-09-19T21:18:03.129Z,1537391883.129 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-09-19T21:18:04.087Z,1537391884.087 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-09-19T21:18:04.208Z,1537391884.208 [CTD_Seabird](INFO): Started Seabird LCM interface with command:nohup ./lrauv-framework/onboard/bin/gpctd -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyC6 -b 9600 >& /dev/null &
2018-09-19T21:18:04.258Z,1537391884.258 [CTD_Seabird](INFO): LCM subscribed to channel:seabird_gpctd_t.seabird-gpctd
2018-09-19T21:18:04.653Z,1537391884.653 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-09-19T21:18:04.654Z,1537391884.654 [CTD_Seabird](INFO): Powering down
2018-09-19T21:18:25.298Z,1537391905.298 [NAL9602](INFO): Powering up NAL9602
2018-09-19T21:18:36.498Z,1537391916.498 [NAL9602](INFO): NAL9602 initialized
2018-09-19T21:19:00.156Z,1537391940.156 [BPC1](INFO): BPC1A: initialized.
2018-09-19T21:19:00.168Z,1537391940.168 [BPC1](INFO): BPC1B: initialized.
2018-09-19T21:19:01.737Z,1537391941.737 [BPC1](INFO): BPC1A: sending IBPS break.
2018-09-19T21:19:01.738Z,1537391941.738 [BPC1](INFO): BPC1B: sending IBPS break.
2018-09-19T21:19:05.752Z,1537391945.752 [BPC1](INFO): BPC1B: validating data format.
2018-09-19T21:19:05.770Z,1537391945.770 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-09-19T21:19:06.147Z,1537391946.147 [BPC1](INFO): BPC1A: validating data format.
2018-09-19T21:19:06.167Z,1537391946.167 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-09-19T21:19:06.167Z,1537391946.167 [BPC1](INFO): BPC1B valid message: 1824 bytes.
2018-09-19T21:19:06.176Z,1537391946.176 [BPC1](INFO): BPC1B: data parsed.
2018-09-19T21:19:06.532Z,1537391946.532 [BPC1](INFO): BPC1A valid message: 1824 bytes.
2018-09-19T21:19:06.565Z,1537391946.565 [BPC1](INFO): BPC1A: data parsed.
2018-09-19T21:19:06.952Z,1537391946.952 [BPC1](INFO): BPC1B: initialized.
2018-09-19T21:19:07.344Z,1537391947.344 [BPC1](INFO): BPC1A: initialized.
2018-09-19T21:19:14.530Z,1537391954.530 [BPC1](INFO): BPC1B: sending IBPS break.
2018-09-19T21:19:15.346Z,1537391955.346 [BPC1](INFO): BPC1A: sending IBPS break.
2018-09-19T21:19:19.333Z,1537391959.333 [BPC1](INFO): BPC1B: validating data format.
2018-09-19T21:19:19.411Z,1537391959.411 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-09-19T21:19:19.734Z,1537391959.734 [BPC1](INFO): BPC1B valid message: 1824 bytes.
2018-09-19T21:19:19.743Z,1537391959.743 [BPC1](INFO): BPC1B: data parsed.
2018-09-19T21:19:20.133Z,1537391960.133 [BPC1](INFO): BPC1A: validating data format.
2018-09-19T21:19:20.209Z,1537391960.209 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-09-19T21:19:20.545Z,1537391960.545 [BPC1](INFO): BPC1A valid message: 1824 bytes.
2018-09-19T21:19:20.554Z,1537391960.554 [BPC1](INFO): BPC1A: data parsed.
2018-09-19T21:19:20.584Z,1537391960.584 [BPC1](INFO): BPC1B: initialized.
2018-09-19T21:19:21.360Z,1537391961.360 [BPC1](INFO): BPC1A: initialized.
2018-09-19T21:19:28.530Z,1537391968.530 [BPC1](INFO): BPC1A: sending IBPS break.
2018-09-19T21:19:28.530Z,1537391968.530 [BPC1](INFO): BPC1B: sending IBPS break.
2018-09-19T21:19:32.931Z,1537391972.931 [BPC1](INFO): BPC1B: validating data format.
2018-09-19T21:19:33.012Z,1537391973.012 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-09-19T21:19:33.331Z,1537391973.331 [BPC1](INFO): BPC1A: validating data format.
2018-09-19T21:19:33.410Z,1537391973.410 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-09-19T21:19:33.410Z,1537391973.410 [BPC1](INFO): BPC1B valid message: 1824 bytes.
2018-09-19T21:19:33.418Z,1537391973.418 [BPC1](INFO): BPC1B: data parsed.
2018-09-19T21:19:33.730Z,1537391973.730 [BPC1](INFO): BPC1A valid message: 1824 bytes.
2018-09-19T21:19:33.746Z,1537391973.746 [BPC1](INFO): BPC1A: data parsed.
2018-09-19T21:19:34.160Z,1537391974.160 [BPC1](INFO): BPC1B: initialized.
2018-09-19T21:19:34.544Z,1537391974.544 [BPC1](INFO): BPC1A: initialized.
2018-09-19T21:19:41.353Z,1537391981.353 [BPC1](INFO): BPC1B: sending IBPS break.
2018-09-19T21:19:41.752Z,1537391981.752 [BPC1](INFO): BPC1A: sending IBPS break.
2018-09-19T21:19:45.730Z,1537391985.730 [BPC1](INFO): BPC1A: validating data format.
2018-09-19T21:19:45.813Z,1537391985.813 [BPC1](INFO): BPC1A: got 7 stick msg (1596 bytes) with SHORT_IBPS_MENU.
2018-09-19T21:19:45.813Z,1537391985.813 [BPC1](INFO): BPC1B: validating data format.
2018-09-19T21:19:45.884Z,1537391985.884 [BPC1](INFO): BPC1B: got 7 stick msg (1596 bytes) with SHORT_IBPS_MENU.
2018-09-19T21:19:46.129Z,1537391986.129 [BPC1](INFO): BPC1A valid message: 1596 bytes.
2018-09-19T21:19:46.137Z,1537391986.137 [BPC1](INFO): BPC1A: data parsed.
2018-09-19T21:19:46.137Z,1537391986.137 [BPC1](INFO): BPC1B valid message: 1596 bytes.
2018-09-19T21:19:46.144Z,1537391986.144 [BPC1](INFO): BPC1B: data parsed.
2018-09-19T21:19:46.146Z,1537391986.146 [BPC1](FAULT): Battery stick #1 (s/n: 0138) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0.
2018-09-19T21:19:46.147Z,1537391986.147 [BPC1](FAULT): Battery stick #8 (s/n: 00E7) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2018-09-19T21:19:46.147Z,1537391986.147 [BPC1](FAULT): Battery stick #14 (s/n: 011D) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0.
2018-09-19T21:19:46.148Z,1537391986.148 [BPC1](FAULT): Battery stick #15 (s/n: 014E) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0.
2018-09-19T21:19:46.149Z,1537391986.149 [BPC1](FAULT): Battery stick #18 (s/n: 0140) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AC0.
2018-09-19T21:19:46.150Z,1537391986.150 [BPC1](FAULT): Battery stick #21 (s/n: 00CD) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2018-09-19T21:19:46.151Z,1537391986.151 [BPC1](FAULT): Battery stick #22 (s/n: 009F) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2018-09-19T21:19:46.176Z,1537391986.176 [BPC1](FAULT): Battery stick #26 (s/n: 00D1) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2018-09-19T21:19:46.177Z,1537391986.177 [BPC1](FAULT): Battery stick #28 (s/n: 0092) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2018-09-19T21:19:46.178Z,1537391986.178 [BPC1](FAULT): Battery stick #30 (s/n: 00E9) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2018-09-19T21:19:46.179Z,1537391986.179 [BPC1](FAULT): Battery stick #32 (s/n: 0157) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2018-09-19T21:19:46.184Z,1537391986.184 [BPC1](FAULT): Battery stick #39 (s/n: 00FD) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2018-09-19T21:19:46.185Z,1537391986.185 [BPC1](FAULT): Battery stick #43 (s/n: 00AE) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AC0.
2018-09-19T21:19:46.186Z,1537391986.186 [BPC1](FAULT): Battery stick #44 (s/n: 00CB) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0.
2018-09-19T21:19:46.187Z,1537391986.187 [BPC1](FAULT): Battery stick #45 (s/n: 00F7) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AC0.
2018-09-19T21:19:46.188Z,1537391986.188 [BPC1](FAULT): Battery stick #46 (s/n: 00A1) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2018-09-19T21:19:46.193Z,1537391986.193 [BPC1](FAULT): Battery stick #50 (s/n: 0152) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AC7.
2018-09-19T21:19:46.194Z,1537391986.194 [BPC1](FAULT): Battery stick #51 (s/n: 014A) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AC0.
2018-09-19T21:19:46.195Z,1537391986.195 [BPC1](FAULT): Battery stick #53 (s/n: 015E) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0.
2018-09-19T21:19:46.196Z,1537391986.196 [BPC1](FAULT): Battery stick #56 (s/n: 0091) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2018-09-19T21:19:46.201Z,1537391986.201 [BPC1](FAULT): Battery stick #57 (s/n: 0153) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2018-09-19T21:19:46.202Z,1537391986.202 [BPC1](FAULT): Battery stick #62 (s/n: 00DA) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0.
2018-09-19T21:19:46.202Z,1537391986.202 [BPC1](INFO): Calculating totals. Valid battery stick count: 36. Valid reserve battery stick count: 4.
2018-09-19T21:20:13.311Z,1537392013.311 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004367
2018-09-19T21:20:38.970Z,1537392038.970 [SBIT](IMPORTANT): Beginning Startup BIT
2018-09-19T21:20:38.974Z,1537392038.974 [CBIT](IMPORTANT): Beginning ground fault scan
2018-09-19T21:20:49.787Z,1537392049.787 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.133767
CHAN A1 (24V): -0.004439
CHAN A2 (12V): -0.002236
CHAN A3 (5V): -0.001598
CHAN B0 (3.3V): -0.000234
CHAN B1 (3.15aV): -0.000076
CHAN B2 (3.15bV): 0.000283
CHAN B3 (GND): 0.000488
OPEN: -0.000261
Full Scale Calc: 4.765 mA, -1.589 mA
2018-09-19T21:20:52.160Z,1537392052.160 [SBIT](ERROR): Could not read elevatorAngleReader_.
2018-09-19T21:20:52.160Z,1537392052.160 [SBIT](ERROR): Could not read rudderAngleReader_.
2018-09-19T21:20:52.160Z,1537392052.160 [SBIT](ERROR): Could not read massPosReader_.
2018-09-19T21:20:58.956Z,1537392058.956 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-09-19T21:20:58.957Z,1537392058.957 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2018-09-19T21:20:58.957Z,1537392058.957 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-09-19T21:20:58.968Z,1537392058.968 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-09-19T21:20:59.406Z,1537392059.406 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-09-19T21:20:59.406Z,1537392059.406 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2018-09-19T21:20:59.769Z,1537392059.769 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-09-19T21:20:59.769Z,1537392059.769 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-09-19T21:20:59.770Z,1537392059.770 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-09-19T21:21:18.943Z,1537392078.943 [SBIT](ERROR): Could not read elevatorAngleReader_.
2018-09-19T21:21:18.943Z,1537392078.943 [SBIT](ERROR): Could not read rudderAngleReader_.
2018-09-19T21:21:18.943Z,1537392078.943 [SBIT](ERROR): Could not read massPosReader_.
2018-09-19T21:21:18.943Z,1537392078.943 [SBIT](FAULT): Control surface position failure.
2018-09-19T21:21:32.554Z,1537392092.554 [SBIT](ERROR): Could not read elevatorAngleReader_.
2018-09-19T21:21:32.554Z,1537392092.554 [SBIT](ERROR): Could not read rudderAngleReader_.
2018-09-19T21:21:32.554Z,1537392092.554 [SBIT](ERROR): Could not read massPosReader_.
2018-09-19T21:21:32.554Z,1537392092.554 [SBIT](FAULT): Control surface position failure.
2018-09-19T21:21:32.952Z,1537392092.952 [SBIT](CRITICAL): SBIT FAILED
2018-09-19T21:21:33.005Z,1537392093.005 [CBIT](INFO): Critical error at 20180919T212132
2018-09-19T21:21:33.045Z,1537392093.045 [CommandLine](IMPORTANT): got command configSet list
2018-09-19T21:21:33.046Z,1537392093.046 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-09-19T21:21:33.047Z,1537392093.047 [CommandLine](IMPORTANT): DAT.loadAtStartup=0 bool;

2018-09-19T21:21:33.047Z,1537392093.047 [CommandLine](IMPORTANT): ESPComponent.loadAtStartup=1 bool;

2018-09-19T21:21:33.047Z,1537392093.047 [CommandLine](IMPORTANT): ESPComponent.sampleTimeout=10 minute;

2018-09-19T21:21:33.047Z,1537392093.047 [CommandLine](IMPORTANT): ESPComponent.simulateHardware=1 bool;

2018-09-19T21:21:33.047Z,1537392093.047 [CommandLine](IMPORTANT): ElevatorServo.loadAtStartup=0 bool;

2018-09-19T21:21:33.047Z,1537392093.047 [CommandLine](IMPORTANT): Express none CTD_NeilBrown.bin_mean_sea_water_salinity;

2018-09-19T21:21:33.047Z,1537392093.047 [CommandLine](IMPORTANT): Express none CTD_NeilBrown.bin_mean_sea_water_temperature;

2018-09-19T21:21:33.047Z,1537392093.047 [CommandLine](IMPORTANT): Express none CTD_NeilBrown.bin_median_sea_water_temperature;

2018-09-19T21:21:33.048Z,1537392093.048 [CommandLine](IMPORTANT): Express none CTD_Seabird.bin_median_sea_water_salinity;

2018-09-19T21:21:33.048Z,1537392093.048 [CommandLine](IMPORTANT): Express none Rowe_600LCM.height_above_sea_floor;

2018-09-19T21:21:33.048Z,1537392093.048 [CommandLine](IMPORTANT): Express none VerticalTemperatureHomogeneityIndexCalculator.vertical_temperature_homogeneity_index;

2018-09-19T21:21:33.048Z,1537392093.048 [CommandLine](IMPORTANT): Express linearApproximation height_above_sea_floor 5.000000 meter;

2018-09-19T21:21:33.048Z,1537392093.048 [CommandLine](IMPORTANT): MassServo.loadAtStartup=0 bool;

2018-09-19T21:21:33.048Z,1537392093.048 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=0 bool;

2018-09-19T21:21:33.048Z,1537392093.048 [CommandLine](IMPORTANT): RudderServo.loadAtStartup=0 bool;

2018-09-19T21:21:33.049Z,1537392093.049 [CommandLine](IMPORTANT): StratificationFrontDetector.loadAtStartup=0 bool;

2018-09-19T21:21:33.049Z,1537392093.049 [CommandLine](IMPORTANT): ThrusterServo.loadAtStartup=0 bool;

2018-09-19T21:21:33.049Z,1537392093.049 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=497.852 cubic_centimeter;

2018-09-19T21:21:33.049Z,1537392093.049 [CommandLine](IMPORTANT): VerticalControl.massDefault=-35 millimeter;

2018-09-19T21:21:33.334Z,1537392093.334 [MissionManager](IMPORTANT): Started mission Startup
2018-09-19T21:21:33.334Z,1537392093.334 [Startup] Running Loop=1
2018-09-19T21:21:33.335Z,1537392093.335 [Startup](DEBUG): Aggregate::initialize Startup
2018-09-19T21:21:33.335Z,1537392093.335 [Startup:A.GoToSurface] Running Loop=1
2018-09-19T21:21:33.335Z,1537392093.335 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-09-19T21:21:33.335Z,1537392093.335 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-09-19T21:21:33.336Z,1537392093.336 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-09-19T21:21:33.337Z,1537392093.337 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-09-19T21:21:33.337Z,1537392093.337 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-09-19T21:21:33.337Z,1537392093.337 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-09-19T21:21:33.364Z,1537392093.364 [Startup:StartupSatComms] Running Loop=1
2018-09-19T21:21:33.369Z,1537392093.369 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-09-19T21:21:33.369Z,1537392093.369 [Startup:StartupSatComms:A] Running Loop=1
2018-09-19T21:21:33.741Z,1537392093.741 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-09-19T21:22:25.206Z,1537392145.206 [CommandLine](IMPORTANT): got command failComponent
2018-09-19T21:22:25.206Z,1537392145.206 [CommandLine](IMPORTANT): Failed components:
2018-09-19T21:22:25.207Z,1537392145.207 [CommandLine](IMPORTANT): DropWeight: Hardware Fault
2018-09-19T21:22:33.748Z,1537392153.748 [Startup:StartupSatComms:A](INFO): Timed out from 2018-09-19T21:21:33.4Z
2018-09-19T21:22:33.748Z,1537392153.748 [Startup:StartupSatComms:A] Stopped
2018-09-19T21:22:33.748Z,1537392153.748 [Startup:StartupSatComms:B] Running Loop=1
2018-09-19T21:22:34.154Z,1537392154.154 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-09-19T21:22:35.825Z,1537392155.825 [CommandLine](IMPORTANT): got command failComponent hardware BPC1
2018-09-19T21:22:35.826Z,1537392155.826 [BPC1] Hardware Fault, FailCount= 1
2018-09-19T21:22:35.826Z,1537392155.826 [BPC1](ERROR): Hardware Fault
2018-09-19T21:22:35.826Z,1537392155.826 [CommandLine](IMPORTANT): BPC1 failureMode is Hardware Fault
2018-09-19T21:22:38.120Z,1537392158.120 [CBIT](ERROR): Hardware Fault in component: BPC1
2018-09-19T21:22:43.047Z,1537392163.047 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180919T210149/Courier0007.lzma
2018-09-19T21:22:43.848Z,1537392163.848 [DataOverHttps](INFO): Moved sent file to Logs/20180919T210149/Courier0007.lzma.bak
2018-09-19T21:22:43.848Z,1537392163.848 [DataOverHttps](INFO): SBD MOMSN=8540319
2018-09-19T21:22:52.733Z,1537392172.733 [DataOverHttps](INFO): Sending 345 bytes from file Logs/20180919T211748/Courier0000.lzma
2018-09-19T21:22:53.495Z,1537392173.495 [DataOverHttps](INFO): Moved sent file to Logs/20180919T211748/Courier0000.lzma.bak
2018-09-19T21:22:53.496Z,1537392173.496 [DataOverHttps](INFO): SBD MOMSN=8540321
2018-09-19T21:23:02.379Z,1537392182.379 [DataOverHttps](INFO): Sending 78 bytes from file Logs/20180919T210149/Express0008.lzma
2018-09-19T21:23:03.167Z,1537392183.167 [DataOverHttps](INFO): Moved sent file to Logs/20180919T210149/Express0008.lzma.bak
2018-09-19T21:23:03.168Z,1537392183.168 [DataOverHttps](INFO): SBD MOMSN=8540328
2018-09-19T21:23:12.068Z,1537392192.068 [DataOverHttps](INFO): Sending 1346 bytes from file Logs/20180919T211748/Express0001.lzma
2018-09-19T21:23:12.852Z,1537392192.852 [DataOverHttps](INFO): Moved sent file to Logs/20180919T211748/Express0001.lzma.bak
2018-09-19T21:23:12.852Z,1537392192.852 [DataOverHttps](INFO): SBD MOMSN=8540331
2018-09-19T21:23:13.691Z,1537392193.691 [Startup:StartupSatComms:B] Stopped
2018-09-19T21:23:13.691Z,1537392193.691 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-09-19T21:23:13.691Z,1537392193.691 [Startup:StartupSatComms] Stopped
2018-09-19T21:23:13.691Z,1537392193.691 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-09-19T21:23:13.692Z,1537392193.692 [Startup](INFO): Completed Startup
2018-09-19T21:23:13.693Z,1537392193.693 [MissionManager](INFO): Startup is completed.
2018-09-19T21:23:13.693Z,1537392193.693 [MissionManager](INFO): Uninitializing Mission Startup
2018-09-19T21:23:13.693Z,1537392193.693 [Startup] Stopped
2018-09-19T21:23:13.693Z,1537392193.693 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-09-19T21:23:13.693Z,1537392193.693 [Startup:A.GoToSurface] Stopped
2018-09-19T21:23:13.693Z,1537392193.693 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-09-19T21:23:13.830Z,1537392193.830 [MissionManager](IMPORTANT): Started mission Default
2018-09-19T21:23:13.830Z,1537392193.830 [Default] Running Loop=1
2018-09-19T21:23:13.830Z,1537392193.830 [Default](DEBUG): Aggregate::initialize Default
2018-09-19T21:23:13.830Z,1537392193.830 [Default:B.GoToSurface] Running Loop=1
2018-09-19T21:23:13.831Z,1537392193.831 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-09-19T21:23:13.831Z,1537392193.831 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-09-19T21:23:13.831Z,1537392193.831 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-09-19T21:23:13.832Z,1537392193.832 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-09-19T21:23:13.832Z,1537392193.832 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-09-19T21:23:13.837Z,1537392193.837 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-09-19T21:23:13.837Z,1537392193.837 [Default:A.Wait] Running Loop=1
2018-09-19T21:23:13.837Z,1537392193.837 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-09-19T21:23:26.973Z,1537392206.973 [Default:A.Wait](INFO): Done Waiting.
2018-09-19T21:23:26.973Z,1537392206.973 [Default:A.Wait] Stopped
2018-09-19T21:23:26.973Z,1537392206.973 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-09-19T21:23:27.357Z,1537392207.357 [Default:CheckIn] Running Loop=1
2018-09-19T21:23:27.357Z,1537392207.357 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-09-19T21:23:27.357Z,1537392207.357 [Default:CheckIn:Read_GPS] Running Loop=1
2018-09-19T21:23:27.826Z,1537392207.826 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-09-19T21:23:39.302Z,1537392219.302 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-09-19T21:24:00.162Z,1537392240.162 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-09-19T21:24:00.162Z,1537392240.162 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2018-09-19T21:24:00.162Z,1537392240.162 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-09-19T21:24:00.176Z,1537392240.176 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-09-19T21:24:00.571Z,1537392240.571 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-09-19T21:24:00.571Z,1537392240.571 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2018-09-19T21:24:00.962Z,1537392240.962 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-09-19T21:24:00.962Z,1537392240.962 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-09-19T21:24:00.962Z,1537392240.962 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-09-19T21:27:01.091Z,1537392421.091 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-09-19T21:27:01.091Z,1537392421.091 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3
2018-09-19T21:27:01.091Z,1537392421.091 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-09-19T21:27:01.102Z,1537392421.102 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-09-19T21:27:01.504Z,1537392421.504 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-09-19T21:27:01.504Z,1537392421.504 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3
2018-09-19T21:27:01.893Z,1537392421.893 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-09-19T21:27:01.894Z,1537392421.894 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-09-19T21:27:01.894Z,1537392421.894 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-09-19T21:28:27.445Z,1537392507.445 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-09-19T21:23:27.4Z
2018-09-19T21:28:27.445Z,1537392507.445 [Default:CheckIn:Read_GPS] Stopped
2018-09-19T21:28:27.445Z,1537392507.445 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-09-19T21:28:27.901Z,1537392507.901 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-09-19T21:28:32.035Z,1537392512.035 [CommandLine](IMPORTANT): got command configSet BPC1.batterySamplingInterval 1.000000 minute persist
2018-09-19T21:28:37.462Z,1537392517.462 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180919T211748/Courier0004.lzma
2018-09-19T21:28:37.470Z,1537392517.470 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-09-19T21:28:37.470Z,1537392517.470 [NAL9602] Data Fault, FailCount= 1
2018-09-19T21:28:37.470Z,1537392517.470 [NAL9602](ERROR): Data Fault
2018-09-19T21:28:37.566Z,1537392517.566 [CBIT](ERROR): Data Fault in component: NAL9602
2018-09-19T21:28:37.862Z,1537392517.862 [NAL9602](INFO): Powering down
2018-09-19T21:28:38.742Z,1537392518.742 [CBIT](INFO): Clearing failed state for component NAL9602
2018-09-19T21:28:38.742Z,1537392518.742 [NAL9602] No Fault, FailCount= 1
2018-09-19T21:28:40.659Z,1537392520.659 [DataOverHttps](INFO): Moved sent file to Logs/20180919T211748/Courier0004.lzma.bak
2018-09-19T21:28:40.660Z,1537392520.660 [DataOverHttps](INFO): SBD MOMSN=8540423
2018-09-19T21:28:50.298Z,1537392530.298 [DataOverHttps](INFO): Sending 241 bytes from file Logs/20180919T211748/Express0005.lzma
2018-09-19T21:28:51.495Z,1537392531.495 [DataOverHttps](INFO): Moved sent file to Logs/20180919T211748/Express0005.lzma.bak
2018-09-19T21:28:51.496Z,1537392531.496 [DataOverHttps](INFO): SBD MOMSN=8540446
2018-09-19T21:28:52.340Z,1537392532.340 [Default:CheckIn:Read_Iridium] Stopped
2018-09-19T21:28:52.340Z,1537392532.340 [Default:CheckIn:C.Wait] Running Loop=1
2018-09-19T21:28:52.340Z,1537392532.340 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-09-19T21:29:07.950Z,1537392547.950 [NAL9602](INFO): Powering up NAL9602
2018-09-19T21:29:19.150Z,1537392559.150 [NAL9602](INFO): NAL9602 initialized
2018-09-19T21:29:47.216Z,1537392587.216 [CBIT](INFO): Clearing failed state for component BPC1
2018-09-19T21:29:47.216Z,1537392587.216 [BPC1] No Fault, FailCount= 1
2018-09-19T21:30:01.990Z,1537392601.990 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-09-19T21:30:01.990Z,1537392601.990 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 4
2018-09-19T21:30:01.990Z,1537392601.990 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-09-19T21:30:02.002Z,1537392602.002 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-09-19T21:30:02.404Z,1537392602.404 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-09-19T21:30:02.405Z,1537392602.405 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 4
2018-09-19T21:30:02.792Z,1537392602.792 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-09-19T21:30:02.793Z,1537392602.793 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-09-19T21:30:02.793Z,1537392602.793 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-09-19T21:30:48.809Z,1537392648.809 [BPC1](INFO): BPC1A: initialized.
2018-09-19T21:30:48.821Z,1537392648.821 [BPC1](INFO): BPC1B: initialized.
2018-09-19T21:30:49.979Z,1537392649.979 [BPC1](INFO): BPC1A: sending IBPS break.
2018-09-19T21:30:50.381Z,1537392650.381 [BPC1](INFO): BPC1B: sending IBPS break.
2018-09-19T21:30:56.298Z,1537392656.298 [BPC1](INFO): BPC1A: validating data format.
2018-09-19T21:30:56.337Z,1537392656.337 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-09-19T21:30:56.337Z,1537392656.337 [BPC1](INFO): BPC1B: validating data format.
2018-09-19T21:30:56.355Z,1537392656.355 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-09-19T21:30:56.489Z,1537392656.489 [BPC1](INFO): BPC1A valid message: 1824 bytes.
2018-09-19T21:30:56.497Z,1537392656.497 [BPC1](INFO): BPC1A: data parsed.
2018-09-19T21:30:56.498Z,1537392656.498 [BPC1](INFO): BPC1B valid message: 1824 bytes.
2018-09-19T21:30:56.506Z,1537392656.506 [BPC1](INFO): BPC1B: data parsed.
2018-09-19T21:30:57.273Z,1537392657.273 [BPC1](INFO): BPC1A: initialized.
2018-09-19T21:30:57.285Z,1537392657.285 [BPC1](INFO): BPC1B: initialized.
2018-09-19T21:31:04.457Z,1537392664.457 [BPC1](INFO): BPC1A: sending IBPS break.
2018-09-19T21:31:04.852Z,1537392664.852 [BPC1](INFO): BPC1B: sending IBPS break.
2018-09-19T21:31:09.262Z,1537392669.262 [BPC1](INFO): BPC1A: validating data format.
2018-09-19T21:31:09.337Z,1537392669.337 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-09-19T21:31:09.668Z,1537392669.668 [BPC1](INFO): BPC1A valid message: 1824 bytes.
2018-09-19T21:31:09.676Z,1537392669.676 [BPC1](INFO): BPC1A: data parsed.
2018-09-19T21:31:09.677Z,1537392669.677 [BPC1](INFO): BPC1B: validating data format.
2018-09-19T21:31:09.784Z,1537392669.784 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-09-19T21:31:10.069Z,1537392670.069 [BPC1](INFO): BPC1B valid message: 1824 bytes.
2018-09-19T21:31:10.085Z,1537392670.085 [BPC1](INFO): BPC1B: data parsed.
2018-09-19T21:31:10.457Z,1537392670.457 [BPC1](INFO): BPC1A: initialized.
2018-09-19T21:31:10.860Z,1537392670.860 [BPC1](INFO): BPC1B: initialized.
2018-09-19T21:31:18.062Z,1537392678.062 [BPC1](INFO): BPC1A: sending IBPS break.
2018-09-19T21:31:18.440Z,1537392678.440 [BPC1](INFO): BPC1B: sending IBPS break.
2018-09-19T21:31:22.847Z,1537392682.847 [BPC1](INFO): BPC1A: validating data format.
2018-09-19T21:31:22.928Z,1537392682.928 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-09-19T21:31:23.254Z,1537392683.254 [BPC1](INFO): BPC1A valid message: 1824 bytes.
2018-09-19T21:31:23.262Z,1537392683.262 [BPC1](INFO): BPC1A: data parsed.
2018-09-19T21:31:23.263Z,1537392683.263 [BPC1](INFO): BPC1B: validating data format.
2018-09-19T21:31:23.384Z,1537392683.384 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-09-19T21:31:23.673Z,1537392683.673 [BPC1](INFO): BPC1B valid message: 1824 bytes.
2018-09-19T21:31:23.681Z,1537392683.681 [BPC1](INFO): BPC1B: data parsed.
2018-09-19T21:31:24.076Z,1537392684.076 [BPC1](INFO): BPC1A: initialized.
2018-09-19T21:31:24.464Z,1537392684.464 [BPC1](INFO): BPC1B: initialized.
2018-09-19T21:31:31.666Z,1537392691.666 [BPC1](INFO): BPC1A: sending IBPS break.
2018-09-19T21:31:31.666Z,1537392691.666 [BPC1](INFO): BPC1B: sending IBPS break.
2018-09-19T21:31:35.658Z,1537392695.658 [BPC1](INFO): BPC1A: validating data format.
2018-09-19T21:31:35.734Z,1537392695.734 [BPC1](INFO): BPC1A: got 7 stick msg (1596 bytes) with SHORT_IBPS_MENU.
2018-09-19T21:31:35.734Z,1537392695.734 [BPC1](INFO): BPC1B: validating data format.
2018-09-19T21:31:35.809Z,1537392695.809 [BPC1](INFO): BPC1B: got 7 stick msg (1596 bytes) with SHORT_IBPS_MENU.
2018-09-19T21:31:36.057Z,1537392696.057 [BPC1](INFO): BPC1A valid message: 1596 bytes.
2018-09-19T21:31:36.064Z,1537392696.064 [BPC1](INFO): BPC1A: data parsed.
2018-09-19T21:31:36.065Z,1537392696.065 [BPC1](INFO): BPC1B valid message: 1596 bytes.
2018-09-19T21:31:36.071Z,1537392696.071 [BPC1](INFO): BPC1B: data parsed.
2018-09-19T21:31:36.097Z,1537392696.097 [BPC1](INFO): Calculating totals. Valid battery stick count: 36. Valid reserve battery stick count: 4.
2018-09-19T21:33:00.041Z,1537392780.041 [CBIT](INFO): Clearing failed state for component DropWeight
2018-09-19T21:33:00.042Z,1537392780.042 [DropWeight] No Fault, FailCount= 1
2018-09-19T21:33:02.837Z,1537392782.837 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-09-19T21:33:02.837Z,1537392782.837 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 5
2018-09-19T21:33:02.837Z,1537392782.837 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-09-19T21:33:02.849Z,1537392782.849 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-09-19T21:33:03.258Z,1537392783.258 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-09-19T21:33:03.258Z,1537392783.258 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 5
2018-09-19T21:33:03.643Z,1537392783.643 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-09-19T21:33:03.644Z,1537392783.644 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-09-19T21:33:03.644Z,1537392783.644 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-09-19T21:33:52.849Z,1537392832.849 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-09-19T21:33:52.849Z,1537392832.849 [Default:CheckIn:C.Wait] Stopped
2018-09-19T21:33:52.849Z,1537392832.849 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-09-19T21:33:52.849Z,1537392832.849 [Default:CheckIn:D] Running Loop=1
2018-09-19T21:33:53.266Z,1537392833.266 [Default:CheckIn:D] Stopped
2018-09-19T21:33:53.266Z,1537392833.266 [Default:CheckIn:E] Running Loop=1
2018-09-19T21:33:53.644Z,1537392833.644 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.657088 min 
2018-09-19T21:33:53.646Z,1537392833.646 [Default:CheckIn:E] Stopped
2018-09-19T21:33:53.646Z,1537392833.646 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-09-19T21:33:53.646Z,1537392833.646 [Default:CheckIn] Stopped
2018-09-19T21:33:53.646Z,1537392833.646 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-09-19T21:33:53.647Z,1537392833.647 [Default:CheckIn](INFO): Running loop #2
2018-09-19T21:33:53.647Z,1537392833.647 [Default:CheckIn] Running Loop=2
2018-09-19T21:33:53.647Z,1537392833.647 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-09-19T21:33:53.647Z,1537392833.647 [Default:CheckIn:Read_GPS] Running Loop=1
2018-09-19T21:35:43.910Z,1537392943.910 [CommandLine](IMPORTANT): got command get BPC1.batterySamplingInterval
2018-09-19T21:35:43.911Z,1537392943.911 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval 0.016667 h
2018-09-19T21:36:04.020Z,1537392964.020 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-09-19T21:36:04.020Z,1537392964.020 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 6
2018-09-19T21:36:04.020Z,1537392964.020 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-09-19T21:36:04.031Z,1537392964.031 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-09-19T21:36:04.438Z,1537392964.438 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-09-19T21:36:04.438Z,1537392964.438 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 6
2018-09-19T21:36:04.795Z,1537392964.795 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-09-19T21:36:04.796Z,1537392964.796 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-09-19T21:36:04.796Z,1537392964.796 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-09-19T21:36:08.829Z,1537392968.829 [CommandLine](IMPORTANT): got command failComponent
2018-09-19T21:36:08.829Z,1537392968.829 [CommandLine](IMPORTANT): Failed components:
2018-09-19T21:36:08.830Z,1537392968.830 [CommandLine](IMPORTANT): No failed Components.
2018-09-19T21:38:54.023Z,1537393134.023 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-09-19T21:33:53.6Z
2018-09-19T21:38:54.023Z,1537393134.023 [Default:CheckIn:Read_GPS] Stopped
2018-09-19T21:38:54.023Z,1537393134.023 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-09-19T21:38:58.350Z,1537393138.350 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20180919T211748/Courier0007.lzma
2018-09-19T21:38:59.152Z,1537393139.152 [DataOverHttps](INFO): Moved sent file to Logs/20180919T211748/Courier0007.lzma.bak
2018-09-19T21:38:59.152Z,1537393139.152 [DataOverHttps](INFO): SBD MOMSN=8540499
2018-09-19T21:39:04.920Z,1537393144.920 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-09-19T21:39:04.920Z,1537393144.920 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 7
2018-09-19T21:39:04.920Z,1537393144.920 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-09-19T21:39:04.969Z,1537393144.969 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-09-19T21:39:08.059Z,1537393148.059 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-09-19T21:39:08.059Z,1537393148.059 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 7
2018-09-19T21:39:08.083Z,1537393148.083 [DataOverHttps](INFO): Sending 302 bytes from file Logs/20180919T211748/Express0008.lzma
2018-09-19T21:39:08.205Z,1537393148.205 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-09-19T21:39:08.205Z,1537393148.205 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-09-19T21:39:08.206Z,1537393148.206 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-09-19T21:39:08.884Z,1537393148.884 [DataOverHttps](INFO): Moved sent file to Logs/20180919T211748/Express0008.lzma.bak
2018-09-19T21:39:08.884Z,1537393148.884 [DataOverHttps](INFO): SBD MOMSN=8540501
2018-09-19T21:39:09.725Z,1537393149.725 [Default:CheckIn:Read_Iridium] Stopped
2018-09-19T21:39:09.725Z,1537393149.725 [Default:CheckIn:C.Wait] Running Loop=1
2018-09-19T21:39:09.725Z,1537393149.725 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-09-19T21:39:21.351Z,1537393161.351 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-09-19T21:39:21.351Z,1537393161.351 [NAL9602] Data Fault, FailCount= 2
2018-09-19T21:39:21.351Z,1537393161.351 [NAL9602](ERROR): Data Fault
2018-09-19T21:39:21.439Z,1537393161.439 [CBIT](ERROR): Data Fault in component: NAL9602
2018-09-19T21:39:21.751Z,1537393161.751 [NAL9602](INFO): Powering down
2018-09-19T21:39:22.756Z,1537393162.756 [CBIT](INFO): Clearing failed state for component NAL9602
2018-09-19T21:39:22.756Z,1537393162.756 [NAL9602] No Fault, FailCount= 2
2018-09-19T21:39:52.151Z,1537393192.151 [NAL9602](INFO): Powering up NAL9602
2018-09-19T21:40:02.950Z,1537393202.950 [NAL9602](INFO): NAL9602 initialized
2018-09-19T21:40:20.466Z,1537393220.466 [CommandLine](IMPORTANT): got command failComponent
2018-09-19T21:40:20.466Z,1537393220.466 [CommandLine](IMPORTANT): Failed components:
2018-09-19T21:40:20.466Z,1537393220.466 [CommandLine](IMPORTANT): No failed Components.
2018-09-19T21:41:34.178Z,1537393294.178 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.389691 seconds old.
2018-09-19T21:41:34.590Z,1537393294.590 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.801800 seconds old.
2018-09-19T21:41:34.984Z,1537393294.984 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.195592 seconds old.
2018-09-19T21:41:35.385Z,1537393295.385 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.596831 seconds old.
2018-09-19T21:41:35.781Z,1537393295.781 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.993043 seconds old.
2018-09-19T21:41:36.178Z,1537393296.178 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 2.389339 seconds old.
2018-09-19T21:41:36.579Z,1537393296.579 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 2.790237 seconds old.
2018-09-19T21:41:36.984Z,1537393296.984 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 3.195328 seconds old.
2018-09-19T21:41:37.418Z,1537393297.418 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 3.629300 seconds old.
2018-09-19T21:41:37.790Z,1537393297.790 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 4.001797 seconds old.
2018-09-19T21:41:38.184Z,1537393298.184 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 4.395344 seconds old.
2018-09-19T21:41:38.587Z,1537393298.587 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 4.798609 seconds old.
2018-09-19T21:41:38.980Z,1537393298.980 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 5.191299 seconds old.
2018-09-19T21:41:39.381Z,1537393299.381 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 5.591944 seconds old.
2018-09-19T21:41:39.779Z,1537393299.779 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 5.990975 seconds old.
2018-09-19T21:41:40.190Z,1537393300.190 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 6.401730 seconds old.
2018-09-19T21:42:04.585Z,1537393324.585 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.379050 seconds old.
2018-09-19T21:42:05.003Z,1537393325.003 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.797170 seconds old.
2018-09-19T21:42:05.388Z,1537393325.388 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.182510 seconds old.
2018-09-19T21:42:05.781Z,1537393325.781 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.574857 seconds old.
2018-09-19T21:42:06.178Z,1537393326.178 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.972081 seconds old.
2018-09-19T21:42:06.590Z,1537393326.590 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 2.384647 seconds old.
2018-09-19T21:42:06.976Z,1537393326.976 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 2.770598 seconds old.
2018-09-19T21:42:07.382Z,1537393327.382 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 3.176386 seconds old.
2018-09-19T21:42:08.595Z,1537393328.595 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-09-19T21:42:08.595Z,1537393328.595 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 8
2018-09-19T21:42:08.595Z,1537393328.595 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-09-19T21:42:08.642Z,1537393328.642 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-09-19T21:42:08.997Z,1537393328.997 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-09-19T21:42:08.998Z,1537393328.998 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 8
2018-09-19T21:42:09.382Z,1537393329.382 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-09-19T21:42:09.383Z,1537393329.383 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-09-19T21:42:09.383Z,1537393329.383 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-09-19T21:42:38.592Z,1537393358.592 [BPC1](INFO): BPC1A: initialized.
2018-09-19T21:42:38.604Z,1537393358.604 [BPC1](INFO): BPC1B: initialized.
2018-09-19T21:42:40.191Z,1537393360.191 [BPC1](INFO): BPC1A: sending IBPS break.
2018-09-19T21:42:40.191Z,1537393360.191 [BPC1](INFO): BPC1B: sending IBPS break.
2018-09-19T21:42:44.585Z,1537393364.585 [BPC1](INFO): BPC1A: validating data format.
2018-09-19T21:42:44.613Z,1537393364.613 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-09-19T21:42:44.613Z,1537393364.613 [BPC1](INFO): BPC1B: validating data format.
2018-09-19T21:42:44.630Z,1537393364.630 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-09-19T21:42:44.979Z,1537393364.979 [BPC1](INFO): BPC1A valid message: 1824 bytes.
2018-09-19T21:42:44.987Z,1537393364.987 [BPC1](INFO): BPC1A: data parsed.
2018-09-19T21:42:44.987Z,1537393364.987 [BPC1](INFO): BPC1B valid message: 1824 bytes.
2018-09-19T21:42:44.995Z,1537393364.995 [BPC1](INFO): BPC1B: data parsed.
2018-09-19T21:42:45.796Z,1537393365.796 [BPC1](INFO): BPC1A: initialized.
2018-09-19T21:42:45.815Z,1537393365.815 [BPC1](INFO): BPC1B: initialized.
2018-09-19T21:42:52.976Z,1537393372.976 [BPC1](INFO): BPC1A: sending IBPS break.
2018-09-19T21:42:53.381Z,1537393373.381 [BPC1](INFO): BPC1B: sending IBPS break.
2018-09-19T21:42:57.789Z,1537393377.789 [BPC1](INFO): BPC1A: validating data format.
2018-09-19T21:42:57.866Z,1537393377.866 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-09-19T21:42:58.195Z,1537393378.195 [BPC1](INFO): BPC1A valid message: 1824 bytes.
2018-09-19T21:42:58.203Z,1537393378.203 [BPC1](INFO): BPC1A: data parsed.
2018-09-19T21:42:58.203Z,1537393378.203 [BPC1](INFO): BPC1B: validating data format.
2018-09-19T21:42:58.325Z,1537393378.325 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-09-19T21:42:58.605Z,1537393378.605 [BPC1](INFO): BPC1B valid message: 1824 bytes.
2018-09-19T21:42:58.613Z,1537393378.613 [BPC1](INFO): BPC1B: data parsed.
2018-09-19T21:42:58.996Z,1537393378.996 [BPC1](INFO): BPC1A: initialized.
2018-09-19T21:42:59.396Z,1537393379.396 [BPC1](INFO): BPC1B: initialized.
2018-09-19T21:43:06.587Z,1537393386.587 [BPC1](INFO): BPC1A: sending IBPS break.
2018-09-19T21:43:06.983Z,1537393386.983 [BPC1](INFO): BPC1B: sending IBPS break.
2018-09-19T21:43:14.086Z,1537393394.086 [BPC1](INFO): BPC1A: validating data format.
2018-09-19T21:43:14.170Z,1537393394.170 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-09-19T21:43:14.170Z,1537393394.170 [BPC1](INFO): BPC1B: validating data format.
2018-09-19T21:43:14.247Z,1537393394.247 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-09-19T21:43:14.366Z,1537393394.366 [BPC1](INFO): BPC1A valid message: 1824 bytes.
2018-09-19T21:43:14.375Z,1537393394.375 [BPC1](INFO): BPC1A: data parsed.
2018-09-19T21:43:14.375Z,1537393394.375 [BPC1](INFO): BPC1B valid message: 1824 bytes.
2018-09-19T21:43:14.383Z,1537393394.383 [BPC1](INFO): BPC1B: data parsed.
2018-09-19T21:43:15.172Z,1537393395.172 [BPC1](INFO): BPC1A: initialized.
2018-09-19T21:43:15.185Z,1537393395.185 [BPC1](INFO): BPC1B: initialized.
2018-09-19T21:43:22.333Z,1537393402.333 [BPC1](INFO): BPC1A: sending IBPS break.
2018-09-19T21:43:22.334Z,1537393402.334 [BPC1](INFO): BPC1B: sending IBPS break.
2018-09-19T21:43:26.326Z,1537393406.326 [BPC1](INFO): BPC1B: validating data format.
2018-09-19T21:43:26.400Z,1537393406.400 [BPC1](INFO): BPC1B: got 7 stick msg (1596 bytes) with SHORT_IBPS_MENU.
2018-09-19T21:43:26.739Z,1537393406.739 [BPC1](INFO): BPC1A: validating data format.
2018-09-19T21:43:26.812Z,1537393406.812 [BPC1](INFO): BPC1A: got 7 stick msg (1596 bytes) with SHORT_IBPS_MENU.
2018-09-19T21:43:26.813Z,1537393406.813 [BPC1](INFO): BPC1B valid message: 1596 bytes.
2018-09-19T21:43:26.820Z,1537393406.820 [BPC1](INFO): BPC1B: data parsed.
2018-09-19T21:43:27.141Z,1537393407.141 [BPC1](INFO): BPC1A valid message: 1596 bytes.
2018-09-19T21:43:27.149Z,1537393407.149 [BPC1](INFO): BPC1A: data parsed.
2018-09-19T21:43:27.166Z,1537393407.166 [BPC1](INFO): Calculating totals. Valid battery stick count: 36. Valid reserve battery stick count: 4.
2018-09-19T21:44:09.954Z,1537393449.954 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-09-19T21:44:09.954Z,1537393449.954 [Default:CheckIn:C.Wait] Stopped
2018-09-19T21:44:09.954Z,1537393449.954 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-09-19T21:44:09.954Z,1537393449.954 [Default:CheckIn:D] Running Loop=1
2018-09-19T21:44:10.349Z,1537393450.349 [Default:CheckIn:D] Stopped
2018-09-19T21:44:10.349Z,1537393450.349 [Default:CheckIn:E] Running Loop=1
2018-09-19T21:44:10.750Z,1537393450.750 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.941968 min 
2018-09-19T21:44:10.751Z,1537393450.751 [Default:CheckIn:E] Stopped
2018-09-19T21:44:10.751Z,1537393450.751 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-09-19T21:44:10.751Z,1537393450.751 [Default:CheckIn] Stopped
2018-09-19T21:44:10.751Z,1537393450.751 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-09-19T21:44:10.751Z,1537393450.751 [Default:CheckIn](INFO): Running loop #3
2018-09-19T21:44:10.751Z,1537393450.751 [Default:CheckIn] Running Loop=3
2018-09-19T21:44:10.751Z,1537393450.751 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-09-19T21:44:10.752Z,1537393450.752 [Default:CheckIn:Read_GPS] Running Loop=1
2018-09-19T21:45:09.609Z,1537393509.609 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-09-19T21:45:09.609Z,1537393509.609 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 9
2018-09-19T21:45:09.609Z,1537393509.609 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-09-19T21:45:09.661Z,1537393509.661 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-09-19T21:45:10.077Z,1537393510.077 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-09-19T21:45:10.077Z,1537393510.077 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 9
2018-09-19T21:45:10.375Z,1537393510.375 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-09-19T21:45:10.375Z,1537393510.375 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-09-19T21:45:10.376Z,1537393510.376 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-09-19T21:48:10.520Z,1537393690.520 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-09-19T21:48:10.520Z,1537393690.520 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 10
2018-09-19T21:48:10.520Z,1537393690.520 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-09-19T21:48:10.531Z,1537393690.531 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-09-19T21:48:10.958Z,1537393690.958 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-09-19T21:48:10.958Z,1537393690.958 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 10
2018-09-19T21:48:11.322Z,1537393691.322 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-09-19T21:48:11.323Z,1537393691.323 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-09-19T21:48:11.323Z,1537393691.323 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-09-19T21:49:10.956Z,1537393750.956 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-09-19T21:44:10.8Z
2018-09-19T21:49:10.956Z,1537393750.956 [Default:CheckIn:Read_GPS] Stopped
2018-09-19T21:49:10.957Z,1537393750.957 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-09-19T21:49:15.316Z,1537393755.316 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20180919T211748/Courier0010.lzma
2018-09-19T21:49:16.115Z,1537393756.115 [DataOverHttps](INFO): Moved sent file to Logs/20180919T211748/Courier0010.lzma.bak
2018-09-19T21:49:16.116Z,1537393756.116 [DataOverHttps](INFO): SBD MOMSN=8540560
2018-09-19T21:49:25.155Z,1537393765.155 [DataOverHttps](INFO): Sending 191 bytes from file Logs/20180919T211748/Express0011.lzma
2018-09-19T21:49:25.944Z,1537393765.944 [DataOverHttps](INFO): Moved sent file to Logs/20180919T211748/Express0011.lzma.bak
2018-09-19T21:49:25.944Z,1537393765.944 [DataOverHttps](INFO): SBD MOMSN=8540562
2018-09-19T21:49:26.781Z,1537393766.781 [Default:CheckIn:Read_Iridium] Stopped
2018-09-19T21:49:26.781Z,1537393766.781 [Default:CheckIn:C.Wait] Running Loop=1
2018-09-19T21:49:26.781Z,1537393766.781 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-09-19T21:50:05.699Z,1537393805.699 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-09-19T21:50:05.699Z,1537393805.699 [NAL9602] Data Fault, FailCount= 3
2018-09-19T21:50:05.699Z,1537393805.699 [NAL9602](ERROR): Data Fault
2018-09-19T21:50:05.802Z,1537393805.802 [CBIT](ERROR): Data Fault in component: NAL9602
2018-09-19T21:50:06.098Z,1537393806.098 [NAL9602](INFO): Powering down
2018-09-19T21:50:07.059Z,1537393807.059 [CBIT](INFO): Clearing failed state for component NAL9602
2018-09-19T21:50:07.059Z,1537393807.059 [NAL9602] No Fault, FailCount= 3
2018-09-19T21:50:36.487Z,1537393836.487 [NAL9602](INFO): Powering up NAL9602
2018-09-19T21:50:47.686Z,1537393847.686 [NAL9602](INFO): NAL9602 initialized
2018-09-19T21:50:59.882Z,1537393859.882 [CommandLine](IMPORTANT): got command restart application
2018-09-19T21:51:00.891Z,1537393860.891 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-09-19T21:51:00.892Z,1537393860.892 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:51:01.072Z,1537393861.072 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2018-09-19T21:51:01.072Z,1537393861.072 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:51:01.073Z,1537393861.073 [CommandLine](INFO): Join timeout helper Thread ID is 2751
2018-09-19T21:51:01.074Z,1537393861.074 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-09-19T21:51:01.074Z,1537393861.074 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:51:01.074Z,1537393861.074 [NavChartDb](INFO): Join timeout helper Thread ID is 2752
2018-09-19T21:51:01.201Z,1537393861.201 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-09-19T21:51:01.201Z,1537393861.201 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:51:01.212Z,1537393861.212 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2018-09-19T21:51:01.213Z,1537393861.213 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:51:01.213Z,1537393861.213 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 2753
2018-09-19T21:51:01.229Z,1537393861.229 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2018-09-19T21:51:01.229Z,1537393861.229 [WetLabsBB2FL](INFO): Powering down
2018-09-19T21:51:01.230Z,1537393861.230 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:51:01.233Z,1537393861.233 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2018-09-19T21:51:01.233Z,1537393861.233 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:51:01.233Z,1537393861.233 [CTD_Seabird](INFO): Join timeout helper Thread ID is 2754
2018-09-19T21:51:01.553Z,1537393861.553 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2018-09-19T21:51:01.636Z,1537393861.636 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-09-19T21:51:01.636Z,1537393861.636 [CTD_Seabird](INFO): Powering down
2018-09-19T21:51:01.637Z,1537393861.637 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:51:01.652Z,1537393861.652 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2018-09-19T21:51:01.653Z,1537393861.653 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:51:01.653Z,1537393861.653 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 2756
2018-09-19T21:51:01.897Z,1537393861.897 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2018-09-19T21:51:01.897Z,1537393861.897 [CTD_NeilBrown](INFO): Powering down
2018-09-19T21:51:01.898Z,1537393861.898 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:51:01.902Z,1537393861.902 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-09-19T21:51:01.902Z,1537393861.902 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:51:01.902Z,1537393861.902 [Radio_Surface](INFO): Join timeout helper Thread ID is 2757
2018-09-19T21:51:02.257Z,1537393862.257 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-09-19T21:51:02.257Z,1537393862.257 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:51:02.269Z,1537393862.269 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-09-19T21:51:02.269Z,1537393862.269 [logger ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:51:02.270Z,1537393862.270 [logger](INFO): Join timeout helper Thread ID is 2758
2018-09-19T21:51:02.285Z,1537393862.285 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-09-19T21:51:02.285Z,1537393862.285 [logger ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:51:02.289Z,1537393862.289 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-09-19T21:51:02.289Z,1537393862.289 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:51:02.290Z,1537393862.290 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-09-19T21:51:02.290Z,1537393862.290 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:51:02.290Z,1537393862.290 [controlThread](INFO): Join timeout helper Thread ID is 2759
2018-09-19T21:51:02.479Z,1537393862.479 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-09-19T21:51:02.479Z,1537393862.479 [controlThread](DEBUG): Uninitializing ControlThread
2018-09-19T21:51:02.480Z,1537393862.480 [NAL9602](INFO): Powering down
2018-09-19T21:51:02.481Z,1537393862.481 [PNI_TCM](INFO): Powering down
2018-09-19T21:51:02.569Z,1537393862.569 [Aanderaa_O2](INFO): Powering down
2018-09-19T21:51:02.572Z,1537393862.572 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-09-19T21:51:02.574Z,1537393862.574 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2018-09-19T21:51:02.574Z,1537393862.574 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-09-19T21:51:02.575Z,1537393862.575 [MissionManager](INFO): Uninitializing Mission Default
2018-09-19T21:51:02.575Z,1537393862.575 [Default] Stopped
2018-09-19T21:51:02.576Z,1537393862.576 [Default](DEBUG): Aggregate::uninitialize Default
2018-09-19T21:51:02.576Z,1537393862.576 [Default:B.GoToSurface] Stopped
2018-09-19T21:51:02.576Z,1537393862.576 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-09-19T21:51:02.576Z,1537393862.576 [Default:CheckIn] Stopped
2018-09-19T21:51:02.576Z,1537393862.576 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-09-19T21:51:02.599Z,1537393862.599 [Default:CheckIn:C.Wait] Stopped
2018-09-19T21:51:02.599Z,1537393862.599 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-09-19T21:51:02.615Z,1537393862.615 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-09-19T21:51:02.616Z,1537393862.616 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-09-19T21:51:02.616Z,1537393862.616 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-09-19T21:51:02.623Z,1537393862.623 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-09-19T21:51:02.628Z,1537393862.628 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-09-19T21:51:02.629Z,1537393862.629 [BuoyancyServo](INFO): Powering down
2018-09-19T21:51:02.641Z,1537393862.641 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-09-19T21:51:02.641Z,1537393862.641 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-09-19T21:51:02.641Z,1537393862.641 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-09-19T21:51:02.642Z,1537393862.642 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:51:02.784Z,1537393862.784 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:51:02.881Z,1537393862.881 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:51:02.885Z,1537393862.885 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:51:02.888Z,1537393862.888 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:51:02.918Z,1537393862.918 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:51:02.978Z,1537393862.978 [logger ThreadHandler](INFO): Thread cancelled.