2018-10-08T17:03:57.914Z,1539018237.914 [Supervisor](DEBUG): Initializing supervisor.
2018-10-08T17:03:57.917Z,1539018237.917 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-10-08T17:03:57.917Z,1539018237.917 [SyncHandler](INFO): Protected caller Thread ID is 7810
2018-10-08T17:03:57.918Z,1539018237.918 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-10-08T17:03:57.919Z,1539018237.919 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-10-08T17:03:57.919Z,1539018237.919 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 7811
2018-10-08T17:03:57.922Z,1539018237.922 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-10-08T17:03:57.934Z,1539018237.934 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-10-08T17:03:57.935Z,1539018237.935 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-10-08T17:03:57.935Z,1539018237.935 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 7812
2018-10-08T17:03:57.936Z,1539018237.936 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-10-08T17:03:57.937Z,1539018237.937 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-10-08T17:03:57.937Z,1539018237.937 [logger ThreadHandler](INFO): Protected caller Thread ID is 7813
2018-10-08T17:03:57.939Z,1539018237.939 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-10-08T17:03:57.940Z,1539018237.940 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-10-08T17:03:57.941Z,1539018237.941 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-10-08T17:03:58.132Z,1539018238.132 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-10-08T17:03:58.133Z,1539018238.133 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-10-08T17:03:58.277Z,1539018238.277 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-10-08T17:03:58.278Z,1539018238.278 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-10-08T17:03:58.637Z,1539018238.637 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-10-08T17:03:58.637Z,1539018238.637 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-10-08T17:03:58.778Z,1539018238.778 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-10-08T17:03:58.778Z,1539018238.778 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-10-08T17:03:58.860Z,1539018238.860 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-10-08T17:03:59.063Z,1539018239.063 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-10-08T17:03:59.064Z,1539018239.064 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-10-08T17:03:59.163Z,1539018239.163 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-10-08T17:03:59.164Z,1539018239.164 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-10-08T17:03:59.527Z,1539018239.527 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-10-08T17:03:59.528Z,1539018239.528 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-10-08T17:04:00.005Z,1539018240.005 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-10-08T17:04:00.006Z,1539018240.006 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-10-08T17:04:00.322Z,1539018240.322 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-10-08T17:04:00.322Z,1539018240.322 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-10-08T17:04:00.827Z,1539018240.827 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-10-08T17:04:00.828Z,1539018240.828 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-10-08T17:04:01.037Z,1539018241.037 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-10-08T17:04:01.037Z,1539018241.037 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-10-08T17:04:01.137Z,1539018241.137 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-10-08T17:04:01.138Z,1539018241.138 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-10-08T17:04:01.632Z,1539018241.632 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-10-08T17:04:01.632Z,1539018241.632 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-10-08T17:04:01.770Z,1539018241.770 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-10-08T17:04:01.772Z,1539018241.772 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2018-10-08T17:04:01.773Z,1539018241.773 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2018-10-08T17:04:02.015Z,1539018242.015 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-10-08T17:04:02.016Z,1539018242.016 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2018-10-08T17:04:02.117Z,1539018242.117 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2018-10-08T17:04:02.212Z,1539018242.212 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2018-10-08T17:04:02.316Z,1539018242.316 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2018-10-08T17:04:02.403Z,1539018242.403 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2018-10-08T17:04:02.539Z,1539018242.539 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2018-10-08T17:04:02.810Z,1539018242.810 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2018-10-08T17:04:02.922Z,1539018242.922 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2018-10-08T17:04:03.023Z,1539018243.023 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2018-10-08T17:04:03.108Z,1539018243.108 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2018-10-08T17:04:03.301Z,1539018243.301 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/root/
2018-10-08T17:04:03.302Z,1539018243.302 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-10-08T17:04:03.310Z,1539018243.310 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-10-08T17:04:03.439Z,1539018243.439 [SBIT](DEBUG): Construct Startup Built In Test.
2018-10-08T17:04:03.469Z,1539018243.469 [SBIT] Loaded
2018-10-08T17:04:03.469Z,1539018243.469 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-10-08T17:04:03.470Z,1539018243.470 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-10-08T17:04:03.497Z,1539018243.497 [IBIT] Loaded
2018-10-08T17:04:03.497Z,1539018243.497 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-10-08T17:04:03.500Z,1539018243.500 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-10-08T17:04:03.658Z,1539018243.658 [CBIT] Loaded
2018-10-08T17:04:03.658Z,1539018243.658 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-10-08T17:04:03.658Z,1539018243.658 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-10-08T17:04:03.659Z,1539018243.659 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-10-08T17:04:03.727Z,1539018243.727 [VerticalControl](DEBUG): Construct VerticalControl.
2018-10-08T17:04:03.826Z,1539018243.826 [VerticalControl] Loaded
2018-10-08T17:04:03.826Z,1539018243.826 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-10-08T17:04:03.827Z,1539018243.827 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-10-08T17:04:03.887Z,1539018243.887 [HorizontalControl] Loaded
2018-10-08T17:04:03.887Z,1539018243.887 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-10-08T17:04:03.887Z,1539018243.887 [SpeedControl](DEBUG): Construct SpeedControl.
2018-10-08T17:04:03.893Z,1539018243.893 [SpeedControl] Loaded
2018-10-08T17:04:03.893Z,1539018243.893 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-10-08T17:04:03.894Z,1539018243.894 [LoopControl](DEBUG): Construct LoopControl.
2018-10-08T17:04:03.894Z,1539018243.894 [LoopControl] Loaded
2018-10-08T17:04:03.895Z,1539018243.895 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-10-08T17:04:03.895Z,1539018243.895 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-10-08T17:04:03.896Z,1539018243.896 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-10-08T17:04:03.938Z,1539018243.938 [DepthRateCalculator] Loaded
2018-10-08T17:04:03.938Z,1539018243.938 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-10-08T17:04:03.943Z,1539018243.943 [PitchRateCalculator] Loaded
2018-10-08T17:04:03.943Z,1539018243.943 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-10-08T17:04:04.032Z,1539018244.032 [SpeedCalculator] Loaded
2018-10-08T17:04:04.032Z,1539018244.032 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-10-08T17:04:04.148Z,1539018244.148 [TempGradientCalculator] Loaded
2018-10-08T17:04:04.149Z,1539018244.149 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-10-08T17:04:04.156Z,1539018244.156 [YawRateCalculator] Loaded
2018-10-08T17:04:04.157Z,1539018244.157 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-10-08T17:04:04.230Z,1539018244.230 [ElevatorOffsetCalculator] Loaded
2018-10-08T17:04:04.230Z,1539018244.230 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-10-08T17:04:04.231Z,1539018244.231 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-10-08T17:04:04.231Z,1539018244.231 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-10-08T17:04:04.322Z,1539018244.322 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-10-08T17:04:04.322Z,1539018244.322 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-10-08T17:04:04.565Z,1539018244.565 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-10-08T17:04:04.566Z,1539018244.566 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-10-08T17:04:04.663Z,1539018244.663 [DeadReckonUsingMultipleVelocitySources] Loaded
2018-10-08T17:04:04.663Z,1539018244.663 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2018-10-08T17:04:04.718Z,1539018244.718 [DeadReckonUsingSpeedCalculator] Loaded
2018-10-08T17:04:04.718Z,1539018244.718 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-10-08T17:04:04.734Z,1539018244.734 [NavChart] Loaded
2018-10-08T17:04:04.734Z,1539018244.734 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-10-08T17:04:04.738Z,1539018244.738 [UniversalFixResidualReporter] Loaded
2018-10-08T17:04:04.739Z,1539018244.739 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-10-08T17:04:04.739Z,1539018244.739 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-10-08T17:04:04.740Z,1539018244.740 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-10-08T17:04:04.753Z,1539018244.753 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-10-08T17:04:04.754Z,1539018244.754 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-10-08T17:04:04.924Z,1539018244.924 [Aanderaa_O2] Loaded
2018-10-08T17:04:04.924Z,1539018244.924 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-10-08T17:04:05.002Z,1539018245.002 [CTD_NeilBrown] Loaded
2018-10-08T17:04:05.002Z,1539018245.002 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2018-10-08T17:04:05.003Z,1539018245.003 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 406DB4E0
2018-10-08T17:04:05.004Z,1539018245.004 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 7892
2018-10-08T17:04:05.048Z,1539018245.048 [WetLabsSeaOWL_UV_A] Loaded
2018-10-08T17:04:05.049Z,1539018245.049 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2018-10-08T17:04:05.050Z,1539018245.050 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 4070B4E0
2018-10-08T17:04:05.050Z,1539018245.050 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 7893
2018-10-08T17:04:05.051Z,1539018245.051 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-10-08T17:04:05.051Z,1539018245.051 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-10-08T17:04:05.362Z,1539018245.362 [AHRS_M2] Loaded
2018-10-08T17:04:05.362Z,1539018245.362 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2018-10-08T17:04:05.432Z,1539018245.432 [DataOverHttps] Loaded
2018-10-08T17:04:05.432Z,1539018245.432 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-10-08T17:04:05.445Z,1539018245.445 [Depth_Keller] Loaded
2018-10-08T17:04:05.446Z,1539018245.446 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-10-08T17:04:05.450Z,1539018245.450 [DropWeight] Loaded
2018-10-08T17:04:05.451Z,1539018245.451 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-10-08T17:04:05.723Z,1539018245.723 [NAL9602] Loaded
2018-10-08T17:04:05.723Z,1539018245.723 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-10-08T17:04:05.728Z,1539018245.728 [Onboard] Loaded
2018-10-08T17:04:05.728Z,1539018245.728 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-10-08T17:04:05.735Z,1539018245.735 [Radio_Surface] Loaded
2018-10-08T17:04:05.736Z,1539018245.736 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-10-08T17:04:05.737Z,1539018245.737 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4096C4E0
2018-10-08T17:04:05.737Z,1539018245.737 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 7894
2018-10-08T17:04:05.765Z,1539018245.765 [RDI_Pathfinder] Loaded
2018-10-08T17:04:05.765Z,1539018245.765 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2018-10-08T17:04:05.771Z,1539018245.771 [SCPI] Loaded
2018-10-08T17:04:05.772Z,1539018245.772 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread.
2018-10-08T17:04:05.796Z,1539018245.796 [BPC1](INFO): BPC1A: got serial number for stick 1: 0165
2018-10-08T17:04:05.797Z,1539018245.797 [BPC1](INFO): BPC1A: got serial number for stick 2: 0135
2018-10-08T17:04:05.798Z,1539018245.798 [BPC1](INFO): BPC1A: got serial number for stick 3: 0149
2018-10-08T17:04:05.799Z,1539018245.799 [BPC1](INFO): BPC1A: got serial number for stick 4: 0146
2018-10-08T17:04:05.799Z,1539018245.799 [BPC1](INFO): BPC1A: got serial number for stick 5: 013D
2018-10-08T17:04:05.800Z,1539018245.800 [BPC1](INFO): BPC1A: got serial number for stick 6: 014D
2018-10-08T17:04:05.801Z,1539018245.801 [BPC1](INFO): BPC1A: got serial number for stick 7: 0156
2018-10-08T17:04:05.802Z,1539018245.802 [BPC1](INFO): BPC1A: got serial number for stick 8: 0133
2018-10-08T17:04:05.802Z,1539018245.802 [BPC1](INFO): BPC1A: marked stick 8 as reserve.
2018-10-08T17:04:05.803Z,1539018245.803 [BPC1](INFO): BPC1A: got serial number for stick 9: 0131
2018-10-08T17:04:05.804Z,1539018245.804 [BPC1](INFO): BPC1A: got serial number for stick 10: 0145
2018-10-08T17:04:05.804Z,1539018245.804 [BPC1](INFO): BPC1A: got serial number for stick 11: 014A
2018-10-08T17:04:05.805Z,1539018245.805 [BPC1](INFO): BPC1A: got serial number for stick 12: 013C
2018-10-08T17:04:05.806Z,1539018245.806 [BPC1](INFO): BPC1A: got serial number for stick 13: 013B
2018-10-08T17:04:05.807Z,1539018245.807 [BPC1](INFO): BPC1A: got serial number for stick 14: 0132
2018-10-08T17:04:05.807Z,1539018245.807 [BPC1](INFO): BPC1A: got serial number for stick 15: 0134
2018-10-08T17:04:05.808Z,1539018245.808 [BPC1](INFO): BPC1A: got serial number for stick 16: 0153
2018-10-08T17:04:05.809Z,1539018245.809 [BPC1](INFO): BPC1A: marked stick 16 as reserve.
2018-10-08T17:04:05.809Z,1539018245.809 [BPC1](INFO): BPC1A: got serial number for stick 17: 014B
2018-10-08T17:04:05.810Z,1539018245.810 [BPC1](INFO): BPC1A: got serial number for stick 18: 013A
2018-10-08T17:04:05.811Z,1539018245.811 [BPC1](INFO): BPC1A: got serial number for stick 19: 0136
2018-10-08T17:04:05.812Z,1539018245.812 [BPC1](INFO): BPC1A: got serial number for stick 20: 014F
2018-10-08T17:04:05.812Z,1539018245.812 [BPC1](INFO): BPC1A: got serial number for stick 21: 014E
2018-10-08T17:04:05.813Z,1539018245.813 [BPC1](INFO): BPC1A: got serial number for stick 22: 013F
2018-10-08T17:04:05.814Z,1539018245.814 [BPC1](INFO): BPC1A: got serial number for stick 23: 0152
2018-10-08T17:04:05.815Z,1539018245.815 [BPC1](INFO): BPC1A: got serial number for stick 24: 014C
2018-10-08T17:04:05.815Z,1539018245.815 [BPC1](INFO): BPC1A: marked stick 24 as reserve.
2018-10-08T17:04:05.816Z,1539018245.816 [BPC1](INFO): BPC1A: got serial number for stick 25: 016B
2018-10-08T17:04:05.817Z,1539018245.817 [BPC1](INFO): BPC1A: got serial number for stick 26: 0141
2018-10-08T17:04:05.817Z,1539018245.817 [BPC1](INFO): BPC1A: got serial number for stick 27: 0139
2018-10-08T17:04:05.818Z,1539018245.818 [BPC1](INFO): BPC1A: got serial number for stick 28: 0137
2018-10-08T17:04:05.819Z,1539018245.819 [BPC1](INFO): BPC1A: got serial number for stick 29: 0142
2018-10-08T17:04:05.820Z,1539018245.820 [BPC1](INFO): BPC1A: got serial number for stick 30: 013E
2018-10-08T17:04:05.820Z,1539018245.820 [BPC1](INFO): BPC1A: got serial number for stick 31: 0147
2018-10-08T17:04:05.822Z,1539018245.822 [BPC1](INFO): BPC1B: got serial number for stick 32: 0140
2018-10-08T17:04:05.823Z,1539018245.823 [BPC1](INFO): BPC1B: got serial number for stick 33: 0163
2018-10-08T17:04:05.824Z,1539018245.824 [BPC1](INFO): BPC1B: got serial number for stick 34: 0157
2018-10-08T17:04:05.824Z,1539018245.824 [BPC1](INFO): BPC1B: got serial number for stick 35: 0159
2018-10-08T17:04:05.825Z,1539018245.825 [BPC1](INFO): BPC1B: got serial number for stick 36: 016E
2018-10-08T17:04:05.826Z,1539018245.826 [BPC1](INFO): BPC1B: got serial number for stick 37: 0160
2018-10-08T17:04:05.827Z,1539018245.827 [BPC1](INFO): BPC1B: got serial number for stick 38: 015C
2018-10-08T17:04:05.828Z,1539018245.828 [BPC1](INFO): BPC1B: got serial number for stick 39: 016D
2018-10-08T17:04:05.828Z,1539018245.828 [BPC1](INFO): BPC1B: marked stick 39 as reserve.
2018-10-08T17:04:05.829Z,1539018245.829 [BPC1](INFO): BPC1B: got serial number for stick 40: 012D
2018-10-08T17:04:05.830Z,1539018245.830 [BPC1](INFO): BPC1B: got serial number for stick 41: 015E
2018-10-08T17:04:05.830Z,1539018245.830 [BPC1](INFO): BPC1B: got serial number for stick 42: 0164
2018-10-08T17:04:05.831Z,1539018245.831 [BPC1](INFO): BPC1B: got serial number for stick 43: 015B
2018-10-08T17:04:05.832Z,1539018245.832 [BPC1](INFO): BPC1B: got serial number for stick 44: 0172
2018-10-08T17:04:05.833Z,1539018245.833 [BPC1](INFO): BPC1B: got serial number for stick 45: 0166
2018-10-08T17:04:05.833Z,1539018245.833 [BPC1](INFO): BPC1B: got serial number for stick 46: 0170
2018-10-08T17:04:05.834Z,1539018245.834 [BPC1](INFO): BPC1B: got serial number for stick 47: 0148
2018-10-08T17:04:05.835Z,1539018245.835 [BPC1](INFO): BPC1B: marked stick 47 as reserve.
2018-10-08T17:04:05.835Z,1539018245.835 [BPC1](INFO): BPC1B: got serial number for stick 48: 0130
2018-10-08T17:04:05.836Z,1539018245.836 [BPC1](INFO): BPC1B: got serial number for stick 49: 0169
2018-10-08T17:04:05.837Z,1539018245.837 [BPC1](INFO): BPC1B: got serial number for stick 50: 0158
2018-10-08T17:04:05.838Z,1539018245.838 [BPC1](INFO): BPC1B: got serial number for stick 51: 0162
2018-10-08T17:04:05.839Z,1539018245.839 [BPC1](INFO): BPC1B: got serial number for stick 52: 0150
2018-10-08T17:04:05.839Z,1539018245.839 [BPC1](INFO): BPC1B: got serial number for stick 53: 015F
2018-10-08T17:04:05.840Z,1539018245.840 [BPC1](INFO): BPC1B: got serial number for stick 54: 0171
2018-10-08T17:04:05.841Z,1539018245.841 [BPC1](INFO): BPC1B: got serial number for stick 55: 0143
2018-10-08T17:04:05.841Z,1539018245.841 [BPC1](INFO): BPC1B: marked stick 55 as reserve.
2018-10-08T17:04:05.842Z,1539018245.842 [BPC1](INFO): BPC1B: got serial number for stick 56: 0144
2018-10-08T17:04:05.843Z,1539018245.843 [BPC1](INFO): BPC1B: got serial number for stick 57: 016A
2018-10-08T17:04:05.844Z,1539018245.844 [BPC1](INFO): BPC1B: got serial number for stick 58: 0155
2018-10-08T17:04:05.844Z,1539018245.844 [BPC1](INFO): BPC1B: got serial number for stick 59: 0151
2018-10-08T17:04:05.845Z,1539018245.845 [BPC1](INFO): BPC1B: got serial number for stick 60: 0154
2018-10-08T17:04:05.846Z,1539018245.846 [BPC1](INFO): BPC1B: got serial number for stick 61: 0161
2018-10-08T17:04:05.847Z,1539018245.847 [BPC1](INFO): BPC1B: got serial number for stick 62: 0138
2018-10-08T17:04:07.733Z,1539018247.733 [BPC1] Loaded
2018-10-08T17:04:07.733Z,1539018247.733 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-10-08T17:04:07.734Z,1539018247.734 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-10-08T17:04:07.734Z,1539018247.734 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-10-08T17:04:07.835Z,1539018247.835 [BuoyancyServo] Loaded
2018-10-08T17:04:07.835Z,1539018247.835 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-10-08T17:04:07.847Z,1539018247.847 [ElevatorServo] Loaded
2018-10-08T17:04:07.847Z,1539018247.847 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-10-08T17:04:07.858Z,1539018247.858 [MassServo] Loaded
2018-10-08T17:04:07.858Z,1539018247.858 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-10-08T17:04:07.869Z,1539018247.869 [RudderServo] Loaded
2018-10-08T17:04:07.869Z,1539018247.869 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-10-08T17:04:07.880Z,1539018247.880 [ThrusterServo] Loaded
2018-10-08T17:04:07.880Z,1539018247.880 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-10-08T17:04:07.881Z,1539018247.881 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-10-08T17:04:07.882Z,1539018247.882 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-10-08T17:04:07.983Z,1539018247.983 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-10-08T17:04:07.983Z,1539018247.983 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-10-08T17:04:08.008Z,1539018248.008 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-10-08T17:04:08.012Z,1539018248.012 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-10-08T17:04:08.013Z,1539018248.013 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-10-08T17:04:08.019Z,1539018248.019 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-10-08T17:04:08.021Z,1539018248.021 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A154E0
2018-10-08T17:04:08.021Z,1539018248.021 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 7895
2018-10-08T17:04:08.026Z,1539018248.026 [Supervisor](INFO): Main Thread ID is 796
2018-10-08T17:04:08.026Z,1539018248.026 [Supervisor](DEBUG): Running supervisor.
2018-10-08T17:04:08.027Z,1539018248.027 [CommandLine ThreadHandler](INFO): Handler Thread ID is 7896
2018-10-08T17:04:08.029Z,1539018248.029 [controlThread ThreadHandler](INFO): Handler Thread ID is 7897
2018-10-08T17:04:08.030Z,1539018248.030 [controlThread](DEBUG): Initializing ControlThread
2018-10-08T17:04:08.031Z,1539018248.031 [SBIT](INFO): Initialize SBIT Component.
2018-10-08T17:04:08.031Z,1539018248.031 [SBIT](IMPORTANT): git: 2018-09-26-9-g14f2005
2018-10-08T17:04:08.031Z,1539018248.031 [SBIT](INFO): git hash: 14f2005f6a70b793a05ede5ccfbd62015cc8442d
2018-10-08T17:04:08.032Z,1539018248.032 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-10-08T17:04:08.032Z,1539018248.032 [SBIT](IMPORTANT): Kernel Version:#2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-10-08T17:04:08.033Z,1539018248.033 [SBIT](INFO): Beginning SBIT in 28.000000 seconds.
2018-10-08T17:04:08.034Z,1539018248.034 [IBIT](INFO): Initialize IBIT Component.
2018-10-08T17:04:08.035Z,1539018248.035 [CBIT](DEBUG): Initialize CBIT Component.
2018-10-08T17:04:08.035Z,1539018248.035 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2018-10-08T17:04:08.036Z,1539018248.036 [logger ThreadHandler](INFO): Handler Thread ID is 7898
2018-10-08T17:04:08.061Z,1539018248.061 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 7899
2018-10-08T17:04:08.062Z,1539018248.062 [CTD_NeilBrown](INFO): Powering down
2018-10-08T17:04:08.101Z,1539018248.101 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 7900
2018-10-08T17:04:08.102Z,1539018248.102 [WetLabsSeaOWL_UV_A](INFO): Powering down
2018-10-08T17:04:08.141Z,1539018248.141 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-10-08T17:04:08.143Z,1539018248.143 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-10-08T17:04:08.144Z,1539018248.144 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-10-08T17:04:08.144Z,1539018248.144 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-10-08T17:04:08.144Z,1539018248.144 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-10-08T17:04:08.145Z,1539018248.145 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-10-08T17:04:08.145Z,1539018248.145 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-10-08T17:04:08.146Z,1539018248.146 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-10-08T17:04:08.146Z,1539018248.146 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-10-08T17:04:08.147Z,1539018248.147 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-10-08T17:04:08.147Z,1539018248.147 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2018-10-08T17:04:08.148Z,1539018248.148 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2018-10-08T17:04:08.148Z,1539018248.148 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2018-10-08T17:04:08.149Z,1539018248.149 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-10-08T17:04:08.149Z,1539018248.149 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-10-08T17:04:08.150Z,1539018248.150 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-10-08T17:04:08.150Z,1539018248.150 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-10-08T17:04:08.150Z,1539018248.150 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-10-08T17:04:08.158Z,1539018248.158 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-10-08T17:04:08.165Z,1539018248.165 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 7901
2018-10-08T17:04:08.171Z,1539018248.171 [Radio_Surface](INFO): Powering up
2018-10-08T17:04:08.181Z,1539018248.181 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 7902
2018-10-08T17:04:08.185Z,1539018248.185 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-10-08T17:04:08.185Z,1539018248.185 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-10-08T17:04:08.185Z,1539018248.185 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-10-08T17:04:08.185Z,1539018248.185 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-10-08T17:04:08.186Z,1539018248.186 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-10-08T17:04:08.186Z,1539018248.186 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-10-08T17:04:08.186Z,1539018248.186 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-10-08T17:04:08.186Z,1539018248.186 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-10-08T17:04:08.186Z,1539018248.186 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-10-08T17:04:08.187Z,1539018248.187 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-10-08T17:04:08.187Z,1539018248.187 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-10-08T17:04:08.187Z,1539018248.187 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-10-08T17:04:08.187Z,1539018248.187 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-10-08T17:04:08.187Z,1539018248.187 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-10-08T17:04:08.188Z,1539018248.188 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-10-08T17:04:08.188Z,1539018248.188 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-10-08T17:04:08.201Z,1539018248.201 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-10-08T17:04:08.245Z,1539018248.245 [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-10-08T17:04:08.246Z,1539018248.246 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-10-08T17:04:08.321Z,1539018248.321 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-10-08T17:04:08.322Z,1539018248.322 [Default:A.Wait](DEBUG): Construct Wait.
2018-10-08T17:04:08.324Z,1539018248.324 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-10-08T17:04:08.375Z,1539018248.375 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-10-08T17:04:08.378Z,1539018248.378 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-10-08T17:04:08.404Z,1539018248.404 [Default:E.Execute](DEBUG): Construct Execute.
2018-10-08T17:04:08.411Z,1539018248.411 [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-10-08T17:04:08.416Z,1539018248.416 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,AHRS_M2,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,RDI_Pathfinder,SCPI,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-10-08T17:04:08.484Z,1539018248.484 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2018-10-08T17:04:08.541Z,1539018248.541 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-10-08T17:04:08.565Z,1539018248.565 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2018-10-08T17:04:08.752Z,1539018248.752 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-10-08T17:04:08.849Z,1539018248.849 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-10-08T17:04:08.876Z,1539018248.876 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-08T17:04:09.001Z,1539018249.001 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-10-08T17:04:09.009Z,1539018249.009 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-10-08T17:04:09.016Z,1539018249.016 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-10-08T17:04:09.021Z,1539018249.021 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-10-08T17:04:09.027Z,1539018249.027 [MassServo](DEBUG): Initializing EZServoServo.
2018-10-08T17:04:09.033Z,1539018249.033 [MassServo](DEBUG): Initializing MassServo.
2018-10-08T17:04:09.055Z,1539018249.055 [RudderServo](DEBUG): Initializing EZServoServo.
2018-10-08T17:04:09.061Z,1539018249.061 [RudderServo](DEBUG): Initializing RudderServo.
2018-10-08T17:04:09.067Z,1539018249.067 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-10-08T17:04:09.073Z,1539018249.073 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-10-08T17:04:09.130Z,1539018249.130 [CommandLine](FAULT): Scheduling is paused
2018-10-08T17:04:09.131Z,1539018249.131 [CBIT](INFO): Critical error at 20181008T170408
2018-10-08T17:04:09.131Z,1539018249.131 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2018-10-08T17:04:09.276Z,1539018249.276 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-10-08T17:04:09.293Z,1539018249.293 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-08T17:04:09.605Z,1539018249.605 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-10-08T17:04:09.606Z,1539018249.606 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-08T17:04:09.937Z,1539018249.937 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2018-10-08T17:04:09.937Z,1539018249.937 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2018-10-08T17:04:09.937Z,1539018249.937 [BuoyancyServo] Communications Fault, FailCount= 1
2018-10-08T17:04:09.937Z,1539018249.937 [BuoyancyServo](ERROR): Communications Fault
2018-10-08T17:04:10.177Z,1539018250.177 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2018-10-08T17:04:10.224Z,1539018250.224 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-10-08T17:04:10.229Z,1539018250.229 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-08T17:04:10.251Z,1539018250.251 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-10-08T17:04:10.251Z,1539018250.251 [BuoyancyServo](INFO): Powering down
2018-10-08T17:04:10.616Z,1539018250.616 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-10-08T17:04:10.618Z,1539018250.618 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-08T17:04:11.016Z,1539018251.016 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-10-08T17:04:11.017Z,1539018251.017 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-08T17:04:11.416Z,1539018251.416 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-10-08T17:04:11.417Z,1539018251.417 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-08T17:04:11.905Z,1539018251.905 [Aanderaa_O2](INFO): Powering down
2018-10-08T17:04:12.060Z,1539018252.060 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-10-08T17:04:12.062Z,1539018252.062 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-08T17:04:12.249Z,1539018252.249 [AHRS_M2](ERROR): Read RFS packet UART error: serial timeout
2018-10-08T17:04:12.292Z,1539018252.292 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-10-08T17:04:12.294Z,1539018252.294 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-08T17:04:12.350Z,1539018252.350 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2018-10-08T17:04:12.350Z,1539018252.350 [BuoyancyServo] No Fault, FailCount= 1
2018-10-08T17:04:12.625Z,1539018252.625 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-10-08T17:04:12.746Z,1539018252.746 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-10-08T17:04:21.881Z,1539018261.881 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2018-10-08T17:04:35.863Z,1539018275.863 [NAL9602](INFO): Powering up NAL9602
2018-10-08T17:04:36.696Z,1539018276.696 [SBIT](IMPORTANT): Beginning Startup BIT
2018-10-08T17:04:36.716Z,1539018276.716 [CBIT](IMPORTANT): Beginning ground fault scan
2018-10-08T17:04:46.935Z,1539018286.935 [NAL9602](INFO): NAL9602 initialized
2018-10-08T17:04:48.378Z,1539018288.378 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.009629
CHAN A1 (24V): 0.003408
CHAN A2 (12V): -0.007635
CHAN A3 (5V): -0.002001
CHAN B0 (3.3V): 0.000214
CHAN B1 (3.15aV): 0.000036
CHAN B2 (3.15bV): 0.000246
CHAN B3 (GND): 0.002366
OPEN: 0.005352
Full Scale Calc: 4.765 mA, -1.589 mA
2018-10-08T17:05:09.573Z,1539018309.573 [BPC1](INFO): BPC1A: initialized.
2018-10-08T17:05:09.585Z,1539018309.585 [BPC1](INFO): BPC1B: initialized.
2018-10-08T17:05:16.736Z,1539018316.736 [BPC1](INFO): BPC1A: sending IBPS break.
2018-10-08T17:05:16.736Z,1539018316.736 [BPC1](INFO): BPC1B: sending IBPS break.
2018-10-08T17:05:21.670Z,1539018321.670 [BPC1](INFO): BPC1A: validating data format.
2018-10-08T17:05:21.752Z,1539018321.752 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-10-08T17:05:21.753Z,1539018321.753 [BPC1](INFO): BPC1A: got valid message (1824 bytes).
2018-10-08T17:05:21.753Z,1539018321.753 [BPC1](INFO): BPC1B: validating data format.
2018-10-08T17:05:21.873Z,1539018321.873 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-10-08T17:05:21.873Z,1539018321.873 [BPC1](INFO): BPC1B: got valid message (1824 bytes).
2018-10-08T17:05:22.243Z,1539018322.243 [BPC1](INFO): BPC1A: data parsed.
2018-10-08T17:05:22.260Z,1539018322.260 [BPC1](INFO): BPC1B: data parsed.
2018-10-08T17:05:23.049Z,1539018323.049 [BPC1](INFO): BPC1A: initialized.
2018-10-08T17:05:23.067Z,1539018323.067 [BPC1](INFO): BPC1B: initialized.
2018-10-08T17:05:30.240Z,1539018330.240 [BPC1](INFO): BPC1A: sending IBPS break.
2018-10-08T17:05:30.256Z,1539018330.256 [SBIT](IMPORTANT): SBIT PASSED
2018-10-08T17:05:30.335Z,1539018330.335 [CommandLine](IMPORTANT): got command configSet list
2018-10-08T17:05:30.336Z,1539018330.336 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-10-08T17:05:30.337Z,1539018330.337 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=1 minute;

2018-10-08T17:05:30.337Z,1539018330.337 [CommandLine](IMPORTANT): CTD_NeilBrown.minSalinityBound=-10 practical_salinity_unit;

2018-10-08T17:05:30.337Z,1539018330.337 [CommandLine](IMPORTANT): Express linearApproximation concentration_of_colored_dissolved_organic_matter_in_sea_water_expressed_as_equivalent_mass_fraction_of_quinine_sulfate_dihydrate 1.000000 part_per_billion;

2018-10-08T17:05:30.337Z,1539018330.337 [CommandLine](IMPORTANT): IBIT.batteryVoltageThreshold=13.7 volt;

2018-10-08T17:05:30.338Z,1539018330.338 [CommandLine](IMPORTANT): NAL9602.gpsFailTimeout=10 minute;

2018-10-08T17:05:30.338Z,1539018330.338 [CommandLine](IMPORTANT): RDI_PathfinderUp.loadAtStartup=0 bool;

2018-10-08T17:05:30.338Z,1539018330.338 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=200 cubic_centimeter;

2018-10-08T17:05:30.338Z,1539018330.338 [CommandLine](IMPORTANT): VerticalControl.massDefault=2 millimeter;

2018-10-08T17:05:30.612Z,1539018330.612 [BPC1](INFO): BPC1B: sending IBPS break.
2018-10-08T17:05:30.646Z,1539018330.646 [MissionManager](IMPORTANT): Started mission Startup
2018-10-08T17:05:30.646Z,1539018330.646 [Startup] Running Loop=1
2018-10-08T17:05:30.646Z,1539018330.646 [Startup](DEBUG): Aggregate::initialize Startup
2018-10-08T17:05:30.646Z,1539018330.646 [Startup:A.GoToSurface] Running Loop=1
2018-10-08T17:05:30.646Z,1539018330.646 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-10-08T17:05:30.647Z,1539018330.647 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-10-08T17:05:30.647Z,1539018330.647 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-10-08T17:05:30.648Z,1539018330.648 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-10-08T17:05:30.648Z,1539018330.648 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-10-08T17:05:30.649Z,1539018330.649 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-10-08T17:05:30.666Z,1539018330.666 [Startup:StartupSatComms] Running Loop=1
2018-10-08T17:05:30.666Z,1539018330.666 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-10-08T17:05:30.666Z,1539018330.666 [Startup:StartupSatComms:A] Running Loop=1
2018-10-08T17:05:31.048Z,1539018331.048 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-10-08T17:05:35.043Z,1539018335.043 [BPC1](INFO): BPC1A: validating data format.
2018-10-08T17:05:35.127Z,1539018335.127 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-10-08T17:05:35.127Z,1539018335.127 [BPC1](INFO): BPC1A: got valid message (1824 bytes).
2018-10-08T17:05:35.428Z,1539018335.428 [BPC1](INFO): BPC1A: data parsed.
2018-10-08T17:05:35.428Z,1539018335.428 [BPC1](INFO): BPC1B: validating data format.
2018-10-08T17:05:35.538Z,1539018335.538 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-10-08T17:05:35.538Z,1539018335.538 [BPC1](INFO): BPC1B: got valid message (1824 bytes).
2018-10-08T17:05:35.877Z,1539018335.877 [BPC1](INFO): BPC1B: data parsed.
2018-10-08T17:05:36.245Z,1539018336.245 [BPC1](INFO): BPC1A: initialized.
2018-10-08T17:05:36.617Z,1539018336.617 [BPC1](INFO): BPC1B: initialized.
2018-10-08T17:05:43.852Z,1539018343.852 [BPC1](INFO): BPC1A: sending IBPS break.
2018-10-08T17:05:43.852Z,1539018343.852 [BPC1](INFO): BPC1B: sending IBPS break.
2018-10-08T17:05:48.220Z,1539018348.220 [BPC1](INFO): BPC1A: validating data format.
2018-10-08T17:05:48.310Z,1539018348.310 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-10-08T17:05:48.311Z,1539018348.311 [BPC1](INFO): BPC1A: got valid message (1824 bytes).
2018-10-08T17:05:48.618Z,1539018348.618 [BPC1](INFO): BPC1A: data parsed.
2018-10-08T17:05:48.618Z,1539018348.618 [BPC1](INFO): BPC1B: validating data format.
2018-10-08T17:05:48.729Z,1539018348.729 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-10-08T17:05:48.730Z,1539018348.730 [BPC1](INFO): BPC1B: got valid message (1824 bytes).
2018-10-08T17:05:49.065Z,1539018349.065 [BPC1](INFO): BPC1B: data parsed.
2018-10-08T17:05:49.421Z,1539018349.421 [BPC1](INFO): BPC1A: initialized.
2018-10-08T17:05:49.825Z,1539018349.825 [BPC1](INFO): BPC1B: initialized.
2018-10-08T17:05:57.035Z,1539018357.035 [BPC1](INFO): BPC1A: sending IBPS break.
2018-10-08T17:05:57.406Z,1539018357.406 [BPC1](INFO): BPC1B: sending IBPS break.
2018-10-08T17:06:01.832Z,1539018361.832 [BPC1](INFO): BPC1A: validating data format.
2018-10-08T17:06:01.920Z,1539018361.920 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-10-08T17:06:01.929Z,1539018361.929 [BPC1](INFO): BPC1A: got valid message (1824 bytes).
2018-10-08T17:06:02.239Z,1539018362.239 [BPC1](INFO): BPC1A: data parsed.
2018-10-08T17:06:02.239Z,1539018362.239 [BPC1](INFO): BPC1B: validating data format.
2018-10-08T17:06:02.343Z,1539018362.343 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-10-08T17:06:02.344Z,1539018362.344 [BPC1](INFO): BPC1B: got valid message (1824 bytes).
2018-10-08T17:06:02.629Z,1539018362.629 [BPC1](INFO): BPC1B: data parsed.
2018-10-08T17:06:03.041Z,1539018363.041 [BPC1](INFO): BPC1A: initialized.
2018-10-08T17:06:03.409Z,1539018363.409 [BPC1](INFO): BPC1B: initialized.
2018-10-08T17:06:10.601Z,1539018370.601 [BPC1](INFO): BPC1A: sending IBPS break.
2018-10-08T17:06:10.601Z,1539018370.601 [BPC1](INFO): BPC1B: sending IBPS break.
2018-10-08T17:06:15.022Z,1539018375.022 [BPC1](INFO): BPC1A: validating data format.
2018-10-08T17:06:15.108Z,1539018375.108 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-10-08T17:06:15.109Z,1539018375.109 [BPC1](INFO): BPC1A: got valid message (1824 bytes).
2018-10-08T17:06:15.416Z,1539018375.416 [BPC1](INFO): BPC1A: data parsed.
2018-10-08T17:06:15.417Z,1539018375.417 [BPC1](INFO): BPC1B: validating data format.
2018-10-08T17:06:15.527Z,1539018375.527 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-10-08T17:06:15.528Z,1539018375.528 [BPC1](INFO): BPC1B: got valid message (1824 bytes).
2018-10-08T17:06:15.865Z,1539018375.865 [BPC1](INFO): BPC1B: data parsed.
2018-10-08T17:06:16.221Z,1539018376.221 [BPC1](INFO): BPC1A: initialized.
2018-10-08T17:06:16.629Z,1539018376.629 [BPC1](INFO): BPC1B: initialized.
2018-10-08T17:06:23.814Z,1539018383.814 [BPC1](INFO): BPC1A: sending IBPS break.
2018-10-08T17:06:24.225Z,1539018384.225 [BPC1](INFO): BPC1B: sending IBPS break.
2018-10-08T17:06:28.606Z,1539018388.606 [BPC1](INFO): BPC1A: validating data format.
2018-10-08T17:06:28.695Z,1539018388.695 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-10-08T17:06:28.695Z,1539018388.695 [BPC1](INFO): BPC1A: got valid message (1824 bytes).
2018-10-08T17:06:29.049Z,1539018389.049 [BPC1](INFO): BPC1A: data parsed.
2018-10-08T17:06:29.050Z,1539018389.050 [BPC1](INFO): BPC1B: validating data format.
2018-10-08T17:06:29.157Z,1539018389.157 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-10-08T17:06:29.158Z,1539018389.158 [BPC1](INFO): BPC1B: got valid message (1824 bytes).
2018-10-08T17:06:29.425Z,1539018389.425 [BPC1](INFO): BPC1B: data parsed.
2018-10-08T17:06:29.817Z,1539018389.817 [BPC1](INFO): BPC1A: initialized.
2018-10-08T17:06:30.257Z,1539018390.257 [BPC1](INFO): BPC1B: initialized.
2018-10-08T17:06:33.451Z,1539018393.451 [Startup:StartupSatComms:A](INFO): Timed out from 2018-10-08T17:05:30.7Z
2018-10-08T17:06:33.451Z,1539018393.451 [Startup:StartupSatComms:A] Stopped
2018-10-08T17:06:33.451Z,1539018393.451 [Startup:StartupSatComms:B] Running Loop=1
2018-10-08T17:06:33.593Z,1539018393.593 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-10-08T17:06:34.307Z,1539018394.307 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004209
2018-10-08T17:06:38.380Z,1539018398.380 [BPC1](INFO): BPC1A: sending IBPS break.
2018-10-08T17:06:38.402Z,1539018398.402 [BPC1](INFO): BPC1B: sending IBPS break.
2018-10-08T17:06:38.477Z,1539018398.477 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20181008T164500/Courier0007.lzma
2018-10-08T17:06:39.263Z,1539018399.263 [DataOverHttps](INFO): Moved sent file to Logs/20181008T164500/Courier0007.lzma.bak
2018-10-08T17:06:39.264Z,1539018399.264 [DataOverHttps](INFO): SBD MOMSN=8614092
2018-10-08T17:06:43.371Z,1539018403.371 [BPC1](INFO): BPC1A: validating data format.
2018-10-08T17:06:43.438Z,1539018403.438 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-10-08T17:06:43.439Z,1539018403.439 [BPC1](INFO): BPC1A: got valid message (1824 bytes).
2018-10-08T17:06:43.439Z,1539018403.439 [BPC1](INFO): BPC1B: validating data format.
2018-10-08T17:06:43.521Z,1539018403.521 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-10-08T17:06:43.521Z,1539018403.521 [BPC1](INFO): BPC1B: got valid message (1824 bytes).
2018-10-08T17:06:43.643Z,1539018403.643 [BPC1](INFO): BPC1A: data parsed.
2018-10-08T17:06:43.656Z,1539018403.656 [BPC1](INFO): BPC1B: data parsed.
2018-10-08T17:06:44.430Z,1539018404.430 [BPC1](INFO): BPC1A: initialized.
2018-10-08T17:06:44.441Z,1539018404.441 [BPC1](INFO): BPC1B: initialized.
2018-10-08T17:06:48.495Z,1539018408.495 [DataOverHttps](INFO): Sending 99 bytes from file Logs/20181008T170357/Courier0000.lzma
2018-10-08T17:06:49.271Z,1539018409.271 [DataOverHttps](INFO): Moved sent file to Logs/20181008T170357/Courier0000.lzma.bak
2018-10-08T17:06:49.271Z,1539018409.271 [DataOverHttps](INFO): SBD MOMSN=8614094
2018-10-08T17:06:53.647Z,1539018413.647 [BPC1](INFO): BPC1A: sending IBPS break.
2018-10-08T17:06:53.648Z,1539018413.648 [BPC1](INFO): BPC1B: sending IBPS break.
2018-10-08T17:06:58.613Z,1539018418.613 [BPC1](INFO): BPC1A: validating data format.
2018-10-08T17:06:58.697Z,1539018418.697 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-10-08T17:06:58.697Z,1539018418.697 [BPC1](INFO): BPC1A: got valid message (1824 bytes).
2018-10-08T17:06:58.698Z,1539018418.698 [BPC1](INFO): BPC1B: validating data format.
2018-10-08T17:06:58.778Z,1539018418.778 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-10-08T17:06:58.779Z,1539018418.779 [BPC1](INFO): BPC1B: got valid message (1824 bytes).
2018-10-08T17:06:58.863Z,1539018418.863 [DataOverHttps](INFO): Sending 326 bytes from file Logs/20181008T164500/Express0008.lzma
2018-10-08T17:06:58.922Z,1539018418.922 [BPC1](INFO): BPC1A: data parsed.
2018-10-08T17:06:58.938Z,1539018418.938 [BPC1](INFO): BPC1B: data parsed.
2018-10-08T17:06:59.623Z,1539018419.623 [DataOverHttps](INFO): Moved sent file to Logs/20181008T164500/Express0008.lzma.bak
2018-10-08T17:06:59.624Z,1539018419.624 [DataOverHttps](INFO): SBD MOMSN=8614097
2018-10-08T17:06:59.705Z,1539018419.705 [BPC1](INFO): BPC1A: initialized.
2018-10-08T17:06:59.717Z,1539018419.717 [BPC1](INFO): BPC1B: initialized.
2018-10-08T17:07:08.904Z,1539018428.904 [BPC1](INFO): BPC1A: sending IBPS break.
2018-10-08T17:07:08.904Z,1539018428.904 [BPC1](INFO): BPC1B: sending IBPS break.
2018-10-08T17:07:08.912Z,1539018428.912 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-10-08T17:07:08.912Z,1539018428.912 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2018-10-08T17:07:08.912Z,1539018428.912 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2018-10-08T17:07:08.914Z,1539018428.914 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-10-08T17:07:08.914Z,1539018428.914 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2018-10-08T17:07:08.914Z,1539018428.914 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-10-08T17:07:09.002Z,1539018429.002 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2018-10-08T17:07:09.002Z,1539018429.002 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-10-08T17:07:09.059Z,1539018429.059 [DataOverHttps](INFO): Sending 1013 bytes from file Logs/20181008T170357/Express0001.lzma
2018-10-08T17:07:09.181Z,1539018429.181 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2018-10-08T17:07:09.182Z,1539018429.182 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2018-10-08T17:07:09.182Z,1539018429.182 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-10-08T17:07:09.182Z,1539018429.182 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2018-10-08T17:07:09.482Z,1539018429.482 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2018-10-08T17:07:09.482Z,1539018429.482 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2018-10-08T17:07:09.483Z,1539018429.483 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2018-10-08T17:07:09.483Z,1539018429.483 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-10-08T17:07:09.484Z,1539018429.484 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-10-08T17:07:09.484Z,1539018429.484 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-10-08T17:07:09.819Z,1539018429.819 [DataOverHttps](INFO): Moved sent file to Logs/20181008T170357/Express0001.lzma.bak
2018-10-08T17:07:09.819Z,1539018429.819 [DataOverHttps](INFO): SBD MOMSN=8614099
2018-10-08T17:07:10.890Z,1539018430.890 [Startup:StartupSatComms:B] Stopped
2018-10-08T17:07:10.890Z,1539018430.890 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-10-08T17:07:10.890Z,1539018430.890 [Startup:StartupSatComms] Stopped
2018-10-08T17:07:10.891Z,1539018430.891 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-10-08T17:07:10.892Z,1539018430.892 [Startup](INFO): Completed Startup
2018-10-08T17:07:10.892Z,1539018430.892 [MissionManager](INFO): Startup is completed.
2018-10-08T17:07:10.892Z,1539018430.892 [MissionManager](INFO): Uninitializing Mission Startup
2018-10-08T17:07:10.892Z,1539018430.892 [Startup] Stopped
2018-10-08T17:07:10.892Z,1539018430.892 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-10-08T17:07:10.892Z,1539018430.892 [Startup:A.GoToSurface] Stopped
2018-10-08T17:07:10.892Z,1539018430.892 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-10-08T17:07:11.013Z,1539018431.013 [MissionManager](IMPORTANT): Started mission Default
2018-10-08T17:07:11.017Z,1539018431.017 [Default] Running Loop=1
2018-10-08T17:07:11.017Z,1539018431.017 [Default](DEBUG): Aggregate::initialize Default
2018-10-08T17:07:11.017Z,1539018431.017 [Default:B.GoToSurface] Running Loop=1
2018-10-08T17:07:11.017Z,1539018431.017 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-10-08T17:07:11.018Z,1539018431.018 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-10-08T17:07:11.018Z,1539018431.018 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-10-08T17:07:11.018Z,1539018431.018 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-10-08T17:07:11.019Z,1539018431.019 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-10-08T17:07:11.019Z,1539018431.019 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-10-08T17:07:11.019Z,1539018431.019 [Default:A.Wait] Running Loop=1
2018-10-08T17:07:11.019Z,1539018431.019 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-10-08T17:07:14.228Z,1539018434.228 [BPC1](INFO): BPC1A: validating data format.
2018-10-08T17:07:14.307Z,1539018434.307 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-10-08T17:07:14.308Z,1539018434.308 [BPC1](INFO): BPC1A: got valid message (1824 bytes).
2018-10-08T17:07:14.308Z,1539018434.308 [BPC1](INFO): BPC1B: validating data format.
2018-10-08T17:07:14.393Z,1539018434.393 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-10-08T17:07:14.393Z,1539018434.393 [BPC1](INFO): BPC1B: got valid message (1824 bytes).
2018-10-08T17:07:14.523Z,1539018434.523 [BPC1](INFO): BPC1A: data parsed.
2018-10-08T17:07:14.542Z,1539018434.542 [BPC1](INFO): BPC1B: data parsed.
2018-10-08T17:07:15.305Z,1539018435.305 [BPC1](INFO): BPC1A: initialized.
2018-10-08T17:07:15.317Z,1539018435.317 [BPC1](INFO): BPC1B: initialized.
2018-10-08T17:07:22.452Z,1539018442.452 [BPC1](INFO): BPC1A: sending IBPS break.
2018-10-08T17:07:22.452Z,1539018442.452 [BPC1](INFO): BPC1B: sending IBPS break.
2018-10-08T17:07:24.085Z,1539018444.085 [Default:A.Wait](INFO): Done Waiting.
2018-10-08T17:07:24.085Z,1539018444.085 [Default:A.Wait] Stopped
2018-10-08T17:07:24.085Z,1539018444.085 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-10-08T17:07:24.487Z,1539018444.487 [Default:CheckIn] Running Loop=1
2018-10-08T17:07:24.487Z,1539018444.487 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-10-08T17:07:24.487Z,1539018444.487 [Default:CheckIn:Read_GPS] Running Loop=1
2018-10-08T17:07:24.905Z,1539018444.905 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-10-08T17:07:27.259Z,1539018447.259 [BPC1](INFO): BPC1A: validating data format.
2018-10-08T17:07:27.336Z,1539018447.336 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-10-08T17:07:27.337Z,1539018447.337 [BPC1](INFO): BPC1A: got valid message (1824 bytes).
2018-10-08T17:07:27.337Z,1539018447.337 [BPC1](INFO): BPC1B: validating data format.
2018-10-08T17:07:27.424Z,1539018447.424 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-10-08T17:07:27.424Z,1539018447.424 [BPC1](INFO): BPC1B: got valid message (1824 bytes).
2018-10-08T17:07:27.665Z,1539018447.665 [BPC1](INFO): BPC1A: data parsed.
2018-10-08T17:07:27.682Z,1539018447.682 [BPC1](INFO): BPC1B: data parsed.
2018-10-08T17:07:28.877Z,1539018448.877 [BPC1](INFO): BPC1A: initialized.
2018-10-08T17:07:28.889Z,1539018448.889 [BPC1](INFO): BPC1B: initialized.
2018-10-08T17:07:35.674Z,1539018455.674 [BPC1](INFO): BPC1A: sending IBPS break.
2018-10-08T17:07:36.091Z,1539018456.091 [BPC1](INFO): BPC1B: sending IBPS break.
2018-10-08T17:07:40.488Z,1539018460.488 [BPC1](INFO): BPC1A: validating data format.
2018-10-08T17:07:40.574Z,1539018460.574 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-10-08T17:07:40.575Z,1539018460.575 [BPC1](INFO): BPC1A: got valid message (1824 bytes).
2018-10-08T17:07:40.883Z,1539018460.883 [BPC1](INFO): BPC1A: data parsed.
2018-10-08T17:07:40.883Z,1539018460.883 [BPC1](INFO): BPC1B: validating data format.
2018-10-08T17:07:40.992Z,1539018460.992 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-10-08T17:07:40.993Z,1539018460.993 [BPC1](INFO): BPC1B: got valid message (1824 bytes).
2018-10-08T17:07:41.305Z,1539018461.305 [BPC1](INFO): BPC1B: data parsed.
2018-10-08T17:07:41.669Z,1539018461.669 [BPC1](INFO): BPC1A: initialized.
2018-10-08T17:07:42.085Z,1539018462.085 [BPC1](INFO): BPC1B: initialized.
2018-10-08T17:07:49.690Z,1539018469.690 [BPC1](INFO): BPC1A: sending IBPS break.
2018-10-08T17:07:49.690Z,1539018469.690 [BPC1](INFO): BPC1B: sending IBPS break.
2018-10-08T17:07:53.358Z,1539018473.358 [BPC1](INFO): BPC1A: validating data format.
2018-10-08T17:07:53.438Z,1539018473.438 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-10-08T17:07:53.439Z,1539018473.439 [BPC1](INFO): BPC1A: got valid message (1824 bytes).
2018-10-08T17:07:53.787Z,1539018473.787 [BPC1](INFO): BPC1A: data parsed.
2018-10-08T17:07:54.173Z,1539018474.173 [BPC1](INFO): BPC1B: validating data format.
2018-10-08T17:07:54.263Z,1539018474.263 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-10-08T17:07:54.264Z,1539018474.264 [BPC1](INFO): BPC1B: got valid message (1824 bytes).
2018-10-08T17:07:54.598Z,1539018474.598 [BPC1](INFO): BPC1B: data parsed.
2018-10-08T17:07:54.982Z,1539018474.982 [BPC1](INFO): BPC1A: initialized.
2018-10-08T17:07:55.777Z,1539018475.777 [BPC1](INFO): BPC1B: initialized.
2018-10-08T17:08:02.185Z,1539018482.185 [BPC1](INFO): BPC1A: sending IBPS break.
2018-10-08T17:08:03.085Z,1539018483.085 [BPC1](INFO): BPC1B: sending IBPS break.
2018-10-08T17:08:05.062Z,1539018485.062 [CommandLine](IMPORTANT): got command restart application
2018-10-08T17:08:06.068Z,1539018486.068 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-10-08T17:08:06.068Z,1539018486.068 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-10-08T17:08:06.213Z,1539018486.213 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2018-10-08T17:08:06.213Z,1539018486.213 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-10-08T17:08:06.214Z,1539018486.214 [CommandLine](INFO): Join timeout helper Thread ID is 7920
2018-10-08T17:08:06.229Z,1539018486.229 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-10-08T17:08:06.233Z,1539018486.233 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-10-08T17:08:06.233Z,1539018486.233 [NavChartDb](INFO): Join timeout helper Thread ID is 7921
2018-10-08T17:08:06.525Z,1539018486.525 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-10-08T17:08:06.525Z,1539018486.525 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-10-08T17:08:06.529Z,1539018486.529 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-10-08T17:08:06.529Z,1539018486.529 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-10-08T17:08:06.530Z,1539018486.530 [Radio_Surface](INFO): Join timeout helper Thread ID is 7922
2018-10-08T17:08:06.689Z,1539018486.689 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-10-08T17:08:06.690Z,1539018486.690 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-10-08T17:08:06.709Z,1539018486.709 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2018-10-08T17:08:06.709Z,1539018486.709 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2018-10-08T17:08:06.709Z,1539018486.709 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 7923
2018-10-08T17:08:06.988Z,1539018486.988 [BPC1](INFO): BPC1A: validating data format.
2018-10-08T17:08:07.001Z,1539018487.001 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2018-10-08T17:08:07.001Z,1539018487.001 [WetLabsSeaOWL_UV_A](INFO): Powering down
2018-10-08T17:08:07.002Z,1539018487.002 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2018-10-08T17:08:07.013Z,1539018487.013 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2018-10-08T17:08:07.014Z,1539018487.014 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-10-08T17:08:07.015Z,1539018487.015 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 7924
2018-10-08T17:08:07.085Z,1539018487.085 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU.
2018-10-08T17:08:07.086Z,1539018487.086 [BPC1](INFO): BPC1A: got valid message (1824 bytes).
2018-10-08T17:08:07.361Z,1539018487.361 [BPC1](INFO): BPC1A: data parsed.
2018-10-08T17:08:07.377Z,1539018487.377 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2018-10-08T17:08:07.377Z,1539018487.377 [CTD_NeilBrown](INFO): Powering down
2018-10-08T17:08:07.378Z,1539018487.378 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-10-08T17:08:07.394Z,1539018487.394 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-10-08T17:08:07.394Z,1539018487.394 [logger ThreadHandler](INFO): Thread cancelled.
2018-10-08T17:08:07.394Z,1539018487.394 [logger](INFO): Join timeout helper Thread ID is 7925
2018-10-08T17:08:07.418Z,1539018487.418 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-10-08T17:08:07.419Z,1539018487.419 [logger ThreadHandler](INFO): Thread cancelled.
2018-10-08T17:08:07.430Z,1539018487.430 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-10-08T17:08:07.430Z,1539018487.430 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-10-08T17:08:07.430Z,1539018487.430 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-10-08T17:08:07.430Z,1539018487.430 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-10-08T17:08:07.430Z,1539018487.430 [controlThread](INFO): Join timeout helper Thread ID is 7926
2018-10-08T17:08:07.717Z,1539018487.717 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-10-08T17:08:07.717Z,1539018487.717 [controlThread](DEBUG): Uninitializing ControlThread
2018-10-08T17:08:07.718Z,1539018487.718 [Aanderaa_O2](INFO): Powering down
2018-10-08T17:08:07.719Z,1539018487.719 [AHRS_M2](INFO): Powering down
2018-10-08T17:08:07.790Z,1539018487.790 [NAL9602](INFO): Powering down
2018-10-08T17:08:07.861Z,1539018487.861 [RDI_Pathfinder](INFO): Powering down
2018-10-08T17:08:07.863Z,1539018487.863 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-10-08T17:08:07.864Z,1539018487.864 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2018-10-08T17:08:07.865Z,1539018487.865 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-10-08T17:08:07.865Z,1539018487.865 [MissionManager](INFO): Uninitializing Mission Default
2018-10-08T17:08:07.865Z,1539018487.865 [Default] Stopped
2018-10-08T17:08:07.866Z,1539018487.866 [Default](DEBUG): Aggregate::uninitialize Default
2018-10-08T17:08:07.866Z,1539018487.866 [Default:B.GoToSurface] Stopped
2018-10-08T17:08:07.866Z,1539018487.866 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-10-08T17:08:07.866Z,1539018487.866 [Default:CheckIn] Stopped
2018-10-08T17:08:07.866Z,1539018487.866 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-10-08T17:08:07.866Z,1539018487.866 [Default:CheckIn:Read_GPS] Stopped
2018-10-08T17:08:07.869Z,1539018487.869 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-10-08T17:08:07.870Z,1539018487.870 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-10-08T17:08:07.870Z,1539018487.870 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-10-08T17:08:07.870Z,1539018487.870 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-10-08T17:08:07.871Z,1539018487.871 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-10-08T17:08:07.871Z,1539018487.871 [BuoyancyServo](INFO): Powering down
2018-10-08T17:08:07.885Z,1539018487.885 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-10-08T17:08:07.885Z,1539018487.885 [ElevatorServo](INFO): Powering down
2018-10-08T17:08:07.886Z,1539018487.886 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-10-08T17:08:07.886Z,1539018487.886 [MassServo](INFO): Powering down
2018-10-08T17:08:07.887Z,1539018487.887 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-10-08T17:08:07.887Z,1539018487.887 [RudderServo](INFO): Powering down
2018-10-08T17:08:07.888Z,1539018487.888 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-10-08T17:08:07.888Z,1539018487.888 [ThrusterServo](INFO): Powering down
2018-10-08T17:08:07.889Z,1539018487.889 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-10-08T17:08:07.890Z,1539018487.890 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-10-08T17:08:07.890Z,1539018487.890 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-10-08T17:08:07.891Z,1539018487.891 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-10-08T17:08:07.954Z,1539018487.954 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2018-10-08T17:08:07.958Z,1539018487.958 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-10-08T17:08:08.016Z,1539018488.016 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-10-08T17:08:08.058Z,1539018488.058 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-10-08T17:08:08.115Z,1539018488.115 [logger ThreadHandler](INFO): Thread cancelled.