2021-01-28T21:05:28.864Z,1611867928.864 [Supervisor](DEBUG): Initializing supervisor. 2021-01-28T21:05:28.868Z,1611867928.868 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2021-01-28T21:05:28.869Z,1611867928.869 [SyncHandler](INFO): Protected caller Thread ID is 819 2021-01-28T21:05:28.869Z,1611867928.869 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2021-01-28T21:05:28.870Z,1611867928.870 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2021-01-28T21:05:28.870Z,1611867928.870 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 820 2021-01-28T21:05:28.875Z,1611867928.875 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2021-01-28T21:05:28.893Z,1611867928.893 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2021-01-28T21:05:28.894Z,1611867928.894 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2021-01-28T21:05:28.895Z,1611867928.895 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 821 2021-01-28T21:05:28.897Z,1611867928.897 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2021-01-28T21:05:28.898Z,1611867928.898 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2021-01-28T21:05:28.898Z,1611867928.898 [logger ThreadHandler](INFO): Protected caller Thread ID is 822 2021-01-28T21:05:28.902Z,1611867928.902 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2021-01-28T21:05:28.902Z,1611867928.902 [Supervisor](INFO): Looking for Config files in directory: Config/ 2021-01-28T21:05:28.906Z,1611867928.906 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2021-01-28T21:05:29.127Z,1611867929.127 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2021-01-28T21:05:29.129Z,1611867929.129 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2021-01-28T21:05:29.210Z,1611867929.210 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2021-01-28T21:05:29.685Z,1611867929.685 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2021-01-28T21:05:29.687Z,1611867929.687 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2021-01-28T21:05:30.004Z,1611867930.004 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2021-01-28T21:05:30.005Z,1611867930.005 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2021-01-28T21:05:30.099Z,1611867930.099 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2021-01-28T21:05:30.100Z,1611867930.100 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2021-01-28T21:05:30.391Z,1611867930.391 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2021-01-28T21:05:30.393Z,1611867930.393 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2021-01-28T21:05:30.580Z,1611867930.580 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2021-01-28T21:05:30.582Z,1611867930.582 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2021-01-28T21:05:30.983Z,1611867930.983 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2021-01-28T21:05:30.984Z,1611867930.984 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2021-01-28T21:05:31.106Z,1611867931.106 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2021-01-28T21:05:31.106Z,1611867931.106 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2021-01-28T21:05:31.185Z,1611867931.185 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2021-01-28T21:05:31.794Z,1611867931.794 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2021-01-28T21:05:31.795Z,1611867931.795 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2021-01-28T21:05:32.134Z,1611867932.134 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2021-01-28T21:05:32.135Z,1611867932.135 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2021-01-28T21:05:32.316Z,1611867932.316 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2021-01-28T21:05:32.318Z,1611867932.318 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2021-01-28T21:05:32.713Z,1611867932.713 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2021-01-28T21:05:33.107Z,1611867933.107 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2021-01-28T21:05:33.384Z,1611867933.384 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2021-01-28T21:05:33.385Z,1611867933.385 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2021-01-28T21:05:33.597Z,1611867933.597 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2021-01-28T21:05:33.599Z,1611867933.599 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2021-01-28T21:05:33.601Z,1611867933.601 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg 2021-01-28T21:05:33.690Z,1611867933.690 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2021-01-28T21:05:33.773Z,1611867933.773 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2021-01-28T21:05:33.871Z,1611867933.871 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2021-01-28T21:05:33.954Z,1611867933.954 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2021-01-28T21:05:34.047Z,1611867934.047 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2021-01-28T21:05:34.145Z,1611867934.145 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2021-01-28T21:05:34.326Z,1611867934.326 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg 2021-01-28T21:05:34.403Z,1611867934.403 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2021-01-28T21:05:34.549Z,1611867934.549 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2021-01-28T21:05:34.686Z,1611867934.686 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2021-01-28T21:05:34.800Z,1611867934.800 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2021-01-28T21:05:35.051Z,1611867935.051 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2021-01-28T21:05:35.051Z,1611867935.051 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2021-01-28T21:05:35.064Z,1611867935.064 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2021-01-28T21:05:35.132Z,1611867935.132 [VerticalControl](DEBUG): Construct VerticalControl. 2021-01-28T21:05:35.191Z,1611867935.191 [VerticalControl] Loaded 2021-01-28T21:05:35.191Z,1611867935.191 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2021-01-28T21:05:35.194Z,1611867935.194 [HorizontalControl](DEBUG): Construct HorizontalControl. 2021-01-28T21:05:35.231Z,1611867935.231 [HorizontalControl] Loaded 2021-01-28T21:05:35.231Z,1611867935.231 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2021-01-28T21:05:35.233Z,1611867935.233 [SpeedControl](DEBUG): Construct SpeedControl. 2021-01-28T21:05:35.236Z,1611867935.236 [SpeedControl] Loaded 2021-01-28T21:05:35.237Z,1611867935.237 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2021-01-28T21:05:35.239Z,1611867935.239 [LoopControl](DEBUG): Construct LoopControl. 2021-01-28T21:05:35.240Z,1611867935.240 [LoopControl] Loaded 2021-01-28T21:05:35.240Z,1611867935.240 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2021-01-28T21:05:35.240Z,1611867935.240 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2021-01-28T21:05:35.242Z,1611867935.242 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2021-01-28T21:05:35.259Z,1611867935.259 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2021-01-28T21:05:35.259Z,1611867935.259 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2021-01-28T21:05:35.385Z,1611867935.385 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2021-01-28T21:05:35.385Z,1611867935.385 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2021-01-28T21:05:35.544Z,1611867935.544 [BuoyancyServo] Loaded 2021-01-28T21:05:35.544Z,1611867935.544 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2021-01-28T21:05:35.563Z,1611867935.563 [ElevatorServo] Loaded 2021-01-28T21:05:35.563Z,1611867935.563 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2021-01-28T21:05:35.581Z,1611867935.581 [MassServo] Loaded 2021-01-28T21:05:35.581Z,1611867935.581 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2021-01-28T21:05:35.598Z,1611867935.598 [RudderServo] Loaded 2021-01-28T21:05:35.598Z,1611867935.598 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2021-01-28T21:05:35.615Z,1611867935.615 [ThrusterServo] Loaded 2021-01-28T21:05:35.615Z,1611867935.615 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2021-01-28T21:05:35.616Z,1611867935.616 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2021-01-28T21:05:35.616Z,1611867935.616 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2021-01-28T21:05:35.713Z,1611867935.713 [DeadReckonUsingMultipleVelocitySources] Loaded 2021-01-28T21:05:35.713Z,1611867935.713 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2021-01-28T21:05:35.725Z,1611867935.725 [NavChart] Loaded 2021-01-28T21:05:35.726Z,1611867935.726 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2021-01-28T21:05:35.731Z,1611867935.731 [UniversalFixResidualReporter] Loaded 2021-01-28T21:05:35.731Z,1611867935.731 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2021-01-28T21:05:35.732Z,1611867935.732 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2021-01-28T21:05:35.732Z,1611867935.732 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2021-01-28T21:05:35.808Z,1611867935.808 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2021-01-28T21:05:35.809Z,1611867935.809 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2021-01-28T21:05:36.491Z,1611867936.491 [AHRS_M2] Loaded 2021-01-28T21:05:36.491Z,1611867936.491 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2021-01-28T21:05:37.256Z,1611867937.256 [BPC1] Loaded 2021-01-28T21:05:37.256Z,1611867937.256 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2021-01-28T21:05:37.398Z,1611867937.398 [DataOverHttps] Loaded 2021-01-28T21:05:37.398Z,1611867937.398 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2021-01-28T21:05:37.399Z,1611867937.399 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4087B4E0 2021-01-28T21:05:37.400Z,1611867937.400 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 907 2021-01-28T21:05:37.418Z,1611867937.418 [Depth_Keller] Loaded 2021-01-28T21:05:37.419Z,1611867937.419 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2021-01-28T21:05:37.423Z,1611867937.423 [DropWeight] Loaded 2021-01-28T21:05:37.423Z,1611867937.423 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2021-01-28T21:05:37.507Z,1611867937.507 [NAL9602] Loaded 2021-01-28T21:05:37.508Z,1611867937.508 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2021-01-28T21:05:37.611Z,1611867937.611 [Onboard] Loaded 2021-01-28T21:05:37.612Z,1611867937.612 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2021-01-28T21:05:37.613Z,1611867937.613 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408AB4E0 2021-01-28T21:05:37.613Z,1611867937.613 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 908 2021-01-28T21:05:37.666Z,1611867937.666 [Radio_Surface] Loaded 2021-01-28T21:05:37.666Z,1611867937.666 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2021-01-28T21:05:37.685Z,1611867937.685 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408DB4E0 2021-01-28T21:05:37.685Z,1611867937.685 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 909 2021-01-28T21:05:37.751Z,1611867937.751 [AMEcho] Loaded 2021-01-28T21:05:37.751Z,1611867937.751 [ComponentRegistry](DEBUG): SyncComponent "AMEcho" handled in the control thread. 2021-01-28T21:05:37.751Z,1611867937.751 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2021-01-28T21:05:37.752Z,1611867937.752 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2021-01-28T21:05:38.420Z,1611867938.420 [DepthRateCalculator] Loaded 2021-01-28T21:05:38.420Z,1611867938.420 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2021-01-28T21:05:38.425Z,1611867938.425 [PitchRateCalculator] Loaded 2021-01-28T21:05:38.425Z,1611867938.425 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2021-01-28T21:05:38.434Z,1611867938.434 [SpeedCalculator] Loaded 2021-01-28T21:05:38.434Z,1611867938.434 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2021-01-28T21:05:38.447Z,1611867938.447 [TempGradientCalculator] Loaded 2021-01-28T21:05:38.448Z,1611867938.448 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2021-01-28T21:05:38.452Z,1611867938.452 [YawRateCalculator] Loaded 2021-01-28T21:05:38.452Z,1611867938.452 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2021-01-28T21:05:38.469Z,1611867938.469 [ElevatorOffsetCalculator] Loaded 2021-01-28T21:05:38.470Z,1611867938.470 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2021-01-28T21:05:38.470Z,1611867938.470 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2021-01-28T21:05:38.471Z,1611867938.471 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2021-01-28T21:05:38.645Z,1611867938.645 [CANONSampler] Loaded 2021-01-28T21:05:38.646Z,1611867938.646 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread. 2021-01-28T21:05:38.702Z,1611867938.702 [CTD_Seabird] Loaded 2021-01-28T21:05:38.703Z,1611867938.703 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2021-01-28T21:05:38.704Z,1611867938.704 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 4098D4E0 2021-01-28T21:05:38.704Z,1611867938.704 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 910 2021-01-28T21:05:38.723Z,1611867938.723 [PAR_Licor] Loaded 2021-01-28T21:05:38.723Z,1611867938.723 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2021-01-28T21:05:38.753Z,1611867938.753 [WetLabsBB2FL] Loaded 2021-01-28T21:05:38.754Z,1611867938.754 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2021-01-28T21:05:38.755Z,1611867938.755 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409BD4E0 2021-01-28T21:05:38.755Z,1611867938.755 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 911 2021-01-28T21:05:38.756Z,1611867938.756 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2021-01-28T21:05:38.756Z,1611867938.756 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2021-01-28T21:05:38.798Z,1611867938.798 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2021-01-28T21:05:38.799Z,1611867938.799 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2021-01-28T21:05:39.155Z,1611867939.155 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2021-01-28T21:05:39.157Z,1611867939.157 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2021-01-28T21:05:39.318Z,1611867939.318 [SBIT](DEBUG): Construct Startup Built In Test. 2021-01-28T21:05:39.327Z,1611867939.327 [SBIT] Loaded 2021-01-28T21:05:39.327Z,1611867939.327 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2021-01-28T21:05:39.330Z,1611867939.330 [IBIT](DEBUG): Construct Initiated Built In Test. 2021-01-28T21:05:39.343Z,1611867939.343 [IBIT] Loaded 2021-01-28T21:05:39.343Z,1611867939.343 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2021-01-28T21:05:39.349Z,1611867939.349 [CBIT](DEBUG): Construct Continuous Built In Test. 2021-01-28T21:05:39.446Z,1611867939.446 [CBIT] Loaded 2021-01-28T21:05:39.446Z,1611867939.446 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2021-01-28T21:05:39.447Z,1611867939.447 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2021-01-28T21:05:39.447Z,1611867939.447 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2021-01-28T21:05:39.552Z,1611867939.552 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2021-01-28T21:05:39.558Z,1611867939.558 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2021-01-28T21:05:39.561Z,1611867939.561 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2021-01-28T21:05:39.571Z,1611867939.571 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2021-01-28T21:05:39.572Z,1611867939.572 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AED4E0 2021-01-28T21:05:39.573Z,1611867939.573 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 912 2021-01-28T21:05:39.577Z,1611867939.577 [Supervisor](INFO): Main Thread ID is 815 2021-01-28T21:05:39.577Z,1611867939.577 [Supervisor](DEBUG): Running supervisor. 2021-01-28T21:05:39.578Z,1611867939.578 [CommandLine ThreadHandler](INFO): Handler Thread ID is 913 2021-01-28T21:05:39.580Z,1611867939.580 [controlThread ThreadHandler](INFO): Handler Thread ID is 914 2021-01-28T21:05:39.580Z,1611867939.580 [controlThread](DEBUG): Initializing ControlThread 2021-01-28T21:05:39.581Z,1611867939.581 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2021-01-28T21:05:39.583Z,1611867939.583 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2021-01-28T21:05:39.584Z,1611867939.584 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2021-01-28T21:05:39.584Z,1611867939.584 [LoopControl](DEBUG): Initialize LoopControlComponent. 2021-01-28T21:05:39.586Z,1611867939.586 [NavChart](DEBUG): Initialize NavChart Navigation. 2021-01-28T21:05:39.587Z,1611867939.587 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2021-01-28T21:05:39.591Z,1611867939.591 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2021-01-28T21:05:39.591Z,1611867939.591 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2021-01-28T21:05:39.592Z,1611867939.592 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2021-01-28T21:05:39.592Z,1611867939.592 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2021-01-28T21:05:39.593Z,1611867939.593 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2021-01-28T21:05:39.593Z,1611867939.593 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2021-01-28T21:05:39.597Z,1611867939.597 [SBIT](INFO): Initialize SBIT Component. 2021-01-28T21:05:39.598Z,1611867939.598 [SBIT](IMPORTANT): git: 2020-12-13-7-gb32928fff 2021-01-28T21:05:39.598Z,1611867939.598 [SBIT](INFO): git hash: b32928ffff5a5ecf5e1c718e9189f27a8889e67a 2021-01-28T21:05:39.598Z,1611867939.598 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2021-01-28T21:05:39.599Z,1611867939.599 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 Kernel Reported: #1 PREEMPT Wed Nov 13 12:38:10 PST 2019 2021-01-28T21:05:39.600Z,1611867939.600 [SBIT](INFO): Beginning SBIT in 44.000000 seconds. 2021-01-28T21:05:39.601Z,1611867939.601 [IBIT](INFO): Initialize IBIT Component. 2021-01-28T21:05:39.602Z,1611867939.602 [CBIT](DEBUG): Initialize CBIT Component. 2021-01-28T21:05:39.603Z,1611867939.603 [logger ThreadHandler](INFO): Handler Thread ID is 915 2021-01-28T21:05:39.613Z,1611867939.613 [CBIT](DEBUG): Initialized mux pins. 2021-01-28T21:05:39.613Z,1611867939.613 [CBIT](DEBUG): Initializing the watchdog timer. 2021-01-28T21:05:39.621Z,1611867939.621 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 916 2021-01-28T21:05:39.622Z,1611867939.622 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2021-01-28T21:05:39.633Z,1611867939.633 [Onboard ThreadHandler](INFO): Handler Thread ID is 917 2021-01-28T21:05:39.637Z,1611867939.637 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2021-01-28T21:05:39.638Z,1611867939.638 [CBIT](DEBUG): Initializing heartbeat. 2021-01-28T21:05:39.651Z,1611867939.651 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 918 2021-01-28T21:05:39.665Z,1611867939.665 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 919 2021-01-28T21:05:39.666Z,1611867939.666 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2021-01-28T21:05:39.670Z,1611867939.670 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 921 2021-01-28T21:05:39.673Z,1611867939.673 [WetLabsBB2FL](INFO): Powering up 2021-01-28T21:05:39.675Z,1611867939.675 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 923 2021-01-28T21:05:39.683Z,1611867939.683 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2021-01-28T21:05:39.683Z,1611867939.683 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2021-01-28T21:05:39.683Z,1611867939.683 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2021-01-28T21:05:39.683Z,1611867939.683 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2021-01-28T21:05:39.683Z,1611867939.683 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2021-01-28T21:05:39.684Z,1611867939.684 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2021-01-28T21:05:39.684Z,1611867939.684 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2021-01-28T21:05:39.684Z,1611867939.684 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2021-01-28T21:05:39.684Z,1611867939.684 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2021-01-28T21:05:39.684Z,1611867939.684 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2021-01-28T21:05:39.684Z,1611867939.684 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2021-01-28T21:05:39.685Z,1611867939.685 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2021-01-28T21:05:39.685Z,1611867939.685 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2021-01-28T21:05:39.685Z,1611867939.685 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2021-01-28T21:05:39.685Z,1611867939.685 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2021-01-28T21:05:39.686Z,1611867939.686 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2021-01-28T21:05:39.709Z,1611867939.709 [CBIT](DEBUG): Deactivating GF circuits. 2021-01-28T21:05:39.709Z,1611867939.709 [CBIT](DEBUG): Deactivating emergency mode. 2021-01-28T21:05:39.745Z,1611867939.745 [CBIT](DEBUG): Backplane powered. 2021-01-28T21:05:39.746Z,1611867939.746 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2021-01-28T21:05:39.772Z,1611867939.772 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2021-01-28T21:05:39.792Z,1611867939.792 [MissionManager](DEBUG): 2021-01-28T21:05:39.817Z,1611867939.817 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2021-01-28T21:05:39.892Z,1611867939.892 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2021-01-28T21:05:39.909Z,1611867939.909 [Default:A.Wait](DEBUG): Construct Wait. 2021-01-28T21:05:39.911Z,1611867939.911 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2021-01-28T21:05:39.939Z,1611867939.939 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2021-01-28T21:05:39.955Z,1611867939.955 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2021-01-28T21:05:39.977Z,1611867939.977 [Default:E.Execute](DEBUG): Construct Execute. 2021-01-28T21:05:39.980Z,1611867939.980 [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 2021-01-28T21:05:39.985Z,1611867939.985 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,AMEcho,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2021-01-28T21:05:39.995Z,1611867939.995 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2021-01-28T21:05:40.057Z,1611867940.057 [Radio_Surface](INFO): Powering up 2021-01-28T21:05:40.266Z,1611867940.266 [AMEcho](INFO): Powering up 2021-01-28T21:05:40.268Z,1611867940.268 [AMEcho](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2021-01-28T21:05:40.277Z,1611867940.277 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2021-01-28T21:05:40.310Z,1611867940.310 [CANONSampler](INFO): Powering down 2021-01-28T21:05:40.382Z,1611867940.382 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2021-01-28T21:05:40.393Z,1611867940.393 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2021-01-28T21:05:40.395Z,1611867940.395 [ElevatorServo](DEBUG): Initializing EZServoServo. 2021-01-28T21:05:40.401Z,1611867940.401 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2021-01-28T21:05:40.402Z,1611867940.402 [MassServo](DEBUG): Initializing EZServoServo. 2021-01-28T21:05:40.409Z,1611867940.409 [MassServo](DEBUG): Initializing MassServo. 2021-01-28T21:05:40.410Z,1611867940.410 [RudderServo](DEBUG): Initializing EZServoServo. 2021-01-28T21:05:40.417Z,1611867940.417 [RudderServo](DEBUG): Initializing RudderServo. 2021-01-28T21:05:40.418Z,1611867940.418 [ThrusterServo](DEBUG): Initializing EZServoServo. 2021-01-28T21:05:40.425Z,1611867940.425 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2021-01-28T21:05:40.513Z,1611867940.513 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2021-01-28T21:05:40.513Z,1611867940.513 [DropWeight] Hardware Fault, FailCount= 1 2021-01-28T21:05:40.513Z,1611867940.513 [DropWeight](ERROR): Hardware Fault 2021-01-28T21:05:40.681Z,1611867940.681 [AMEcho](INFO): Powering down 2021-01-28T21:05:40.716Z,1611867940.716 [CommandLine](FAULT): Scheduling is paused 2021-01-28T21:05:40.716Z,1611867940.716 [CBIT](INFO): Critical error at 20210128T210540 2021-01-28T21:05:40.716Z,1611867940.716 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2021-01-28T21:05:40.719Z,1611867940.719 [CBIT](ERROR): Hardware Fault in component: DropWeight 2021-01-28T21:05:40.719Z,1611867940.719 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2021-01-28T21:05:40.895Z,1611867940.895 [CBIT](INFO): Critical error at 20210128T210540 2021-01-28T21:05:41.250Z,1611867941.250 [AMEcho](IMPORTANT): Setting 'enabled' to 0 2021-01-28T21:05:41.251Z,1611867941.251 [AMEcho](IMPORTANT): Setting 'depthThreshold' to 20.000000 2021-01-28T21:05:42.285Z,1611867942.285 [WetLabsBB2FL](INFO): Powering down 2021-01-28T21:05:46.697Z,1611867946.697 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit. 2021-01-28T21:06:07.510Z,1611867967.510 [NAL9602](INFO): Powering up NAL9602 2021-01-28T21:06:18.425Z,1611867978.425 [NAL9602](INFO): NAL9602 initialized 2021-01-28T21:06:24.127Z,1611867984.127 [SBIT](IMPORTANT): Beginning Startup BIT 2021-01-28T21:06:24.131Z,1611867984.131 [CBIT](IMPORTANT): Beginning ground fault scan 2021-01-28T21:06:35.014Z,1611867995.014 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.004030 CHAN A1 (24V): 4.610929 CHAN A2 (12V): -0.002194 CHAN A3 (5V): -0.001245 CHAN B0 (3.3V): 0.000007 CHAN B1 (3.15aV): 0.000008 CHAN B2 (3.15bV): -0.000113 CHAN B3 (GND): 0.000056 OPEN: -0.000407 Full Scale Calc: 4.765 mA, -1.589 mA 2021-01-28T21:07:18.231Z,1611868038.231 [SBIT](IMPORTANT): SBIT PASSED 2021-01-28T21:07:18.232Z,1611868038.232 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2021-01-28T21:07:18.232Z,1611868038.232 [SBIT](IMPORTANT): AMEcho.enabled=0 bool; 2021-01-28T21:07:18.233Z,1611868038.233 [SBIT](IMPORTANT): ElevatorOffsetCalculator.loadAtStartup=1 bool; 2021-01-28T21:07:18.233Z,1611868038.233 [SBIT](IMPORTANT): Express linearApproximation AMEcho.altitude 1.000000 meter; 2021-01-28T21:07:18.233Z,1611868038.233 [SBIT](IMPORTANT): Express linearApproximation height_above_sea_floor 1.000000 meter; 2021-01-28T21:07:18.233Z,1611868038.233 [SBIT](IMPORTANT): PAR_Licor.parCal=1.0914 none; 2021-01-28T21:07:18.233Z,1611868038.233 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=229.775315 cubic_centimeter; 2021-01-28T21:07:18.233Z,1611868038.233 [SBIT](IMPORTANT): VerticalControl.massDefault=-6.105428 millimeter; 2021-01-28T21:07:18.648Z,1611868038.648 [MissionManager](IMPORTANT): Started mission Startup 2021-01-28T21:07:18.648Z,1611868038.648 [Startup] Running Loop=1 2021-01-28T21:07:18.648Z,1611868038.648 [Startup](DEBUG): Aggregate::initialize Startup 2021-01-28T21:07:18.648Z,1611868038.648 [Startup:A.GoToSurface] Running Loop=1 2021-01-28T21:07:18.649Z,1611868038.649 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2021-01-28T21:07:18.649Z,1611868038.649 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2021-01-28T21:07:18.650Z,1611868038.650 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2021-01-28T21:07:18.650Z,1611868038.650 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2021-01-28T21:07:18.650Z,1611868038.650 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2021-01-28T21:07:18.651Z,1611868038.651 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2021-01-28T21:07:18.652Z,1611868038.652 [Startup:StartupSatComms] Running Loop=1 2021-01-28T21:07:18.652Z,1611868038.652 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2021-01-28T21:07:18.652Z,1611868038.652 [Startup:StartupSatComms:A] Running Loop=1 2021-01-28T21:07:19.061Z,1611868039.061 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2021-01-28T21:08:12.534Z,1611868092.534 [DataOverHttps](DEBUG): dataRead() @823 received: vehicle=daphne&busy=true 2021-01-28T21:08:12.535Z,1611868092.535 [DataOverHttps](DEBUG): ParseDataRead( data = busy=true, key = 6, value = daphne 2021-01-28T21:08:12.535Z,1611868092.535 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 0, value = true 2021-01-28T21:08:12.541Z,1611868092.541 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.006063 2021-01-28T21:08:18.830Z,1611868098.830 [Startup:StartupSatComms:A](INFO): Timed out from 2021-01-28T21:07:18.7Z 2021-01-28T21:08:18.831Z,1611868098.831 [Startup:StartupSatComms:A] Stopped 2021-01-28T21:08:18.831Z,1611868098.831 [Startup:StartupSatComms:B] Running Loop=1 2021-01-28T21:08:19.239Z,1611868099.239 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2021-01-28T21:08:26.754Z,1611868106.754 [DataOverHttps](DEBUG): dataRead() @823 received: vehicle=daphne&busy=true 2021-01-28T21:08:26.754Z,1611868106.754 [DataOverHttps](DEBUG): ParseDataRead( data = busy=true, key = 6, value = daphne 2021-01-28T21:08:26.755Z,1611868106.755 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 0, value = true 2021-01-28T21:08:34.930Z,1611868114.930 [DataOverHttps](DEBUG): dataRead() @823 received: vehicle=daphne&busy=true 2021-01-28T21:08:34.930Z,1611868114.930 [DataOverHttps](DEBUG): ParseDataRead( data = busy=true, key = 6, value = daphne 2021-01-28T21:08:34.931Z,1611868114.931 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 0, value = true 2021-01-28T21:08:39.851Z,1611868119.851 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2021-01-28T21:08:39.851Z,1611868119.851 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-01-28T21:08:39.861Z,1611868119.861 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-01-28T21:08:40.272Z,1611868120.272 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-01-28T21:08:40.272Z,1611868120.272 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2021-01-28T21:08:43.162Z,1611868123.162 [DataOverHttps](DEBUG): dataRead() @823 received: vehicle=daphne&busy=true 2021-01-28T21:08:43.163Z,1611868123.163 [DataOverHttps](DEBUG): ParseDataRead( data = busy=true, key = 6, value = daphne 2021-01-28T21:08:43.163Z,1611868123.163 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 0, value = true 2021-01-28T21:08:51.630Z,1611868131.630 [DataOverHttps](DEBUG): dataRead() @823 received: vehicle=daphne&busy=true 2021-01-28T21:08:51.631Z,1611868131.631 [DataOverHttps](DEBUG): ParseDataRead( data = busy=true, key = 6, value = daphne 2021-01-28T21:08:51.631Z,1611868131.631 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 0, value = true 2021-01-28T21:08:59.966Z,1611868139.966 [DataOverHttps](DEBUG): dataRead() @823 received: vehicle=daphne&busy=true 2021-01-28T21:08:59.967Z,1611868139.967 [DataOverHttps](DEBUG): ParseDataRead( data = busy=true, key = 6, value = daphne 2021-01-28T21:08:59.967Z,1611868139.967 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 0, value = true 2021-01-28T21:09:00.071Z,1611868140.071 [CommandLine](IMPORTANT): got command configSet DataOverHttps.verbosity 3.000000 count 2021-01-28T21:09:00.969Z,1611868140.969 [DataOverHttps](INFO): platform communications requested and available 2021-01-28T21:09:00.969Z,1611868140.969 [DataOverHttps](INFO): queued: Logs/20201208T213204/Courier0010.lzma 2021-01-28T21:09:00.970Z,1611868140.970 [DataOverHttps](INFO): data state is TCP_CONNECT 2021-01-28T21:09:01.974Z,1611868141.974 [DataOverHttps](INFO): platform communications requested and available 2021-01-28T21:09:01.974Z,1611868141.974 [DataOverHttps](INFO): queued: Logs/20201208T213204/Courier0010.lzma 2021-01-28T21:09:01.974Z,1611868141.974 [DataOverHttps](INFO): data state is TCP_CONNECTING 2021-01-28T21:09:02.977Z,1611868142.977 [DataOverHttps](INFO): platform communications requested and available 2021-01-28T21:09:02.977Z,1611868142.977 [DataOverHttps](INFO): queued: Logs/20201208T213204/Courier0010.lzma 2021-01-28T21:09:02.977Z,1611868142.977 [DataOverHttps](INFO): data state is SSL_CONNECTING 2021-01-28T21:09:08.629Z,1611868148.629 [DataOverHttps](INFO): platform communications requested and available 2021-01-28T21:09:08.629Z,1611868148.629 [DataOverHttps](INFO): queued: Logs/20201208T213204/Courier0010.lzma 2021-01-28T21:09:08.629Z,1611868148.629 [DataOverHttps](INFO): data state is SSL_CONNECTING 2021-01-28T21:09:08.631Z,1611868148.631 [DataOverHttps](IMPORTANT): dataWrite() sendFilename_: Logs/20201208T213204/Courier0010.lzma, busy: 1 2021-01-28T21:09:08.631Z,1611868148.631 [DataOverHttps](IMPORTANT): dataWriting 206 bytes: POST /TethysDash/dataLink HTTP/1.1 User-Agent: LRAUV Host: 134.89.2.23:443 Accept: */* Content-Type: application/x-www-form-urlencoded Content-Length: 40 imei=300234011783940&imeiPassword=4ju-wR 2021-01-28T21:09:08.661Z,1611868148.661 [DataOverHttps](IMPORTANT): dataWriting with SSL WROTE 206 bytes: POST /TethysDash/dataLink HTTP/1.1 User-Agent: LRAUV Host: 134.89.2.23:443 Accept: */* Content-Type: application/x-www-form-urlencoded Content-Length: 40 imei=300234011783940&imeiPassword=4ju-wR 2021-01-28T21:09:09.617Z,1611868149.617 [DataOverHttps](INFO): platform communications requested and available 2021-01-28T21:09:09.618Z,1611868149.618 [DataOverHttps](INFO): queued: Logs/20201208T213204/Courier0010.lzma 2021-01-28T21:09:09.618Z,1611868149.618 [DataOverHttps](INFO): data state is DATA_READ 2021-01-28T21:09:09.619Z,1611868149.619 [DataOverHttps](INFO): dataread() @741 received: 262 2021-01-28T21:09:09.619Z,1611868149.619 [DataOverHttps](INFO): dataRead() @823 received: vehicle=daphne&busy=true 2021-01-28T21:09:09.619Z,1611868149.619 [DataOverHttps](INFO): ParseDataRead( data = busy=true, key = 6, value = daphne 2021-01-28T21:09:09.620Z,1611868149.620 [DataOverHttps](INFO): ParseDataRead( data = , key = 0, value = true 2021-01-28T21:09:10.621Z,1611868150.621 [DataOverHttps](INFO): platform communications requested and available 2021-01-28T21:09:10.621Z,1611868150.621 [DataOverHttps](INFO): queued: Logs/20201208T213204/Courier0010.lzma 2021-01-28T21:09:10.622Z,1611868150.622 [DataOverHttps](INFO): data state is TCP_CONNECT 2021-01-28T21:09:11.625Z,1611868151.625 [DataOverHttps](INFO): platform communications requested and available 2021-01-28T21:09:11.625Z,1611868151.625 [DataOverHttps](INFO): queued: Logs/20201208T213204/Courier0010.lzma 2021-01-28T21:09:11.625Z,1611868151.625 [DataOverHttps](INFO): data state is TCP_CONNECTING 2021-01-28T21:09:12.629Z,1611868152.629 [DataOverHttps](INFO): platform communications requested and available 2021-01-28T21:09:12.629Z,1611868152.629 [DataOverHttps](INFO): queued: Logs/20201208T213204/Courier0010.lzma 2021-01-28T21:09:12.629Z,1611868152.629 [DataOverHttps](INFO): data state is SSL_CONNECTING 2021-01-28T21:09:19.095Z,1611868159.095 [Startup:StartupSatComms:B](INFO): Timed out from 2021-01-28T21:08:18.8Z 2021-01-28T21:09:19.095Z,1611868159.095 [Startup:StartupSatComms:B] Stopped 2021-01-28T21:09:19.095Z,1611868159.095 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2021-01-28T21:09:19.095Z,1611868159.095 [Startup:StartupSatComms] Stopped 2021-01-28T21:09:19.095Z,1611868159.095 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2021-01-28T21:09:19.096Z,1611868159.096 [Startup](INFO): Completed Startup 2021-01-28T21:09:19.096Z,1611868159.096 [MissionManager](INFO): Startup is completed. 2021-01-28T21:09:19.096Z,1611868159.096 [MissionManager](INFO): Uninitializing Mission Startup 2021-01-28T21:09:19.096Z,1611868159.096 [Startup] Stopped 2021-01-28T21:09:19.096Z,1611868159.096 [Startup](DEBUG): Aggregate::uninitialize Startup 2021-01-28T21:09:19.101Z,1611868159.101 [Startup:A.GoToSurface] Stopped 2021-01-28T21:09:19.101Z,1611868159.101 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2021-01-28T21:09:19.534Z,1611868159.534 [MissionManager](IMPORTANT): Started mission Default 2021-01-28T21:09:19.534Z,1611868159.534 [Default] Running Loop=1 2021-01-28T21:09:19.534Z,1611868159.534 [Default](DEBUG): Aggregate::initialize Default 2021-01-28T21:09:19.534Z,1611868159.534 [Default:B.GoToSurface] Running Loop=1 2021-01-28T21:09:19.534Z,1611868159.534 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2021-01-28T21:09:19.535Z,1611868159.535 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2021-01-28T21:09:19.535Z,1611868159.535 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2021-01-28T21:09:19.535Z,1611868159.535 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2021-01-28T21:09:19.535Z,1611868159.535 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2021-01-28T21:09:19.536Z,1611868159.536 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2021-01-28T21:09:19.536Z,1611868159.536 [Default:A.Wait] Running Loop=1 2021-01-28T21:09:19.536Z,1611868159.536 [Default:A.Wait](DEBUG): Initialize Wait Component. 2021-01-28T21:09:20.226Z,1611868160.226 [DataOverHttps](INFO): data state is SSL_CONNECTING 2021-01-28T21:09:21.229Z,1611868161.229 [DataOverHttps](INFO): data state is SSL_CONNECTING 2021-01-28T21:09:21.231Z,1611868161.231 [DataOverHttps](IMPORTANT): dataWrite() sendFilename_: Logs/20201208T213204/Courier0010.lzma, busy: 1 2021-01-28T21:09:21.231Z,1611868161.231 [DataOverHttps](IMPORTANT): dataWriting 206 bytes: POST /TethysDash/dataLink HTTP/1.1 User-Agent: LRAUV Host: 134.89.2.23:443 Accept: */* Content-Type: application/x-www-form-urlencoded Content-Length: 40 imei=300234011783940&imeiPassword=4ju-wR 2021-01-28T21:09:21.232Z,1611868161.232 [DataOverHttps](IMPORTANT): dataWriting with SSL WROTE 206 bytes: POST /TethysDash/dataLink HTTP/1.1 User-Agent: LRAUV Host: 134.89.2.23:443 Accept: */* Content-Type: application/x-www-form-urlencoded Content-Length: 40 imei=300234011783940&imeiPassword=4ju-wR 2021-01-28T21:09:22.233Z,1611868162.233 [DataOverHttps](INFO): data state is DATA_READ 2021-01-28T21:09:22.234Z,1611868162.234 [DataOverHttps](INFO): dataread() @741 received: 262 2021-01-28T21:09:22.234Z,1611868162.234 [DataOverHttps](INFO): dataRead() @823 received: vehicle=daphne&busy=true 2021-01-28T21:09:22.235Z,1611868162.235 [DataOverHttps](INFO): ParseDataRead( data = busy=true, key = 6, value = daphne 2021-01-28T21:09:22.235Z,1611868162.235 [DataOverHttps](INFO): ParseDataRead( data = , key = 0, value = true 2021-01-28T21:09:23.237Z,1611868163.237 [DataOverHttps](INFO): data state is TCP_CONNECT 2021-01-28T21:09:24.241Z,1611868164.241 [DataOverHttps](INFO): data state is TCP_CONNECTING 2021-01-28T21:09:25.245Z,1611868165.245 [DataOverHttps](INFO): data state is SSL_CONNECTING 2021-01-28T21:09:28.568Z,1611868168.568 [DataOverHttps](INFO): data state is SSL_CONNECTING 2021-01-28T21:09:29.569Z,1611868169.569 [DataOverHttps](INFO): data state is SSL_CONNECTING 2021-01-28T21:09:29.571Z,1611868169.571 [DataOverHttps](IMPORTANT): dataWrite() sendFilename_: Logs/20201208T213204/Courier0010.lzma, busy: 1 2021-01-28T21:09:29.571Z,1611868169.571 [DataOverHttps](IMPORTANT): dataWriting 206 bytes: POST /TethysDash/dataLink HTTP/1.1 User-Agent: LRAUV Host: 134.89.2.23:443 Accept: */* Content-Type: application/x-www-form-urlencoded Content-Length: 40 imei=300234011783940&imeiPassword=4ju-wR 2021-01-28T21:09:29.572Z,1611868169.572 [DataOverHttps](IMPORTANT): dataWriting with SSL WROTE 206 bytes: POST /TethysDash/dataLink HTTP/1.1 User-Agent: LRAUV Host: 134.89.2.23:443 Accept: */* Content-Type: application/x-www-form-urlencoded Content-Length: 40 imei=300234011783940&imeiPassword=4ju-wR 2021-01-28T21:09:30.573Z,1611868170.573 [DataOverHttps](INFO): data state is DATA_READ 2021-01-28T21:09:30.575Z,1611868170.575 [DataOverHttps](INFO): dataread() @741 received: 262 2021-01-28T21:09:30.575Z,1611868170.575 [DataOverHttps](INFO): dataRead() @823 received: vehicle=daphne&busy=true 2021-01-28T21:09:30.575Z,1611868170.575 [DataOverHttps](INFO): ParseDataRead( data = busy=true, key = 6, value = daphne 2021-01-28T21:09:30.576Z,1611868170.576 [DataOverHttps](INFO): ParseDataRead( data = , key = 0, value = true 2021-01-28T21:09:31.577Z,1611868171.577 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:09:32.581Z,1611868172.581 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:09:32.816Z,1611868172.816 [Default:A.Wait](INFO): Done Waiting. 2021-01-28T21:09:32.816Z,1611868172.816 [Default:A.Wait] Stopped 2021-01-28T21:09:32.816Z,1611868172.816 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2021-01-28T21:09:33.224Z,1611868173.224 [Default:CheckIn] Running Loop=1 2021-01-28T21:09:33.224Z,1611868173.224 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-01-28T21:09:33.224Z,1611868173.224 [Default:CheckIn:Read_GPS] Running Loop=1 2021-01-28T21:09:33.585Z,1611868173.585 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:09:33.622Z,1611868173.622 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2021-01-28T21:09:34.589Z,1611868174.589 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:09:35.593Z,1611868175.593 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:09:36.597Z,1611868176.597 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:09:37.601Z,1611868177.601 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:09:38.605Z,1611868178.605 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:09:39.609Z,1611868179.609 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:09:40.613Z,1611868180.613 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:09:41.617Z,1611868181.617 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:09:42.621Z,1611868182.621 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:09:43.625Z,1611868183.625 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:09:44.629Z,1611868184.629 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:09:45.633Z,1611868185.633 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:09:46.637Z,1611868186.637 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:09:47.641Z,1611868187.641 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:09:48.645Z,1611868188.645 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:09:49.649Z,1611868189.649 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:09:50.653Z,1611868190.653 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:09:51.657Z,1611868191.657 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:09:52.661Z,1611868192.661 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:09:53.665Z,1611868193.665 [DataOverHttps](INFO): data state is TCP_CONNECT 2021-01-28T21:09:54.669Z,1611868194.669 [DataOverHttps](INFO): data state is TCP_CONNECTING 2021-01-28T21:09:55.673Z,1611868195.673 [DataOverHttps](INFO): data state is SSL_CONNECTING 2021-01-28T21:09:58.865Z,1611868198.865 [DataOverHttps](INFO): data state is SSL_CONNECTING 2021-01-28T21:09:59.869Z,1611868199.869 [DataOverHttps](INFO): data state is SSL_CONNECTING 2021-01-28T21:09:59.871Z,1611868199.871 [DataOverHttps](IMPORTANT): dataWrite() sendFilename_: Logs/20201208T213204/Courier0010.lzma, busy: 1 2021-01-28T21:09:59.871Z,1611868199.871 [DataOverHttps](IMPORTANT): dataWriting 206 bytes: POST /TethysDash/dataLink HTTP/1.1 User-Agent: LRAUV Host: 134.89.2.23:443 Accept: */* Content-Type: application/x-www-form-urlencoded Content-Length: 40 imei=300234011783940&imeiPassword=4ju-wR 2021-01-28T21:09:59.873Z,1611868199.873 [DataOverHttps](IMPORTANT): dataWriting with SSL WROTE 206 bytes: POST /TethysDash/dataLink HTTP/1.1 User-Agent: LRAUV Host: 134.89.2.23:443 Accept: */* Content-Type: application/x-www-form-urlencoded Content-Length: 40 imei=300234011783940&imeiPassword=4ju-wR 2021-01-28T21:10:00.873Z,1611868200.873 [DataOverHttps](INFO): data state is DATA_READ 2021-01-28T21:10:00.874Z,1611868200.874 [DataOverHttps](INFO): dataread() @741 received: 262 2021-01-28T21:10:00.874Z,1611868200.874 [DataOverHttps](INFO): dataRead() @823 received: vehicle=daphne&busy=true 2021-01-28T21:10:00.875Z,1611868200.875 [DataOverHttps](INFO): ParseDataRead( data = busy=true, key = 6, value = daphne 2021-01-28T21:10:00.875Z,1611868200.875 [DataOverHttps](INFO): ParseDataRead( data = , key = 0, value = true 2021-01-28T21:10:01.877Z,1611868201.877 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:02.881Z,1611868202.881 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:03.885Z,1611868203.885 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:04.889Z,1611868204.889 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:05.893Z,1611868205.893 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:06.897Z,1611868206.897 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:07.901Z,1611868207.901 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:08.905Z,1611868208.905 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:09.909Z,1611868209.909 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:10.913Z,1611868210.913 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:11.917Z,1611868211.917 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:12.921Z,1611868212.921 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:13.925Z,1611868213.925 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:14.929Z,1611868214.929 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:15.933Z,1611868215.933 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:16.937Z,1611868216.937 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:17.941Z,1611868217.941 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:18.945Z,1611868218.945 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:19.949Z,1611868219.949 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:20.953Z,1611868220.953 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:21.957Z,1611868221.957 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:22.961Z,1611868222.961 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:23.965Z,1611868223.965 [DataOverHttps](INFO): data state is TCP_CONNECT 2021-01-28T21:10:24.969Z,1611868224.969 [DataOverHttps](INFO): data state is TCP_CONNECTING 2021-01-28T21:10:25.973Z,1611868225.973 [DataOverHttps](INFO): data state is SSL_CONNECTING 2021-01-28T21:10:29.130Z,1611868229.130 [DataOverHttps](INFO): data state is SSL_CONNECTING 2021-01-28T21:10:30.133Z,1611868230.133 [DataOverHttps](INFO): data state is SSL_CONNECTING 2021-01-28T21:10:30.135Z,1611868230.135 [DataOverHttps](IMPORTANT): dataWrite() sendFilename_: Logs/20201208T213204/Courier0010.lzma, busy: 1 2021-01-28T21:10:30.135Z,1611868230.135 [DataOverHttps](IMPORTANT): dataWriting 206 bytes: POST /TethysDash/dataLink HTTP/1.1 User-Agent: LRAUV Host: 134.89.2.23:443 Accept: */* Content-Type: application/x-www-form-urlencoded Content-Length: 40 imei=300234011783940&imeiPassword=4ju-wR 2021-01-28T21:10:30.137Z,1611868230.137 [DataOverHttps](IMPORTANT): dataWriting with SSL WROTE 206 bytes: POST /TethysDash/dataLink HTTP/1.1 User-Agent: LRAUV Host: 134.89.2.23:443 Accept: */* Content-Type: application/x-www-form-urlencoded Content-Length: 40 imei=300234011783940&imeiPassword=4ju-wR 2021-01-28T21:10:31.137Z,1611868231.137 [DataOverHttps](INFO): data state is DATA_READ 2021-01-28T21:10:31.138Z,1611868231.138 [DataOverHttps](INFO): dataread() @741 received: 262 2021-01-28T21:10:31.138Z,1611868231.138 [DataOverHttps](INFO): dataRead() @823 received: vehicle=daphne&busy=true 2021-01-28T21:10:31.139Z,1611868231.139 [DataOverHttps](INFO): ParseDataRead( data = busy=true, key = 6, value = daphne 2021-01-28T21:10:31.139Z,1611868231.139 [DataOverHttps](INFO): ParseDataRead( data = , key = 0, value = true 2021-01-28T21:10:32.141Z,1611868232.141 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:33.145Z,1611868233.145 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:34.149Z,1611868234.149 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:35.153Z,1611868235.153 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:36.157Z,1611868236.157 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:37.162Z,1611868237.162 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:38.165Z,1611868238.165 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:39.169Z,1611868239.169 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:40.173Z,1611868240.173 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:41.177Z,1611868241.177 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:42.181Z,1611868242.181 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:43.185Z,1611868243.185 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:44.189Z,1611868244.189 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:45.201Z,1611868245.201 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:46.205Z,1611868246.205 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:47.209Z,1611868247.209 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:48.213Z,1611868248.213 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:49.217Z,1611868249.217 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:50.221Z,1611868250.221 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:51.225Z,1611868251.225 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:52.229Z,1611868252.229 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:53.233Z,1611868253.233 [DataOverHttps](INFO): data state is DISCONNECTED 2021-01-28T21:10:54.237Z,1611868254.237 [DataOverHttps](INFO): data state is TCP_CONNECT 2021-01-28T21:10:55.241Z,1611868255.241 [DataOverHttps](INFO): data state is TCP_CONNECTING 2021-01-28T21:10:56.245Z,1611868256.245 [DataOverHttps](INFO): data state is SSL_CONNECTING