2019-03-23T05:25:42.429Z,1553318742.429 [Supervisor](DEBUG): Initializing supervisor. 2019-03-23T05:25:42.432Z,1553318742.432 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2019-03-23T05:25:42.433Z,1553318742.433 [SyncHandler](INFO): Protected caller Thread ID is 4255 2019-03-23T05:25:42.433Z,1553318742.433 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2019-03-23T05:25:42.434Z,1553318742.434 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2019-03-23T05:25:42.435Z,1553318742.435 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 4256 2019-03-23T05:25:42.438Z,1553318742.438 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2019-03-23T05:25:42.450Z,1553318742.450 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2019-03-23T05:25:42.451Z,1553318742.451 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2019-03-23T05:25:42.451Z,1553318742.451 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 4257 2019-03-23T05:25:42.452Z,1553318742.452 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2019-03-23T05:25:42.453Z,1553318742.453 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2019-03-23T05:25:42.453Z,1553318742.453 [logger ThreadHandler](INFO): Protected caller Thread ID is 4258 2019-03-23T05:25:42.455Z,1553318742.455 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2019-03-23T05:25:42.456Z,1553318742.456 [Supervisor](INFO): Looking for Config files in directory: Config/ 2019-03-23T05:25:42.457Z,1553318742.457 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2019-03-23T05:25:42.875Z,1553318742.875 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2019-03-23T05:25:42.876Z,1553318742.876 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2019-03-23T05:25:43.020Z,1553318743.020 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2019-03-23T05:25:43.021Z,1553318743.021 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2019-03-23T05:25:43.102Z,1553318743.102 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2019-03-23T05:25:43.201Z,1553318743.201 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2019-03-23T05:25:43.202Z,1553318743.202 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2019-03-23T05:25:43.298Z,1553318743.298 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2019-03-23T05:25:43.299Z,1553318743.299 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2019-03-23T05:25:43.694Z,1553318743.694 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2019-03-23T05:25:43.694Z,1553318743.694 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2019-03-23T05:25:43.836Z,1553318743.836 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2019-03-23T05:25:43.837Z,1553318743.837 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2019-03-23T05:25:44.349Z,1553318744.349 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2019-03-23T05:25:44.350Z,1553318744.350 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2019-03-23T05:25:44.551Z,1553318744.551 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2019-03-23T05:25:44.552Z,1553318744.552 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2019-03-23T05:25:44.857Z,1553318744.857 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2019-03-23T05:25:44.857Z,1553318744.857 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2019-03-23T05:25:45.070Z,1553318745.070 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2019-03-23T05:25:45.071Z,1553318745.071 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2019-03-23T05:25:45.213Z,1553318745.213 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2019-03-23T05:25:45.214Z,1553318745.214 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2019-03-23T05:25:45.705Z,1553318745.705 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2019-03-23T05:25:45.706Z,1553318745.706 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2019-03-23T05:25:46.040Z,1553318746.040 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2019-03-23T05:25:46.041Z,1553318746.041 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2019-03-23T05:25:46.247Z,1553318746.247 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2019-03-23T05:25:46.249Z,1553318746.249 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/ 2019-03-23T05:25:46.249Z,1553318746.249 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg 2019-03-23T05:25:46.430Z,1553318746.430 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg 2019-03-23T05:25:46.514Z,1553318746.514 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg 2019-03-23T05:25:46.630Z,1553318746.630 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg 2019-03-23T05:25:46.716Z,1553318746.716 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg 2019-03-23T05:25:46.942Z,1553318746.942 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2019-03-23T05:25:46.942Z,1553318746.942 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg 2019-03-23T05:25:47.042Z,1553318747.042 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg 2019-03-23T05:25:47.152Z,1553318747.152 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg 2019-03-23T05:25:47.247Z,1553318747.247 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg 2019-03-23T05:25:47.398Z,1553318747.398 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg 2019-03-23T05:25:47.500Z,1553318747.500 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg 2019-03-23T05:25:47.600Z,1553318747.600 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/root/ 2019-03-23T05:25:47.601Z,1553318747.601 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2019-03-23T05:25:47.610Z,1553318747.610 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2019-03-23T05:25:47.623Z,1553318747.623 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2019-03-23T05:25:47.624Z,1553318747.624 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2019-03-23T05:25:47.688Z,1553318747.688 [VerticalControl](DEBUG): Construct VerticalControl. 2019-03-23T05:25:47.799Z,1553318747.799 [VerticalControl] Loaded 2019-03-23T05:25:47.799Z,1553318747.799 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2019-03-23T05:25:47.800Z,1553318747.800 [HorizontalControl](DEBUG): Construct HorizontalControl. 2019-03-23T05:25:47.868Z,1553318747.868 [HorizontalControl] Loaded 2019-03-23T05:25:47.868Z,1553318747.868 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2019-03-23T05:25:47.869Z,1553318747.869 [SpeedControl](DEBUG): Construct SpeedControl. 2019-03-23T05:25:47.874Z,1553318747.874 [SpeedControl] Loaded 2019-03-23T05:25:47.875Z,1553318747.875 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2019-03-23T05:25:47.875Z,1553318747.875 [LoopControl](DEBUG): Construct LoopControl. 2019-03-23T05:25:47.876Z,1553318747.876 [LoopControl] Loaded 2019-03-23T05:25:47.876Z,1553318747.876 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2019-03-23T05:25:47.877Z,1553318747.877 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2019-03-23T05:25:47.877Z,1553318747.877 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2019-03-23T05:25:47.990Z,1553318747.990 [ElevatorServo] Loaded 2019-03-23T05:25:47.991Z,1553318747.991 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2019-03-23T05:25:48.001Z,1553318748.001 [MassServo] Loaded 2019-03-23T05:25:48.002Z,1553318748.002 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2019-03-23T05:25:48.013Z,1553318748.013 [ThrusterServo] Loaded 2019-03-23T05:25:48.013Z,1553318748.013 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2019-03-23T05:25:48.013Z,1553318748.013 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2019-03-23T05:25:48.014Z,1553318748.014 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2019-03-23T05:25:48.054Z,1553318748.054 [DepthRateCalculator] Loaded 2019-03-23T05:25:48.054Z,1553318748.054 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2019-03-23T05:25:48.059Z,1553318748.059 [PitchRateCalculator] Loaded 2019-03-23T05:25:48.059Z,1553318748.059 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2019-03-23T05:25:48.075Z,1553318748.075 [SpeedCalculator] Loaded 2019-03-23T05:25:48.075Z,1553318748.075 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2019-03-23T05:25:48.096Z,1553318748.096 [TempGradientCalculator] Loaded 2019-03-23T05:25:48.096Z,1553318748.096 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2019-03-23T05:25:48.101Z,1553318748.101 [YawRateCalculator] Loaded 2019-03-23T05:25:48.101Z,1553318748.101 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2019-03-23T05:25:48.130Z,1553318748.130 [ElevatorOffsetCalculator] Loaded 2019-03-23T05:25:48.130Z,1553318748.130 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2019-03-23T05:25:48.131Z,1553318748.131 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2019-03-23T05:25:48.131Z,1553318748.131 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2019-03-23T05:25:48.234Z,1553318748.234 [DeadReckonUsingMultipleVelocitySources] Loaded 2019-03-23T05:25:48.234Z,1553318748.234 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2019-03-23T05:25:48.292Z,1553318748.292 [DeadReckonUsingSpeedCalculator] Loaded 2019-03-23T05:25:48.292Z,1553318748.292 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2019-03-23T05:25:48.313Z,1553318748.313 [NavChart] Loaded 2019-03-23T05:25:48.313Z,1553318748.313 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2019-03-23T05:25:48.317Z,1553318748.317 [UniversalFixResidualReporter] Loaded 2019-03-23T05:25:48.317Z,1553318748.317 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2019-03-23T05:25:48.318Z,1553318748.318 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2019-03-23T05:25:48.318Z,1553318748.318 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2019-03-23T05:25:48.635Z,1553318748.635 [DataOverHttps] Loaded 2019-03-23T05:25:48.635Z,1553318748.635 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2019-03-23T05:25:48.636Z,1553318748.636 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408004E0 2019-03-23T05:25:48.636Z,1553318748.636 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 4337 2019-03-23T05:25:48.649Z,1553318748.649 [Depth_Keller] Loaded 2019-03-23T05:25:48.650Z,1553318748.650 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2019-03-23T05:25:48.745Z,1553318748.745 [NAL9602] Loaded 2019-03-23T05:25:48.745Z,1553318748.745 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2019-03-23T05:25:48.760Z,1553318748.760 [Onboard] Loaded 2019-03-23T05:25:48.761Z,1553318748.761 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2019-03-23T05:25:48.764Z,1553318748.764 [Radio_Surface] Loaded 2019-03-23T05:25:48.764Z,1553318748.764 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2019-03-23T05:25:48.765Z,1553318748.765 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408304E0 2019-03-23T05:25:48.765Z,1553318748.765 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 4338 2019-03-23T05:25:48.790Z,1553318748.790 [BPC1](INFO): BPC1A: got serial number for stick 1: 023F 2019-03-23T05:25:48.791Z,1553318748.791 [BPC1](INFO): BPC1A: got serial number for stick 2: 02A8 2019-03-23T05:25:48.792Z,1553318748.792 [BPC1](INFO): BPC1A: got serial number for stick 3: 01D7 2019-03-23T05:25:48.793Z,1553318748.793 [BPC1](INFO): BPC1A: got serial number for stick 4: 01EF 2019-03-23T05:25:48.794Z,1553318748.794 [BPC1](INFO): BPC1A: got serial number for stick 5: 0299 2019-03-23T05:25:48.795Z,1553318748.795 [BPC1](INFO): BPC1A: got serial number for stick 6: 0292 2019-03-23T05:25:48.795Z,1553318748.795 [BPC1](INFO): BPC1A: got serial number for stick 7: 0296 2019-03-23T05:25:48.796Z,1553318748.796 [BPC1](INFO): BPC1A: got serial number for stick 8: 0291 2019-03-23T05:25:48.796Z,1553318748.796 [BPC1](INFO): BPC1A: marked stick 8 as reserve. 2019-03-23T05:25:48.797Z,1553318748.797 [BPC1](INFO): BPC1A: got serial number for stick 9: 00BB 2019-03-23T05:25:48.798Z,1553318748.798 [BPC1](INFO): BPC1A: got serial number for stick 10: 025B 2019-03-23T05:25:48.799Z,1553318748.799 [BPC1](INFO): BPC1A: got serial number for stick 11: 024E 2019-03-23T05:25:48.799Z,1553318748.799 [BPC1](INFO): BPC1A: got serial number for stick 12: 029C 2019-03-23T05:25:48.800Z,1553318748.800 [BPC1](INFO): BPC1A: got serial number for stick 13: 0242 2019-03-23T05:25:48.801Z,1553318748.801 [BPC1](INFO): BPC1A: got serial number for stick 14: 01FA 2019-03-23T05:25:48.802Z,1553318748.802 [BPC1](INFO): BPC1A: got serial number for stick 15: 0269 2019-03-23T05:25:48.802Z,1553318748.802 [BPC1](INFO): BPC1A: got serial number for stick 16: 02AD 2019-03-23T05:25:48.803Z,1553318748.803 [BPC1](INFO): BPC1A: marked stick 16 as reserve. 2019-03-23T05:25:48.804Z,1553318748.804 [BPC1](INFO): BPC1A: got serial number for stick 17: 0295 2019-03-23T05:25:48.805Z,1553318748.805 [BPC1](INFO): BPC1A: got serial number for stick 18: 0224 2019-03-23T05:25:48.806Z,1553318748.806 [BPC1](INFO): BPC1A: got serial number for stick 19: 00F6 2019-03-23T05:25:48.806Z,1553318748.806 [BPC1](INFO): BPC1A: got serial number for stick 20: 0294 2019-03-23T05:25:48.807Z,1553318748.807 [BPC1](INFO): BPC1A: got serial number for stick 21: 0271 2019-03-23T05:25:48.808Z,1553318748.808 [BPC1](INFO): BPC1A: got serial number for stick 22: 0206 2019-03-23T05:25:48.809Z,1553318748.809 [BPC1](INFO): BPC1A: got serial number for stick 23: 02B0 2019-03-23T05:25:48.809Z,1553318748.809 [BPC1](INFO): BPC1A: got serial number for stick 24: 020C 2019-03-23T05:25:48.810Z,1553318748.810 [BPC1](INFO): BPC1A: marked stick 24 as reserve. 2019-03-23T05:25:48.810Z,1553318748.810 [BPC1](INFO): BPC1A: got serial number for stick 25: 016F 2019-03-23T05:25:48.811Z,1553318748.811 [BPC1](INFO): BPC1A: got serial number for stick 26: 026A 2019-03-23T05:25:48.812Z,1553318748.812 [BPC1](INFO): BPC1A: got serial number for stick 27: 01C6 2019-03-23T05:25:48.813Z,1553318748.813 [BPC1](INFO): BPC1A: got serial number for stick 28: 0246 2019-03-23T05:25:48.813Z,1553318748.813 [BPC1](INFO): BPC1A: got serial number for stick 29: 02D3 2019-03-23T05:25:48.814Z,1553318748.814 [BPC1](INFO): BPC1A: got serial number for stick 30: 01C0 2019-03-23T05:25:48.815Z,1553318748.815 [BPC1](INFO): BPC1A: got serial number for stick 31: 01F3 2019-03-23T05:25:48.816Z,1553318748.816 [BPC1](INFO): BPC1B: got serial number for stick 32: 0163 2019-03-23T05:25:48.817Z,1553318748.817 [BPC1](INFO): BPC1B: got serial number for stick 33: 01AA 2019-03-23T05:25:48.818Z,1553318748.818 [BPC1](INFO): BPC1B: got serial number for stick 34: 0197 2019-03-23T05:25:48.819Z,1553318748.819 [BPC1](INFO): BPC1B: got serial number for stick 35: 0215 2019-03-23T05:25:48.819Z,1553318748.819 [BPC1](INFO): BPC1B: got serial number for stick 36: 020E 2019-03-23T05:25:48.820Z,1553318748.820 [BPC1](INFO): BPC1B: got serial number for stick 37: 0228 2019-03-23T05:25:48.821Z,1553318748.821 [BPC1](INFO): BPC1B: got serial number for stick 38: 02B4 2019-03-23T05:25:48.822Z,1553318748.822 [BPC1](INFO): BPC1B: got serial number for stick 39: 01AC 2019-03-23T05:25:48.822Z,1553318748.822 [BPC1](INFO): BPC1B: marked stick 39 as reserve. 2019-03-23T05:25:48.823Z,1553318748.823 [BPC1](INFO): BPC1B: got serial number for stick 40: 022A 2019-03-23T05:25:48.824Z,1553318748.824 [BPC1](INFO): BPC1B: got serial number for stick 41: 0232 2019-03-23T05:25:48.825Z,1553318748.825 [BPC1](INFO): BPC1B: got serial number for stick 42: 0219 2019-03-23T05:25:48.825Z,1553318748.825 [BPC1](INFO): BPC1B: got serial number for stick 43: 0229 2019-03-23T05:25:48.826Z,1553318748.826 [BPC1](INFO): BPC1B: got serial number for stick 44: 0253 2019-03-23T05:25:48.827Z,1553318748.827 [BPC1](INFO): BPC1B: got serial number for stick 45: 02A1 2019-03-23T05:25:48.828Z,1553318748.828 [BPC1](INFO): BPC1B: got serial number for stick 46: 028A 2019-03-23T05:25:48.828Z,1553318748.828 [BPC1](INFO): BPC1B: got serial number for stick 47: 019A 2019-03-23T05:25:48.829Z,1553318748.829 [BPC1](INFO): BPC1B: marked stick 47 as reserve. 2019-03-23T05:25:48.829Z,1553318748.829 [BPC1](INFO): BPC1B: got serial number for stick 48: 0202 2019-03-23T05:25:48.831Z,1553318748.831 [BPC1](INFO): BPC1B: got serial number for stick 49: 027C 2019-03-23T05:25:48.831Z,1553318748.831 [BPC1](INFO): BPC1B: got serial number for stick 50: 022F 2019-03-23T05:25:48.832Z,1553318748.832 [BPC1](INFO): BPC1B: got serial number for stick 51: 01FF 2019-03-23T05:25:48.833Z,1553318748.833 [BPC1](INFO): BPC1B: got serial number for stick 52: 0203 2019-03-23T05:25:48.834Z,1553318748.834 [BPC1](INFO): BPC1B: got serial number for stick 53: 02A6 2019-03-23T05:25:48.834Z,1553318748.834 [BPC1](INFO): BPC1B: got serial number for stick 54: 01D4 2019-03-23T05:25:48.835Z,1553318748.835 [BPC1](INFO): BPC1B: got serial number for stick 55: 017F 2019-03-23T05:25:48.835Z,1553318748.835 [BPC1](INFO): BPC1B: marked stick 55 as reserve. 2019-03-23T05:25:48.836Z,1553318748.836 [BPC1](INFO): BPC1B: got serial number for stick 56: 021D 2019-03-23T05:25:48.837Z,1553318748.837 [BPC1](INFO): BPC1B: got serial number for stick 57: 01BF 2019-03-23T05:25:48.838Z,1553318748.838 [BPC1](INFO): BPC1B: got serial number for stick 58: 0216 2019-03-23T05:25:48.838Z,1553318748.838 [BPC1](INFO): BPC1B: got serial number for stick 59: 024A 2019-03-23T05:25:48.839Z,1553318748.839 [BPC1](INFO): BPC1B: got serial number for stick 60: 01DA 2019-03-23T05:25:48.840Z,1553318748.840 [BPC1](INFO): BPC1B: got serial number for stick 61: 01DF 2019-03-23T05:25:48.841Z,1553318748.841 [BPC1](INFO): BPC1B: got serial number for stick 62: 0205 2019-03-23T05:25:50.249Z,1553318750.249 [BPC1] Loaded 2019-03-23T05:25:50.250Z,1553318750.250 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2019-03-23T05:25:50.250Z,1553318750.250 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2019-03-23T05:25:50.251Z,1553318750.251 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2019-03-23T05:25:50.450Z,1553318750.450 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2019-03-23T05:25:50.450Z,1553318750.450 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2019-03-23T05:25:50.712Z,1553318750.712 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2019-03-23T05:25:50.713Z,1553318750.713 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2019-03-23T05:25:50.796Z,1553318750.796 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2019-03-23T05:25:50.797Z,1553318750.797 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2019-03-23T05:25:51.261Z,1553318751.261 [CTD_NeilBrown] Loaded 2019-03-23T05:25:51.261Z,1553318751.261 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2019-03-23T05:25:51.262Z,1553318751.262 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 409BD4E0 2019-03-23T05:25:51.262Z,1553318751.262 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 4339 2019-03-23T05:25:51.310Z,1553318751.310 [WetLabsBB2FL] Loaded 2019-03-23T05:25:51.310Z,1553318751.310 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2019-03-23T05:25:51.311Z,1553318751.311 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409ED4E0 2019-03-23T05:25:51.311Z,1553318751.311 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 4340 2019-03-23T05:25:51.312Z,1553318751.312 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2019-03-23T05:25:51.313Z,1553318751.313 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2019-03-23T05:25:51.574Z,1553318751.574 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2019-03-23T05:25:51.575Z,1553318751.575 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2019-03-23T05:25:51.703Z,1553318751.703 [SBIT](DEBUG): Construct Startup Built In Test. 2019-03-23T05:25:51.714Z,1553318751.714 [SBIT] Loaded 2019-03-23T05:25:51.715Z,1553318751.715 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2019-03-23T05:25:51.715Z,1553318751.715 [IBIT](DEBUG): Construct Initiated Built In Test. 2019-03-23T05:25:51.727Z,1553318751.727 [IBIT] Loaded 2019-03-23T05:25:51.727Z,1553318751.727 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2019-03-23T05:25:51.730Z,1553318751.730 [CBIT](DEBUG): Construct Continuous Built In Test. 2019-03-23T05:25:51.868Z,1553318751.868 [CBIT] Loaded 2019-03-23T05:25:51.868Z,1553318751.868 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2019-03-23T05:25:51.869Z,1553318751.869 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2019-03-23T05:25:51.872Z,1553318751.872 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2019-03-23T05:25:51.873Z,1553318751.873 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2019-03-23T05:25:51.880Z,1553318751.880 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2019-03-23T05:25:51.881Z,1553318751.881 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AC54E0 2019-03-23T05:25:51.881Z,1553318751.881 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 4341 2019-03-23T05:25:51.886Z,1553318751.886 [Supervisor](INFO): Main Thread ID is 4136 2019-03-23T05:25:51.886Z,1553318751.886 [Supervisor](DEBUG): Running supervisor. 2019-03-23T05:25:51.887Z,1553318751.887 [CommandLine ThreadHandler](INFO): Handler Thread ID is 4342 2019-03-23T05:25:51.889Z,1553318751.889 [controlThread ThreadHandler](INFO): Handler Thread ID is 4343 2019-03-23T05:25:51.889Z,1553318751.889 [controlThread](DEBUG): Initializing ControlThread 2019-03-23T05:25:51.890Z,1553318751.890 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2019-03-23T05:25:51.892Z,1553318751.892 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2019-03-23T05:25:51.892Z,1553318751.892 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2019-03-23T05:25:51.893Z,1553318751.893 [LoopControl](DEBUG): Initialize LoopControlComponent. 2019-03-23T05:25:51.894Z,1553318751.894 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2019-03-23T05:25:51.894Z,1553318751.894 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2019-03-23T05:25:51.895Z,1553318751.895 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2019-03-23T05:25:51.895Z,1553318751.895 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2019-03-23T05:25:51.895Z,1553318751.895 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2019-03-23T05:25:51.896Z,1553318751.896 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2019-03-23T05:25:51.897Z,1553318751.897 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2019-03-23T05:25:51.897Z,1553318751.897 [NavChart](DEBUG): Initialize NavChart Navigation. 2019-03-23T05:25:51.898Z,1553318751.898 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2019-03-23T05:25:51.902Z,1553318751.902 [SBIT](INFO): Initialize SBIT Component. 2019-03-23T05:25:51.902Z,1553318751.902 [SBIT](IMPORTANT): git: 2019-03-18-18-g6cf6cc5 2019-03-23T05:25:51.903Z,1553318751.903 [SBIT](INFO): git hash: 6cf6cc5c1826bb1f8f9a0dab23a9d4b1019792a5 2019-03-23T05:25:51.903Z,1553318751.903 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2019-03-23T05:25:51.904Z,1553318751.904 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 Kernel Reported: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018 2019-03-23T05:25:51.905Z,1553318751.905 [SBIT](INFO): Beginning SBIT in 28.000000 seconds. 2019-03-23T05:25:51.906Z,1553318751.906 [IBIT](INFO): Initialize IBIT Component. 2019-03-23T05:25:51.906Z,1553318751.906 [CBIT](DEBUG): Initialize CBIT Component. 2019-03-23T05:25:51.907Z,1553318751.907 [logger ThreadHandler](INFO): Handler Thread ID is 4344 2019-03-23T05:25:51.921Z,1553318751.921 [CBIT](DEBUG): Initialized mux pins. 2019-03-23T05:25:51.921Z,1553318751.921 [CBIT](DEBUG): Initializing the watchdog timer. 2019-03-23T05:25:51.925Z,1553318751.925 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 4345 2019-03-23T05:25:51.926Z,1553318751.926 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2019-03-23T05:25:51.933Z,1553318751.933 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 4346 2019-03-23T05:25:51.941Z,1553318751.941 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 4347 2019-03-23T05:25:51.945Z,1553318751.945 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2019-03-23T05:25:51.945Z,1553318751.945 [CBIT](DEBUG): Initializing heartbeat. 2019-03-23T05:25:51.953Z,1553318751.953 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 4348 2019-03-23T05:25:51.954Z,1553318751.954 [WetLabsBB2FL](INFO): Powering down 2019-03-23T05:25:51.981Z,1553318751.981 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 4349 2019-03-23T05:25:51.984Z,1553318751.984 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2019-03-23T05:25:51.985Z,1553318751.985 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2019-03-23T05:25:51.985Z,1553318751.985 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2019-03-23T05:25:51.985Z,1553318751.985 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2019-03-23T05:25:51.985Z,1553318751.986 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2019-03-23T05:25:51.986Z,1553318751.986 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2019-03-23T05:25:51.986Z,1553318751.986 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2019-03-23T05:25:51.986Z,1553318751.986 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2019-03-23T05:25:51.986Z,1553318751.986 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2019-03-23T05:25:51.986Z,1553318751.986 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2019-03-23T05:25:51.987Z,1553318751.987 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2019-03-23T05:25:51.987Z,1553318751.987 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2019-03-23T05:25:51.987Z,1553318751.987 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2019-03-23T05:25:51.987Z,1553318751.987 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2019-03-23T05:25:51.988Z,1553318751.988 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2019-03-23T05:25:51.988Z,1553318751.988 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2019-03-23T05:25:52.017Z,1553318752.017 [CBIT](DEBUG): Deactivating GF circuits. 2019-03-23T05:25:52.017Z,1553318752.017 [CBIT](DEBUG): Deactivating emergency mode. 2019-03-23T05:25:52.053Z,1553318752.053 [CBIT](DEBUG): Backplane powered. 2019-03-23T05:25:52.054Z,1553318752.054 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2019-03-23T05:25:52.063Z,1553318752.063 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2019-03-23T05:25:52.074Z,1553318752.074 [MissionManager](DEBUG): 2019-03-23T05:25:52.075Z,1553318752.075 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2019-03-23T05:25:52.147Z,1553318752.147 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2019-03-23T05:25:52.148Z,1553318752.148 [Default:A.Wait](DEBUG): Construct Wait. 2019-03-23T05:25:52.150Z,1553318752.150 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2019-03-23T05:25:52.193Z,1553318752.193 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2019-03-23T05:25:52.195Z,1553318752.195 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2019-03-23T05:25:52.217Z,1553318752.217 [Default:E.Execute](DEBUG): Construct Execute. 2019-03-23T05:25:52.220Z,1553318752.220 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2019-03-23T05:25:52.237Z,1553318752.237 [controlThread](DEBUG): Component order: CycleStarter,Depth_Keller,NAL9602,Onboard,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,ElevatorServo,MassServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2019-03-23T05:25:52.258Z,1553318752.258 [Depth_Keller](ERROR): Pressure reading out of range: 1925.893799 decibar 2019-03-23T05:25:52.305Z,1553318752.305 [DepthRateCalculator](ERROR): Depth measurement is not active 2019-03-23T05:25:52.332Z,1553318752.332 [ElevatorServo](DEBUG): Initializing EZServoServo. 2019-03-23T05:25:52.333Z,1553318752.333 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2019-03-23T05:25:52.334Z,1553318752.334 [MassServo](DEBUG): Initializing EZServoServo. 2019-03-23T05:25:52.337Z,1553318752.337 [Radio_Surface](INFO): Powering up 2019-03-23T05:25:52.341Z,1553318752.341 [MassServo](DEBUG): Initializing MassServo. 2019-03-23T05:25:52.342Z,1553318752.342 [ThrusterServo](DEBUG): Initializing EZServoServo. 2019-03-23T05:25:52.353Z,1553318752.353 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2019-03-23T05:26:18.910Z,1553318778.910 [NAL9602](INFO): Powering up NAL9602 2019-03-23T05:26:20.550Z,1553318780.550 [SBIT](IMPORTANT): Beginning Startup BIT 2019-03-23T05:26:20.554Z,1553318780.554 [CBIT](IMPORTANT): Beginning ground fault scan 2019-03-23T05:26:29.874Z,1553318789.874 [NAL9602](INFO): NAL9602 initialized 2019-03-23T05:26:30.693Z,1553318790.693 [NAL9602](DEBUG): Fix Requested 2019-03-23T05:26:31.601Z,1553318791.601 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.021340 CHAN A1 (24V): 0.002410 CHAN A2 (12V): -0.067959 CHAN A3 (5V): -0.003101 CHAN B0 (3.3V): -0.001323 CHAN B1 (3.15aV): -0.001020 CHAN B2 (3.15bV): -0.000714 CHAN B3 (GND): -0.000486 OPEN: -0.001148 Full Scale Calc: 4.765 mA, -1.589 mA 2019-03-23T05:26:33.666Z,1553318793.666 [SBIT](ERROR): Could not read rudderAngleReader_. 2019-03-23T05:26:53.437Z,1553318813.437 [BPC1](INFO): BPC1A: initialized. 2019-03-23T05:26:53.833Z,1553318813.833 [BPC1](INFO): BPC1B: initialized. 2019-03-23T05:26:55.424Z,1553318815.424 [BPC1](INFO): BPC1B: sending IBPS break. 2019-03-23T05:26:58.671Z,1553318818.671 [BPC1](INFO): BPC1B: validating data format. 2019-03-23T05:26:58.685Z,1553318818.685 [BPC1](INFO): BPC1B: got 6 stick msg (1368 bytes) with LONG_IBPS_MENU. 2019-03-23T05:26:58.685Z,1553318818.685 [BPC1](INFO): BPC1B: got valid message (1368 bytes). 2019-03-23T05:26:59.076Z,1553318819.076 [BPC1](INFO): BPC1B: data parsed. 2019-03-23T05:26:59.893Z,1553318819.893 [BPC1](INFO): BPC1B: initialized. 2019-03-23T05:27:00.290Z,1553318820.290 [SBIT](ERROR): Could not read rudderAngleReader_. 2019-03-23T05:27:00.290Z,1553318820.290 [SBIT](FAULT): Control surface position failure. 2019-03-23T05:27:00.682Z,1553318820.682 [BPC1](INFO): BPC1A: sending IBPS break. 2019-03-23T05:27:05.574Z,1553318825.574 [BPC1](INFO): BPC1A: validating data format. 2019-03-23T05:27:05.634Z,1553318825.634 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with LONG_IBPS_MENU. 2019-03-23T05:27:05.634Z,1553318825.634 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2019-03-23T05:27:05.979Z,1553318825.979 [BPC1](INFO): BPC1A: data parsed. 2019-03-23T05:27:06.793Z,1553318826.793 [BPC1](INFO): BPC1A: initialized. 2019-03-23T05:27:07.589Z,1553318827.589 [BPC1](INFO): BPC1B: sending IBPS break. 2019-03-23T05:27:11.225Z,1553318831.225 [BPC1](INFO): BPC1B: validating data format. 2019-03-23T05:27:11.317Z,1553318831.317 [BPC1](INFO): BPC1B: got 6 stick msg (1368 bytes) with SHORT_IBPS_MENU. 2019-03-23T05:27:11.317Z,1553318831.317 [BPC1](INFO): BPC1B: got valid message (1368 bytes). 2019-03-23T05:27:11.626Z,1553318831.626 [BPC1](INFO): BPC1B: data parsed. 2019-03-23T05:27:12.853Z,1553318832.853 [BPC1](INFO): BPC1B: initialized. 2019-03-23T05:27:14.063Z,1553318834.063 [BPC1](INFO): BPC1A: sending IBPS break. 2019-03-23T05:27:14.073Z,1553318834.073 [SBIT](ERROR): Could not read rudderAngleReader_. 2019-03-23T05:27:14.073Z,1553318834.073 [SBIT](FAULT): Control surface position failure. 2019-03-23T05:27:14.478Z,1553318834.478 [SBIT](CRITICAL): SBIT FAILED 2019-03-23T05:27:14.493Z,1553318834.493 [CommandLine](FAULT): Scheduling is paused 2019-03-23T05:27:14.494Z,1553318834.494 [CBIT](INFO): Critical error at 20190323T052714 2019-03-23T05:27:14.494Z,1553318834.494 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2019-03-23T05:27:14.514Z,1553318834.514 [CommandLine](IMPORTANT): got command configSet list 2019-03-23T05:27:14.514Z,1553318834.514 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2019-03-23T05:27:14.515Z,1553318834.515 [CommandLine](IMPORTANT): AHRS_M2.loadAtStartup=0 bool; 2019-03-23T05:27:14.515Z,1553318834.515 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=10 minute; 2019-03-23T05:27:14.515Z,1553318834.515 [CommandLine](IMPORTANT): BuoyancyServo.loadAtStartup=0 bool; 2019-03-23T05:27:14.515Z,1553318834.515 [CommandLine](IMPORTANT): CBIT.vehicleOpen=1 bool; 2019-03-23T05:27:14.515Z,1553318834.515 [CommandLine](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool; 2019-03-23T05:27:14.516Z,1553318834.516 [CommandLine](IMPORTANT): Depth_Keller.offset=-0.13 decibar; 2019-03-23T05:27:14.516Z,1553318834.516 [CommandLine](IMPORTANT): Depth_Keller.scale=45.92 micropascal; 2019-03-23T05:27:14.516Z,1553318834.516 [CommandLine](IMPORTANT): DropWeight.loadAtStartup=0 bool; 2019-03-23T05:27:14.516Z,1553318834.516 [CommandLine](IMPORTANT): RudderServo.loadAtStartup=0 bool; 2019-03-23T05:27:14.877Z,1553318834.877 [MissionManager](IMPORTANT): Started mission Startup 2019-03-23T05:27:14.878Z,1553318834.878 [Startup] Running Loop=1 2019-03-23T05:27:14.878Z,1553318834.878 [Startup](DEBUG): Aggregate::initialize Startup 2019-03-23T05:27:14.878Z,1553318834.878 [Startup:A.GoToSurface] Running Loop=1 2019-03-23T05:27:14.878Z,1553318834.878 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-03-23T05:27:14.879Z,1553318834.879 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-03-23T05:27:14.879Z,1553318834.879 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-03-23T05:27:14.879Z,1553318834.879 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-03-23T05:27:14.880Z,1553318834.880 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-03-23T05:27:14.880Z,1553318834.880 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-03-23T05:27:14.882Z,1553318834.882 [Startup:StartupSatComms] Running Loop=1 2019-03-23T05:27:14.882Z,1553318834.882 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2019-03-23T05:27:14.882Z,1553318834.882 [Startup:StartupSatComms:A] Running Loop=1 2019-03-23T05:27:15.282Z,1553318835.282 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2019-03-23T05:27:18.896Z,1553318838.896 [BPC1](INFO): BPC1A: validating data format. 2019-03-23T05:27:18.955Z,1553318838.955 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2019-03-23T05:27:18.955Z,1553318838.955 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2019-03-23T05:27:19.318Z,1553318839.318 [BPC1](INFO): BPC1A: data parsed. 2019-03-23T05:27:20.137Z,1553318840.137 [BPC1](INFO): BPC1A: initialized. 2019-03-23T05:27:20.920Z,1553318840.920 [BPC1](INFO): BPC1B: sending IBPS break. 2019-03-23T05:27:24.567Z,1553318844.567 [BPC1](INFO): BPC1B: validating data format. 2019-03-23T05:27:24.619Z,1553318844.619 [BPC1](INFO): BPC1B: got 6 stick msg (1368 bytes) with LONG_IBPS_MENU. 2019-03-23T05:27:24.619Z,1553318844.619 [BPC1](INFO): BPC1B: got valid message (1368 bytes). 2019-03-23T05:27:24.972Z,1553318844.972 [BPC1](INFO): BPC1B: data parsed. 2019-03-23T05:27:25.793Z,1553318845.793 [BPC1](INFO): BPC1B: initialized. 2019-03-23T05:27:27.385Z,1553318847.385 [BPC1](INFO): BPC1A: sending IBPS break. 2019-03-23T05:27:32.233Z,1553318852.233 [BPC1](INFO): BPC1A: validating data format. 2019-03-23T05:27:32.293Z,1553318852.293 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with LONG_IBPS_MENU. 2019-03-23T05:27:32.293Z,1553318852.293 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2019-03-23T05:27:32.643Z,1553318852.643 [BPC1](INFO): BPC1A: data parsed. 2019-03-23T05:27:33.457Z,1553318853.457 [BPC1](INFO): BPC1A: initialized. 2019-03-23T05:27:33.457Z,1553318853.457 [BPC1](INFO): BPC1B: sending IBPS break. 2019-03-23T05:27:37.081Z,1553318857.081 [BPC1](INFO): BPC1B: validating data format. 2019-03-23T05:27:37.135Z,1553318857.135 [BPC1](INFO): BPC1B: got 6 stick msg (1368 bytes) with SHORT_IBPS_MENU. 2019-03-23T05:27:37.136Z,1553318857.136 [BPC1](INFO): BPC1B: got valid message (1368 bytes). 2019-03-23T05:27:37.486Z,1553318857.486 [BPC1](INFO): BPC1B: data parsed. 2019-03-23T05:27:38.709Z,1553318858.709 [BPC1](INFO): BPC1B: initialized. 2019-03-23T05:27:40.727Z,1553318860.727 [BPC1](INFO): BPC1A: sending IBPS break. 2019-03-23T05:27:45.575Z,1553318865.575 [BPC1](INFO): BPC1A: validating data format. 2019-03-23T05:27:45.644Z,1553318865.644 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2019-03-23T05:27:45.645Z,1553318865.645 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2019-03-23T05:27:45.982Z,1553318865.982 [BPC1](INFO): BPC1A: data parsed. 2019-03-23T05:27:46.801Z,1553318866.801 [BPC1](INFO): BPC1A: initialized. 2019-03-23T05:27:46.801Z,1553318866.801 [BPC1](INFO): BPC1B: sending IBPS break. 2019-03-23T05:27:50.416Z,1553318870.416 [BPC1](INFO): BPC1B: validating data format. 2019-03-23T05:27:50.461Z,1553318870.461 [BPC1](INFO): BPC1B: got 6 stick msg (1368 bytes) with LONG_IBPS_MENU. 2019-03-23T05:27:50.461Z,1553318870.461 [BPC1](INFO): BPC1B: got valid message (1368 bytes). 2019-03-23T05:27:50.836Z,1553318870.836 [BPC1](INFO): BPC1B: data parsed. 2019-03-23T05:27:51.649Z,1553318871.649 [BPC1](INFO): BPC1B: initialized. 2019-03-23T05:27:52.048Z,1553318872.048 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-03-23T05:27:52.048Z,1553318872.048 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2019-03-23T05:27:52.048Z,1553318872.048 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-03-23T05:27:52.050Z,1553318872.050 [DeadReckonUsingSpeedCalculator](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-03-23T05:27:52.050Z,1553318872.050 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1 2019-03-23T05:27:52.050Z,1553318872.050 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2019-03-23T05:27:52.060Z,1553318872.060 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-03-23T05:27:52.060Z,1553318872.060 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2019-03-23T05:27:52.448Z,1553318872.448 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-03-23T05:27:52.448Z,1553318872.448 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2019-03-23T05:27:52.449Z,1553318872.449 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2019-03-23T05:27:52.449Z,1553318872.449 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1 2019-03-23T05:27:52.840Z,1553318872.840 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2019-03-23T05:27:54.452Z,1553318874.452 [BPC1](INFO): BPC1A: sending IBPS break. 2019-03-23T05:27:58.897Z,1553318878.897 [BPC1](INFO): BPC1A: validating data format. 2019-03-23T05:27:58.969Z,1553318878.969 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with LONG_IBPS_MENU. 2019-03-23T05:27:58.969Z,1553318878.969 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2019-03-23T05:27:59.304Z,1553318879.304 [BPC1](INFO): BPC1A: data parsed. 2019-03-23T05:27:59.304Z,1553318879.304 [BPC1](INFO): BPC1B: sending IBPS break. 2019-03-23T05:28:00.529Z,1553318880.529 [BPC1](INFO): BPC1A: initialized. 2019-03-23T05:28:02.937Z,1553318882.937 [BPC1](INFO): BPC1B: validating data format. 2019-03-23T05:28:02.979Z,1553318882.979 [BPC1](INFO): BPC1B: got 6 stick msg (1368 bytes) with SHORT_IBPS_MENU. 2019-03-23T05:28:02.979Z,1553318882.979 [BPC1](INFO): BPC1B: got valid message (1368 bytes). 2019-03-23T05:28:03.341Z,1553318883.341 [BPC1](INFO): BPC1B: data parsed. 2019-03-23T05:28:04.165Z,1553318884.165 [BPC1](INFO): BPC1B: initialized. 2019-03-23T05:28:07.799Z,1553318887.799 [BPC1](INFO): BPC1A: sending IBPS break. 2019-03-23T05:28:11.835Z,1553318891.835 [BPC1](INFO): BPC1B: sending IBPS break. 2019-03-23T05:28:12.647Z,1553318892.647 [BPC1](INFO): BPC1A: validating data format. 2019-03-23T05:28:12.719Z,1553318892.719 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2019-03-23T05:28:12.720Z,1553318892.720 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2019-03-23T05:28:13.049Z,1553318893.049 [BPC1](INFO): BPC1A: data parsed. 2019-03-23T05:28:13.857Z,1553318893.857 [BPC1](INFO): BPC1A: initialized. 2019-03-23T05:28:15.062Z,1553318895.062 [Startup:StartupSatComms:A](INFO): Timed out from 2019-03-23T05:27:14.9Z 2019-03-23T05:28:15.062Z,1553318895.062 [Startup:StartupSatComms:A] Stopped 2019-03-23T05:28:15.062Z,1553318895.062 [Startup:StartupSatComms:B] Running Loop=1 2019-03-23T05:28:15.457Z,1553318895.457 [BPC1](INFO): BPC1B: validating data format. 2019-03-23T05:28:15.544Z,1553318895.544 [BPC1](INFO): BPC1B: got 6 stick msg (1368 bytes) with LONG_IBPS_MENU. 2019-03-23T05:28:15.544Z,1553318895.544 [BPC1](INFO): BPC1B: got valid message (1368 bytes). 2019-03-23T05:28:15.571Z,1553318895.571 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-03-23T05:28:16.038Z,1553318896.038 [BPC1](INFO): BPC1B: data parsed. 2019-03-23T05:28:16.861Z,1553318896.861 [BPC1](INFO): BPC1B: initialized. 2019-03-23T05:28:18.738Z,1553318898.738 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004459 2019-03-23T05:28:21.277Z,1553318901.277 [BPC1](INFO): BPC1A: sending IBPS break. 2019-03-23T05:28:23.444Z,1553318903.444 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190323T051057/Courier0004.lzma 2019-03-23T05:28:24.109Z,1553318904.109 [BPC1](INFO): BPC1B: sending IBPS break. 2019-03-23T05:28:24.250Z,1553318904.250 [DataOverHttps](INFO): Moved sent file to Logs/20190323T051057/Courier0004.lzma.bak 2019-03-23T05:28:24.250Z,1553318904.250 [DataOverHttps](INFO): SBD MOMSN=10219511 2019-03-23T05:28:26.122Z,1553318906.122 [BPC1](INFO): BPC1A: validating data format. 2019-03-23T05:28:26.249Z,1553318906.249 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with LONG_IBPS_MENU. 2019-03-23T05:28:26.250Z,1553318906.250 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2019-03-23T05:28:26.539Z,1553318906.539 [BPC1](INFO): BPC1A: data parsed. 2019-03-23T05:28:27.365Z,1553318907.365 [BPC1](INFO): BPC1A: initialized. 2019-03-23T05:28:27.748Z,1553318907.748 [BPC1](INFO): BPC1B: validating data format. 2019-03-23T05:28:27.828Z,1553318907.828 [BPC1](INFO): BPC1B: got 6 stick msg (1368 bytes) with SHORT_IBPS_MENU. 2019-03-23T05:28:27.829Z,1553318907.829 [BPC1](INFO): BPC1B: got valid message (1368 bytes). 2019-03-23T05:28:28.160Z,1553318908.160 [BPC1](INFO): BPC1B: data parsed. 2019-03-23T05:28:28.965Z,1553318908.965 [BPC1](INFO): BPC1B: initialized. 2019-03-23T05:28:34.609Z,1553318914.609 [BPC1](INFO): BPC1A: sending IBPS break. 2019-03-23T05:28:34.664Z,1553318914.664 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20190323T052354/Courier0000.lzma 2019-03-23T05:28:35.470Z,1553318915.470 [DataOverHttps](INFO): Moved sent file to Logs/20190323T052354/Courier0000.lzma.bak 2019-03-23T05:28:35.470Z,1553318915.470 [DataOverHttps](INFO): SBD MOMSN=10219513 2019-03-23T05:28:37.032Z,1553318917.032 [BPC1](INFO): BPC1B: sending IBPS break. 2019-03-23T05:28:39.063Z,1553318919.063 [BPC1](INFO): BPC1A: validating data format. 2019-03-23T05:28:39.182Z,1553318919.182 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2019-03-23T05:28:39.182Z,1553318919.182 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2019-03-23T05:28:39.464Z,1553318919.464 [BPC1](INFO): BPC1A: data parsed. 2019-03-23T05:28:40.285Z,1553318920.285 [BPC1](INFO): BPC1A: initialized. 2019-03-23T05:28:41.073Z,1553318921.073 [BPC1](INFO): BPC1B: validating data format. 2019-03-23T05:28:41.258Z,1553318921.258 [BPC1](INFO): BPC1B: got 6 stick msg (1368 bytes) with LONG_IBPS_MENU. 2019-03-23T05:28:41.258Z,1553318921.258 [BPC1](INFO): BPC1B: got valid message (1368 bytes). 2019-03-23T05:28:41.485Z,1553318921.485 [BPC1](INFO): BPC1B: data parsed. 2019-03-23T05:28:42.301Z,1553318922.301 [BPC1](INFO): BPC1B: initialized. 2019-03-23T05:28:45.736Z,1553318925.736 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20190323T052542/Courier0000.lzma 2019-03-23T05:28:46.542Z,1553318926.542 [DataOverHttps](INFO): Moved sent file to Logs/20190323T052542/Courier0000.lzma.bak 2019-03-23T05:28:46.542Z,1553318926.542 [DataOverHttps](INFO): SBD MOMSN=10219517 2019-03-23T05:28:47.537Z,1553318927.537 [BPC1](INFO): BPC1A: sending IBPS break. 2019-03-23T05:28:50.366Z,1553318930.366 [BPC1](INFO): BPC1B: sending IBPS break. 2019-03-23T05:28:52.389Z,1553318932.389 [BPC1](INFO): BPC1A: validating data format. 2019-03-23T05:28:52.463Z,1553318932.463 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with LONG_IBPS_MENU. 2019-03-23T05:28:52.463Z,1553318932.463 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2019-03-23T05:28:52.795Z,1553318932.795 [BPC1](INFO): BPC1A: data parsed. 2019-03-23T05:28:53.625Z,1553318933.625 [BPC1](INFO): BPC1A: initialized. 2019-03-23T05:28:54.016Z,1553318934.016 [BPC1](INFO): BPC1B: validating data format. 2019-03-23T05:28:54.091Z,1553318934.091 [BPC1](INFO): BPC1B: got 6 stick msg (1368 bytes) with SHORT_IBPS_MENU. 2019-03-23T05:28:54.091Z,1553318934.091 [BPC1](INFO): BPC1B: got valid message (1368 bytes). 2019-03-23T05:28:54.420Z,1553318934.420 [BPC1](INFO): BPC1B: data parsed. 2019-03-23T05:28:55.629Z,1553318935.629 [BPC1](INFO): BPC1B: initialized. 2019-03-23T05:28:56.784Z,1553318936.784 [DataOverHttps](INFO): Sending 94 bytes from file Logs/20190323T051057/Express0005.lzma 2019-03-23T05:28:57.238Z,1553318937.238 [BPC1](INFO): BPC1B: sending IBPS break. 2019-03-23T05:28:57.590Z,1553318937.590 [DataOverHttps](INFO): Moved sent file to Logs/20190323T051057/Express0005.lzma.bak 2019-03-23T05:28:57.590Z,1553318937.590 [DataOverHttps](INFO): SBD MOMSN=10219521 2019-03-23T05:29:00.868Z,1553318940.868 [BPC1](INFO): BPC1A: sending IBPS break. 2019-03-23T05:29:01.677Z,1553318941.677 [BPC1](INFO): BPC1B: validating data format. 2019-03-23T05:29:01.716Z,1553318941.716 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with LONG_IBPS_MENU. 2019-03-23T05:29:01.716Z,1553318941.716 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2019-03-23T05:29:02.087Z,1553318942.087 [BPC1](INFO): BPC1B: data parsed. 2019-03-23T05:29:02.905Z,1553318942.905 [BPC1](INFO): BPC1B: initialized. 2019-03-23T05:29:05.713Z,1553318945.713 [BPC1](INFO): BPC1A: validating data format. 2019-03-23T05:29:05.826Z,1553318945.826 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2019-03-23T05:29:05.827Z,1553318945.827 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2019-03-23T05:29:06.128Z,1553318946.128 [BPC1](INFO): BPC1A: data parsed. 2019-03-23T05:29:06.941Z,1553318946.941 [BPC1](INFO): BPC1A: initialized. 2019-03-23T05:29:07.946Z,1553318947.946 [DataOverHttps](INFO): Sending 812 bytes from file Logs/20190323T052354/Express0001.lzma 2019-03-23T05:29:08.750Z,1553318948.750 [DataOverHttps](INFO): Moved sent file to Logs/20190323T052354/Express0001.lzma.bak 2019-03-23T05:29:08.750Z,1553318948.750 [DataOverHttps](INFO): SBD MOMSN=10219525 2019-03-23T05:29:09.771Z,1553318949.771 [BPC1](INFO): BPC1B: sending IBPS break. 2019-03-23T05:29:14.628Z,1553318954.628 [BPC1](INFO): BPC1A: sending IBPS break. 2019-03-23T05:29:14.628Z,1553318954.628 [BPC1](INFO): BPC1B: validating data format. 2019-03-23T05:29:14.688Z,1553318954.688 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2019-03-23T05:29:14.688Z,1553318954.688 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2019-03-23T05:29:15.038Z,1553318955.038 [BPC1](INFO): BPC1B: data parsed. 2019-03-23T05:29:15.470Z,1553318955.470 [Startup:StartupSatComms:B](INFO): Timed out from 2019-03-23T05:28:15.1Z 2019-03-23T05:29:15.470Z,1553318955.470 [Startup:StartupSatComms:B] Stopped 2019-03-23T05:29:15.470Z,1553318955.470 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2019-03-23T05:29:15.470Z,1553318955.470 [Startup:StartupSatComms] Stopped 2019-03-23T05:29:15.470Z,1553318955.470 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2019-03-23T05:29:15.471Z,1553318955.471 [Startup](INFO): Completed Startup 2019-03-23T05:29:15.471Z,1553318955.471 [MissionManager](INFO): Startup is completed. 2019-03-23T05:29:15.471Z,1553318955.471 [MissionManager](INFO): Uninitializing Mission Startup 2019-03-23T05:29:15.471Z,1553318955.471 [Startup] Stopped 2019-03-23T05:29:15.471Z,1553318955.471 [Startup](DEBUG): Aggregate::uninitialize Startup 2019-03-23T05:29:15.472Z,1553318955.472 [Startup:A.GoToSurface] Stopped 2019-03-23T05:29:15.472Z,1553318955.472 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-03-23T05:29:15.841Z,1553318955.841 [BPC1](INFO): BPC1B: initialized. 2019-03-23T05:29:15.850Z,1553318955.850 [MissionManager](IMPORTANT): Started mission Default 2019-03-23T05:29:15.850Z,1553318955.850 [Default] Running Loop=1 2019-03-23T05:29:15.850Z,1553318955.850 [Default](DEBUG): Aggregate::initialize Default 2019-03-23T05:29:15.850Z,1553318955.850 [Default:B.GoToSurface] Running Loop=1 2019-03-23T05:29:15.850Z,1553318955.850 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-03-23T05:29:15.850Z,1553318955.850 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-03-23T05:29:15.851Z,1553318955.851 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-03-23T05:29:15.851Z,1553318955.851 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-03-23T05:29:15.851Z,1553318955.851 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-03-23T05:29:15.852Z,1553318955.852 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-03-23T05:29:15.852Z,1553318955.852 [Default:A.Wait] Running Loop=1 2019-03-23T05:29:15.852Z,1553318955.852 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-03-23T05:29:19.015Z,1553318959.015 [DataOverHttps](INFO): Sending 910 bytes from file Logs/20190323T052542/Express0001.lzma 2019-03-23T05:29:19.453Z,1553318959.453 [BPC1](INFO): BPC1A: validating data format. 2019-03-23T05:29:19.523Z,1553318959.523 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with LONG_IBPS_MENU. 2019-03-23T05:29:19.523Z,1553318959.523 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2019-03-23T05:29:19.818Z,1553318959.818 [DataOverHttps](INFO): Moved sent file to Logs/20190323T052542/Express0001.lzma.bak 2019-03-23T05:29:19.819Z,1553318959.819 [DataOverHttps](INFO): SBD MOMSN=10219549 2019-03-23T05:29:19.874Z,1553318959.874 [BPC1](INFO): BPC1A: data parsed. 2019-03-23T05:29:20.693Z,1553318960.693 [BPC1](INFO): BPC1A: initialized. 2019-03-23T05:29:23.089Z,1553318963.089 [BPC1](INFO): BPC1B: sending IBPS break. 2019-03-23T05:29:27.945Z,1553318967.945 [BPC1](INFO): BPC1A: sending IBPS break. 2019-03-23T05:29:27.946Z,1553318967.946 [BPC1](INFO): BPC1B: validating data format. 2019-03-23T05:29:28.006Z,1553318968.006 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with LONG_IBPS_MENU. 2019-03-23T05:29:28.007Z,1553318968.007 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2019-03-23T05:29:28.347Z,1553318968.347 [BPC1](INFO): BPC1B: data parsed. 2019-03-23T05:29:29.165Z,1553318969.165 [BPC1](INFO): BPC1B: initialized. 2019-03-23T05:29:29.178Z,1553318969.178 [Default:A.Wait](INFO): Done Waiting. 2019-03-23T05:29:29.178Z,1553318969.178 [Default:A.Wait] Stopped 2019-03-23T05:29:29.178Z,1553318969.178 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-03-23T05:29:29.558Z,1553318969.558 [Default:CheckIn] Running Loop=1 2019-03-23T05:29:29.558Z,1553318969.558 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-03-23T05:29:29.558Z,1553318969.558 [Default:CheckIn:Read_GPS] Running Loop=1 2019-03-23T05:29:29.966Z,1553318969.966 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2019-03-23T05:29:32.786Z,1553318972.786 [BPC1](INFO): BPC1A: validating data format. 2019-03-23T05:29:32.857Z,1553318972.857 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2019-03-23T05:29:32.857Z,1553318972.857 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2019-03-23T05:29:33.195Z,1553318973.195 [BPC1](INFO): BPC1A: data parsed. 2019-03-23T05:29:34.013Z,1553318974.013 [BPC1](INFO): BPC1A: initialized. 2019-03-23T05:29:36.435Z,1553318976.435 [BPC1](INFO): BPC1B: sending IBPS break. 2019-03-23T05:29:41.286Z,1553318981.286 [BPC1](INFO): BPC1A: sending IBPS break. 2019-03-23T05:29:41.286Z,1553318981.286 [BPC1](INFO): BPC1B: validating data format. 2019-03-23T05:29:41.346Z,1553318981.346 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2019-03-23T05:29:41.346Z,1553318981.346 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2019-03-23T05:29:41.690Z,1553318981.690 [BPC1](INFO): BPC1B: data parsed. 2019-03-23T05:29:42.497Z,1553318982.497 [BPC1](INFO): BPC1B: initialized. 2019-03-23T05:29:46.131Z,1553318986.131 [BPC1](INFO): BPC1A: validating data format. 2019-03-23T05:29:46.203Z,1553318986.203 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with LONG_IBPS_MENU. 2019-03-23T05:29:46.203Z,1553318986.203 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2019-03-23T05:29:46.538Z,1553318986.538 [BPC1](INFO): BPC1A: data parsed. 2019-03-23T05:29:47.357Z,1553318987.357 [BPC1](INFO): BPC1A: initialized. 2019-03-23T05:29:49.757Z,1553318989.757 [BPC1](INFO): BPC1B: sending IBPS break. 2019-03-23T05:29:52.989Z,1553318992.989 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-03-23T05:29:52.989Z,1553318992.989 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2019-03-23T05:29:52.990Z,1553318992.990 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-03-23T05:29:52.991Z,1553318992.991 [DeadReckonUsingSpeedCalculator](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-03-23T05:29:52.991Z,1553318992.991 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2 2019-03-23T05:29:52.991Z,1553318992.991 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2019-03-23T05:29:53.001Z,1553318993.001 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-03-23T05:29:53.001Z,1553318993.001 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2019-03-23T05:29:53.408Z,1553318993.408 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-03-23T05:29:53.409Z,1553318993.409 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2019-03-23T05:29:53.409Z,1553318993.409 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2019-03-23T05:29:53.409Z,1553318993.409 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2 2019-03-23T05:29:53.796Z,1553318993.796 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2019-03-23T05:29:54.609Z,1553318994.609 [BPC1](INFO): BPC1A: sending IBPS break. 2019-03-23T05:29:54.609Z,1553318994.609 [BPC1](INFO): BPC1B: validating data format. 2019-03-23T05:29:54.670Z,1553318994.670 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with LONG_IBPS_MENU. 2019-03-23T05:29:54.670Z,1553318994.670 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2019-03-23T05:29:55.023Z,1553318995.023 [BPC1](INFO): BPC1B: data parsed. 2019-03-23T05:29:55.829Z,1553318995.829 [BPC1](INFO): BPC1B: initialized. 2019-03-23T05:29:59.470Z,1553318999.470 [BPC1](INFO): BPC1A: validating data format. 2019-03-23T05:29:59.640Z,1553318999.640 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2019-03-23T05:29:59.640Z,1553318999.640 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2019-03-23T05:29:59.876Z,1553318999.876 [BPC1](INFO): BPC1A: data parsed. 2019-03-23T05:30:00.689Z,1553319000.689 [BPC1](INFO): BPC1A: initialized. 2019-03-23T05:30:03.112Z,1553319003.112 [BPC1](INFO): BPC1B: sending IBPS break. 2019-03-23T05:30:07.557Z,1553319007.557 [BPC1](INFO): BPC1A: sending IBPS break. 2019-03-23T05:30:07.967Z,1553319007.967 [BPC1](INFO): BPC1B: validating data format. 2019-03-23T05:30:08.114Z,1553319008.114 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2019-03-23T05:30:08.114Z,1553319008.114 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2019-03-23T05:30:08.372Z,1553319008.372 [BPC1](INFO): BPC1B: data parsed. 2019-03-23T05:30:09.181Z,1553319009.181 [BPC1](INFO): BPC1B: initialized. 2019-03-23T05:30:12.413Z,1553319012.413 [BPC1](INFO): BPC1A: validating data format. 2019-03-23T05:30:12.535Z,1553319012.535 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with LONG_IBPS_MENU. 2019-03-23T05:30:12.535Z,1553319012.535 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2019-03-23T05:30:12.820Z,1553319012.820 [BPC1](INFO): BPC1A: data parsed. 2019-03-23T05:30:13.629Z,1553319013.629 [BPC1](INFO): BPC1A: initialized. 2019-03-23T05:30:17.245Z,1553319017.245 [BPC1](INFO): BPC1B: sending IBPS break. 2019-03-23T05:30:18.803Z,1553319018.803 [CommandLine](IMPORTANT): got command restart application 2019-03-23T05:30:19.809Z,1553319019.809 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2019-03-23T05:30:19.809Z,1553319019.809 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-03-23T05:30:19.889Z,1553319019.889 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2019-03-23T05:30:19.889Z,1553319019.889 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-03-23T05:30:19.890Z,1553319019.889 [CommandLine](INFO): Join timeout helper Thread ID is 4367 2019-03-23T05:30:19.890Z,1553319019.890 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2019-03-23T05:30:19.890Z,1553319019.890 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-03-23T05:30:19.891Z,1553319019.891 [NavChartDb](INFO): Join timeout helper Thread ID is 4368 2019-03-23T05:30:20.261Z,1553319020.261 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2019-03-23T05:30:20.261Z,1553319020.261 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-03-23T05:30:20.277Z,1553319020.277 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2019-03-23T05:30:20.277Z,1553319020.277 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-03-23T05:30:20.277Z,1553319020.277 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 4369 2019-03-23T05:30:20.697Z,1553319020.697 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2019-03-23T05:30:20.697Z,1553319020.697 [WetLabsBB2FL](INFO): Powering down 2019-03-23T05:30:20.698Z,1553319020.698 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-03-23T05:30:20.717Z,1553319020.717 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler 2019-03-23T05:30:20.717Z,1553319020.717 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2019-03-23T05:30:20.717Z,1553319020.717 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 4370 2019-03-23T05:30:20.833Z,1553319020.833 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread. 2019-03-23T05:30:20.833Z,1553319020.833 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2019-03-23T05:30:20.837Z,1553319020.837 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2019-03-23T05:30:20.837Z,1553319020.837 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-03-23T05:30:20.837Z,1553319020.837 [Radio_Surface](INFO): Join timeout helper Thread ID is 4371 2019-03-23T05:30:21.025Z,1553319021.025 [Radio_Surface](INFO): Powering down 2019-03-23T05:30:21.026Z,1553319021.026 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2019-03-23T05:30:21.026Z,1553319021.026 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-03-23T05:30:21.034Z,1553319021.034 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2019-03-23T05:30:21.034Z,1553319021.034 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-03-23T05:30:21.034Z,1553319021.034 [DataOverHttps](INFO): Join timeout helper Thread ID is 4372 2019-03-23T05:30:21.285Z,1553319021.285 [BPC1](INFO): BPC1A: sending IBPS break. 2019-03-23T05:30:21.361Z,1553319021.361 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2019-03-23T05:30:21.361Z,1553319021.361 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-03-23T05:30:21.366Z,1553319021.366 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2019-03-23T05:30:21.366Z,1553319021.366 [logger ThreadHandler](INFO): Thread cancelled. 2019-03-23T05:30:21.366Z,1553319021.366 [logger](INFO): Join timeout helper Thread ID is 4373 2019-03-23T05:30:21.433Z,1553319021.433 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2019-03-23T05:30:21.433Z,1553319021.433 [logger ThreadHandler](INFO): Thread cancelled. 2019-03-23T05:30:21.445Z,1553319021.445 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2019-03-23T05:30:21.446Z,1553319021.446 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-03-23T05:30:21.446Z,1553319021.446 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2019-03-23T05:30:21.446Z,1553319021.446 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-03-23T05:30:21.446Z,1553319021.446 [controlThread](INFO): Join timeout helper Thread ID is 4374 2019-03-23T05:30:21.661Z,1553319021.661 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2019-03-23T05:30:21.661Z,1553319021.661 [controlThread](DEBUG): Uninitializing ControlThread 2019-03-23T05:30:21.662Z,1553319021.662 [NAL9602](INFO): Powering down 2019-03-23T05:30:21.663Z,1553319021.663 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2019-03-23T05:30:21.664Z,1553319021.664 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2019-03-23T05:30:21.665Z,1553319021.665 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2019-03-23T05:30:21.665Z,1553319021.665 [MissionManager](INFO): Uninitializing Mission Default 2019-03-23T05:30:21.665Z,1553319021.665 [Default] Stopped 2019-03-23T05:30:21.665Z,1553319021.665 [Default](DEBUG): Aggregate::uninitialize Default 2019-03-23T05:30:21.665Z,1553319021.665 [Default:B.GoToSurface] Stopped 2019-03-23T05:30:21.665Z,1553319021.665 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-03-23T05:30:21.665Z,1553319021.665 [Default:CheckIn] Stopped 2019-03-23T05:30:21.666Z,1553319021.666 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-03-23T05:30:21.666Z,1553319021.666 [Default:CheckIn:Read_GPS] Stopped 2019-03-23T05:30:21.668Z,1553319021.668 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2019-03-23T05:30:21.668Z,1553319021.668 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2019-03-23T05:30:21.668Z,1553319021.668 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2019-03-23T05:30:21.669Z,1553319021.669 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2019-03-23T05:30:21.669Z,1553319021.669 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2019-03-23T05:30:21.669Z,1553319021.669 [ElevatorServo](INFO): Powering down 2019-03-23T05:30:21.670Z,1553319021.670 [MassServo](DEBUG): Uninitialize Mass Servo. 2019-03-23T05:30:21.670Z,1553319021.670 [MassServo](INFO): Powering down 2019-03-23T05:30:21.671Z,1553319021.671 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2019-03-23T05:30:21.671Z,1553319021.671 [ThrusterServo](INFO): Powering down 2019-03-23T05:30:21.672Z,1553319021.672 [SBIT](DEBUG): Uninitialize SBIT Component. 2019-03-23T05:30:21.672Z,1553319021.672 [IBIT](DEBUG): Uninitialize IBIT Component. 2019-03-23T05:30:21.672Z,1553319021.672 [CBIT](DEBUG): Uninitialize CBIT Component. 2019-03-23T05:30:21.672Z,1553319021.672 [CBIT](DEBUG): Powering off loads. 2019-03-23T05:30:21.685Z,1553319021.685 [CBIT](DEBUG): Disabling WDT. 2019-03-23T05:30:21.697Z,1553319021.697 [CBIT](DEBUG): Opening all GF detection circuits. 2019-03-23T05:30:21.697Z,1553319021.697 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-03-23T05:30:21.780Z,1553319021.780 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-03-23T05:30:21.785Z,1553319021.785 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-03-23T05:30:21.824Z,1553319021.824 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-03-23T05:30:21.826Z,1553319021.826 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2019-03-23T05:30:21.862Z,1553319021.862 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-03-23T05:30:21.921Z,1553319021.921 [logger ThreadHandler](INFO): Thread cancelled.