2019-08-28T04:19:37.099Z,1566965977.099 [Supervisor](DEBUG): Initializing supervisor. 2019-08-28T04:19:37.102Z,1566965977.102 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2019-08-28T04:19:37.103Z,1566965977.103 [SyncHandler](INFO): Protected caller Thread ID is 2758 2019-08-28T04:19:37.104Z,1566965977.104 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2019-08-28T04:19:37.105Z,1566965977.105 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2019-08-28T04:19:37.105Z,1566965977.105 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2759 2019-08-28T04:19:37.109Z,1566965977.109 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2019-08-28T04:19:37.120Z,1566965977.120 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2019-08-28T04:19:37.121Z,1566965977.121 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2019-08-28T04:19:37.121Z,1566965977.121 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2760 2019-08-28T04:19:37.122Z,1566965977.122 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2019-08-28T04:19:37.123Z,1566965977.123 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2019-08-28T04:19:37.123Z,1566965977.123 [logger ThreadHandler](INFO): Protected caller Thread ID is 2761 2019-08-28T04:19:37.125Z,1566965977.125 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2019-08-28T04:19:37.126Z,1566965977.126 [Supervisor](INFO): Looking for Config files in directory: Config/ 2019-08-28T04:19:37.127Z,1566965977.127 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2019-08-28T04:19:37.223Z,1566965977.223 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2019-08-28T04:19:37.223Z,1566965977.223 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2019-08-28T04:19:37.768Z,1566965977.768 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2019-08-28T04:19:37.769Z,1566965977.769 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2019-08-28T04:19:37.867Z,1566965977.867 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2019-08-28T04:19:37.867Z,1566965977.867 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2019-08-28T04:19:37.969Z,1566965977.969 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2019-08-28T04:19:37.969Z,1566965977.969 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2019-08-28T04:19:38.053Z,1566965978.053 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2019-08-28T04:19:38.529Z,1566965978.529 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2019-08-28T04:19:38.529Z,1566965978.529 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2019-08-28T04:19:38.818Z,1566965978.818 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2019-08-28T04:19:38.818Z,1566965978.818 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2019-08-28T04:19:39.263Z,1566965979.263 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2019-08-28T04:19:39.263Z,1566965979.263 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2019-08-28T04:19:39.406Z,1566965979.406 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2019-08-28T04:19:39.407Z,1566965979.407 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2019-08-28T04:19:39.601Z,1566965979.601 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2019-08-28T04:19:39.602Z,1566965979.602 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2019-08-28T04:19:40.044Z,1566965980.044 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2019-08-28T04:19:40.044Z,1566965980.044 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2019-08-28T04:19:40.253Z,1566965980.253 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2019-08-28T04:19:40.254Z,1566965980.254 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2019-08-28T04:19:40.453Z,1566965980.453 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2019-08-28T04:19:40.453Z,1566965980.453 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2019-08-28T04:19:40.863Z,1566965980.863 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2019-08-28T04:19:40.864Z,1566965980.864 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2019-08-28T04:19:41.189Z,1566965981.189 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2019-08-28T04:19:41.191Z,1566965981.191 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/ 2019-08-28T04:19:41.192Z,1566965981.192 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg 2019-08-28T04:19:41.276Z,1566965981.276 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg 2019-08-28T04:19:41.430Z,1566965981.430 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg 2019-08-28T04:19:41.538Z,1566965981.538 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg 2019-08-28T04:19:41.623Z,1566965981.623 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg 2019-08-28T04:19:41.718Z,1566965981.718 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg 2019-08-28T04:19:41.909Z,1566965981.909 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg 2019-08-28T04:19:42.134Z,1566965982.134 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2019-08-28T04:19:42.135Z,1566965982.135 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg 2019-08-28T04:19:42.229Z,1566965982.229 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg 2019-08-28T04:19:42.326Z,1566965982.326 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg 2019-08-28T04:19:42.445Z,1566965982.445 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg 2019-08-28T04:19:42.546Z,1566965982.546 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/root/ 2019-08-28T04:19:42.546Z,1566965982.546 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2019-08-28T04:19:42.550Z,1566965982.550 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2019-08-28T04:19:42.616Z,1566965982.616 [VerticalControl](DEBUG): Construct VerticalControl. 2019-08-28T04:19:42.724Z,1566965982.724 [VerticalControl] Loaded 2019-08-28T04:19:42.724Z,1566965982.724 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2019-08-28T04:19:42.725Z,1566965982.725 [HorizontalControl](DEBUG): Construct HorizontalControl. 2019-08-28T04:19:42.791Z,1566965982.791 [HorizontalControl] Loaded 2019-08-28T04:19:42.791Z,1566965982.791 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2019-08-28T04:19:42.792Z,1566965982.792 [SpeedControl](DEBUG): Construct SpeedControl. 2019-08-28T04:19:42.797Z,1566965982.797 [SpeedControl] Loaded 2019-08-28T04:19:42.798Z,1566965982.798 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2019-08-28T04:19:42.798Z,1566965982.798 [LoopControl](DEBUG): Construct LoopControl. 2019-08-28T04:19:42.799Z,1566965982.799 [LoopControl] Loaded 2019-08-28T04:19:42.799Z,1566965982.799 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2019-08-28T04:19:42.799Z,1566965982.799 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2019-08-28T04:19:42.800Z,1566965982.800 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2019-08-28T04:19:42.840Z,1566965982.840 [DepthRateCalculator] Loaded 2019-08-28T04:19:42.840Z,1566965982.840 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2019-08-28T04:19:42.845Z,1566965982.845 [PitchRateCalculator] Loaded 2019-08-28T04:19:42.845Z,1566965982.845 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2019-08-28T04:19:42.860Z,1566965982.860 [SpeedCalculator] Loaded 2019-08-28T04:19:42.860Z,1566965982.860 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2019-08-28T04:19:42.880Z,1566965982.880 [TempGradientCalculator] Loaded 2019-08-28T04:19:42.880Z,1566965982.880 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2019-08-28T04:19:42.885Z,1566965982.885 [YawRateCalculator] Loaded 2019-08-28T04:19:42.885Z,1566965982.885 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2019-08-28T04:19:42.913Z,1566965982.913 [ElevatorOffsetCalculator] Loaded 2019-08-28T04:19:42.914Z,1566965982.914 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2019-08-28T04:19:42.914Z,1566965982.914 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2019-08-28T04:19:42.915Z,1566965982.915 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2019-08-28T04:19:42.946Z,1566965982.946 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2019-08-28T04:19:42.947Z,1566965982.947 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2019-08-28T04:19:43.019Z,1566965983.019 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2019-08-28T04:19:43.019Z,1566965983.019 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2019-08-28T04:19:43.296Z,1566965983.296 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2019-08-28T04:19:43.296Z,1566965983.296 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2019-08-28T04:19:43.537Z,1566965983.537 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2019-08-28T04:19:43.538Z,1566965983.538 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2019-08-28T04:19:44.402Z,1566965984.402 [AHRS_M2] Loaded 2019-08-28T04:19:44.403Z,1566965984.403 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2019-08-28T04:19:44.475Z,1566965984.475 [DataOverHttps] Loaded 2019-08-28T04:19:44.475Z,1566965984.475 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2019-08-28T04:19:44.476Z,1566965984.476 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408CA4E0 2019-08-28T04:19:44.476Z,1566965984.476 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 2840 2019-08-28T04:19:44.489Z,1566965984.489 [Depth_Keller] Loaded 2019-08-28T04:19:44.489Z,1566965984.489 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2019-08-28T04:19:44.494Z,1566965984.494 [DropWeight] Loaded 2019-08-28T04:19:44.494Z,1566965984.494 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2019-08-28T04:19:44.588Z,1566965984.588 [NAL9602] Loaded 2019-08-28T04:19:44.588Z,1566965984.588 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2019-08-28T04:19:44.603Z,1566965984.603 [Onboard] Loaded 2019-08-28T04:19:44.603Z,1566965984.603 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2019-08-28T04:19:44.607Z,1566965984.607 [Radio_Surface] Loaded 2019-08-28T04:19:44.607Z,1566965984.607 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2019-08-28T04:19:44.608Z,1566965984.608 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408FA4E0 2019-08-28T04:19:44.608Z,1566965984.608 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2841 2019-08-28T04:19:44.777Z,1566965984.777 [Rowe_600] Loaded 2019-08-28T04:19:44.778Z,1566965984.778 [ComponentRegistry](DEBUG): Component "Rowe_600" handled in its own thread. 2019-08-28T04:19:44.779Z,1566965984.779 [Rowe_600 ThreadHandler](DEBUG): Created PCaller Thread at 4092A4E0 2019-08-28T04:19:44.779Z,1566965984.779 [Rowe_600 ThreadHandler](INFO): Protected caller Thread ID is 2842 2019-08-28T04:19:46.225Z,1566965986.225 [BPC1] Loaded 2019-08-28T04:19:46.225Z,1566965986.225 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2019-08-28T04:19:46.225Z,1566965986.225 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2019-08-28T04:19:46.226Z,1566965986.226 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2019-08-28T04:19:46.326Z,1566965986.326 [DeadReckonUsingMultipleVelocitySources] Loaded 2019-08-28T04:19:46.326Z,1566965986.326 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2019-08-28T04:19:46.345Z,1566965986.345 [NavChart] Loaded 2019-08-28T04:19:46.346Z,1566965986.346 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2019-08-28T04:19:46.350Z,1566965986.350 [UniversalFixResidualReporter] Loaded 2019-08-28T04:19:46.350Z,1566965986.350 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2019-08-28T04:19:46.350Z,1566965986.350 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2019-08-28T04:19:46.351Z,1566965986.351 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2019-08-28T04:19:46.480Z,1566965986.480 [SBIT](DEBUG): Construct Startup Built In Test. 2019-08-28T04:19:46.491Z,1566965986.491 [SBIT] Loaded 2019-08-28T04:19:46.491Z,1566965986.491 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2019-08-28T04:19:46.492Z,1566965986.492 [IBIT](DEBUG): Construct Initiated Built In Test. 2019-08-28T04:19:46.503Z,1566965986.503 [IBIT] Loaded 2019-08-28T04:19:46.504Z,1566965986.504 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2019-08-28T04:19:46.507Z,1566965986.507 [CBIT](DEBUG): Construct Continuous Built In Test. 2019-08-28T04:19:46.640Z,1566965986.640 [CBIT] Loaded 2019-08-28T04:19:46.640Z,1566965986.640 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2019-08-28T04:19:46.641Z,1566965986.641 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2019-08-28T04:19:46.641Z,1566965986.641 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2019-08-28T04:19:46.743Z,1566965986.743 [BuoyancyServo] Loaded 2019-08-28T04:19:46.743Z,1566965986.743 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2019-08-28T04:19:46.754Z,1566965986.754 [ElevatorServo] Loaded 2019-08-28T04:19:46.755Z,1566965986.755 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2019-08-28T04:19:46.766Z,1566965986.766 [MassServo] Loaded 2019-08-28T04:19:46.766Z,1566965986.766 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2019-08-28T04:19:46.777Z,1566965986.777 [RudderServo] Loaded 2019-08-28T04:19:46.777Z,1566965986.777 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2019-08-28T04:19:46.788Z,1566965986.788 [ThrusterServo] Loaded 2019-08-28T04:19:46.788Z,1566965986.788 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2019-08-28T04:19:46.788Z,1566965986.788 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2019-08-28T04:19:46.789Z,1566965986.789 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2019-08-28T04:19:46.803Z,1566965986.803 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2019-08-28T04:19:46.803Z,1566965986.803 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2019-08-28T04:19:46.975Z,1566965986.975 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density 2019-08-28T04:19:46.981Z,1566965986.981 [CTD_Seabird](INFO): created writer for : sea_water_density 2019-08-28T04:19:46.983Z,1566965986.983 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth 2019-08-28T04:19:46.987Z,1566965986.987 [CTD_Seabird](INFO): created writer for : depth 2019-08-28T04:19:46.988Z,1566965986.988 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure 2019-08-28T04:19:46.993Z,1566965986.993 [CTD_Seabird](INFO): created writer for : sea_water_pressure 2019-08-28T04:19:46.993Z,1566965986.993 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity 2019-08-28T04:19:46.999Z,1566965986.999 [CTD_Seabird](INFO): created writer for : sea_water_salinity 2019-08-28T04:19:46.999Z,1566965986.999 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature 2019-08-28T04:19:47.004Z,1566965987.004 [CTD_Seabird](INFO): created writer for : sea_water_temperature 2019-08-28T04:19:47.005Z,1566965987.005 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity 2019-08-28T04:19:47.010Z,1566965987.010 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity 2019-08-28T04:19:47.011Z,1566965987.011 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water 2019-08-28T04:19:47.015Z,1566965987.015 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water 2019-08-28T04:19:47.042Z,1566965987.042 [CTD_Seabird] Loaded 2019-08-28T04:19:47.042Z,1566965987.042 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2019-08-28T04:19:47.043Z,1566965987.043 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40AAF4E0 2019-08-28T04:19:47.044Z,1566965987.044 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 2843 2019-08-28T04:19:47.091Z,1566965987.091 [WetLabsBB2FL] Loaded 2019-08-28T04:19:47.091Z,1566965987.091 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2019-08-28T04:19:47.092Z,1566965987.092 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40ADF4E0 2019-08-28T04:19:47.093Z,1566965987.093 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 2844 2019-08-28T04:19:47.093Z,1566965987.093 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2019-08-28T04:19:47.097Z,1566965987.097 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2019-08-28T04:19:47.098Z,1566965987.098 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2019-08-28T04:19:47.105Z,1566965987.105 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2019-08-28T04:19:47.106Z,1566965987.106 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B0F4E0 2019-08-28T04:19:47.106Z,1566965987.106 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2845 2019-08-28T04:19:47.111Z,1566965987.111 [Supervisor](INFO): Main Thread ID is 2133 2019-08-28T04:19:47.111Z,1566965987.111 [Supervisor](DEBUG): Running supervisor. 2019-08-28T04:19:47.112Z,1566965987.112 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2846 2019-08-28T04:19:47.114Z,1566965987.114 [controlThread ThreadHandler](INFO): Handler Thread ID is 2847 2019-08-28T04:19:47.115Z,1566965987.115 [controlThread](DEBUG): Initializing ControlThread 2019-08-28T04:19:47.115Z,1566965987.115 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2019-08-28T04:19:47.117Z,1566965987.117 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2019-08-28T04:19:47.118Z,1566965987.118 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2019-08-28T04:19:47.118Z,1566965987.118 [LoopControl](DEBUG): Initialize LoopControlComponent. 2019-08-28T04:19:47.118Z,1566965987.118 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2019-08-28T04:19:47.119Z,1566965987.119 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2019-08-28T04:19:47.119Z,1566965987.119 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2019-08-28T04:19:47.119Z,1566965987.119 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2019-08-28T04:19:47.120Z,1566965987.120 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2019-08-28T04:19:47.120Z,1566965987.120 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2019-08-28T04:19:47.128Z,1566965987.128 [NavChart](DEBUG): Initialize NavChart Navigation. 2019-08-28T04:19:47.128Z,1566965987.128 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2019-08-28T04:19:47.128Z,1566965987.128 [SBIT](INFO): Initialize SBIT Component. 2019-08-28T04:19:47.129Z,1566965987.129 [SBIT](IMPORTANT): git: 2019-08-13-6-g4aae551 2019-08-28T04:19:47.129Z,1566965987.129 [SBIT](INFO): git hash: 4aae551959fa3237669caaf032899fc457a0fca0 2019-08-28T04:19:47.129Z,1566965987.129 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2019-08-28T04:19:47.129Z,1566965987.129 [SBIT](IMPORTANT): Kernel Version:#1 PREEMPT Thu Feb 21 11:17:40 PST 2019 2019-08-28T04:19:47.131Z,1566965987.131 [SBIT](INFO): Beginning SBIT in 59.000000 seconds. 2019-08-28T04:19:47.131Z,1566965987.131 [IBIT](INFO): Initialize IBIT Component. 2019-08-28T04:19:47.132Z,1566965987.132 [CBIT](DEBUG): Initialize CBIT Component. 2019-08-28T04:19:47.133Z,1566965987.133 [logger ThreadHandler](INFO): Handler Thread ID is 2848 2019-08-28T04:19:47.145Z,1566965987.145 [CBIT](DEBUG): Initialized mux pins. 2019-08-28T04:19:47.145Z,1566965987.145 [CBIT](DEBUG): Initializing the watchdog timer. 2019-08-28T04:19:47.153Z,1566965987.153 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 2849 2019-08-28T04:19:47.154Z,1566965987.154 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2019-08-28T04:19:47.165Z,1566965987.165 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2850 2019-08-28T04:19:47.169Z,1566965987.169 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET. 2019-08-28T04:19:47.169Z,1566965987.169 [CBIT](DEBUG): Initializing heartbeat. 2019-08-28T04:19:47.177Z,1566965987.177 [Rowe_600 ThreadHandler](INFO): Handler Thread ID is 2851 2019-08-28T04:19:47.189Z,1566965987.189 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 2852 2019-08-28T04:19:47.190Z,1566965987.190 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2019-08-28T04:19:47.193Z,1566965987.193 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20 2019-08-28T04:19:47.194Z,1566965987.194 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 2854 2019-08-28T04:19:47.196Z,1566965987.196 [WetLabsBB2FL](INFO): Powering down 2019-08-28T04:19:47.222Z,1566965987.222 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2855 2019-08-28T04:19:47.226Z,1566965987.226 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2019-08-28T04:19:47.226Z,1566965987.226 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2019-08-28T04:19:47.226Z,1566965987.226 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2019-08-28T04:19:47.226Z,1566965987.226 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2019-08-28T04:19:47.227Z,1566965987.227 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2019-08-28T04:19:47.227Z,1566965987.227 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2019-08-28T04:19:47.227Z,1566965987.227 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2019-08-28T04:19:47.227Z,1566965987.227 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2019-08-28T04:19:47.227Z,1566965987.227 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2019-08-28T04:19:47.227Z,1566965987.227 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2019-08-28T04:19:47.228Z,1566965987.228 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2019-08-28T04:19:47.228Z,1566965987.228 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2019-08-28T04:19:47.228Z,1566965987.228 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2019-08-28T04:19:47.228Z,1566965987.228 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2019-08-28T04:19:47.228Z,1566965987.228 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2019-08-28T04:19:47.228Z,1566965987.228 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2019-08-28T04:19:47.241Z,1566965987.241 [CBIT](DEBUG): Deactivating GF circuits. 2019-08-28T04:19:47.241Z,1566965987.241 [CBIT](DEBUG): Deactivating emergency mode. 2019-08-28T04:19:47.277Z,1566965987.277 [CBIT](DEBUG): Backplane powered. 2019-08-28T04:19:47.279Z,1566965987.279 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2019-08-28T04:19:47.290Z,1566965987.290 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2019-08-28T04:19:47.313Z,1566965987.313 [MissionManager](DEBUG): 2019-08-28T04:19:47.321Z,1566965987.321 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2019-08-28T04:19:47.375Z,1566965987.375 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2019-08-28T04:19:47.376Z,1566965987.376 [Default:A.Wait](DEBUG): Construct Wait. 2019-08-28T04:19:47.404Z,1566965987.404 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2019-08-28T04:19:47.437Z,1566965987.437 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2019-08-28T04:19:47.440Z,1566965987.440 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2019-08-28T04:19:47.453Z,1566965987.453 [Rowe_600](INFO): Powering down 2019-08-28T04:19:47.481Z,1566965987.481 [Default:E.Execute](DEBUG): Construct Execute. 2019-08-28T04:19:47.500Z,1566965987.500 [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-08-28T04:19:47.516Z,1566965987.516 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,Onboard,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2019-08-28T04:19:47.533Z,1566965987.533 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-08-28T04:19:47.569Z,1566965987.569 [Radio_Surface](INFO): Powering up 2019-08-28T04:19:47.656Z,1566965987.656 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2019-08-28T04:19:47.661Z,1566965987.661 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2019-08-28T04:19:47.662Z,1566965987.662 [ElevatorServo](DEBUG): Initializing EZServoServo. 2019-08-28T04:19:47.669Z,1566965987.669 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2019-08-28T04:19:47.670Z,1566965987.670 [MassServo](DEBUG): Initializing EZServoServo. 2019-08-28T04:19:47.677Z,1566965987.677 [Rowe_600](INFO): Data requested. STOPPED ==> START 2019-08-28T04:19:47.677Z,1566965987.677 [Rowe_600](INFO): Initializing 2019-08-28T04:19:47.679Z,1566965987.679 [MassServo](DEBUG): Initializing MassServo. 2019-08-28T04:19:47.680Z,1566965987.680 [RudderServo](DEBUG): Initializing EZServoServo. 2019-08-28T04:19:47.698Z,1566965987.698 [RudderServo](DEBUG): Initializing RudderServo. 2019-08-28T04:19:47.698Z,1566965987.698 [ThrusterServo](DEBUG): Initializing EZServoServo. 2019-08-28T04:19:47.701Z,1566965987.701 [Rowe_600](INFO): Powering up 2019-08-28T04:19:47.713Z,1566965987.713 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2019-08-28T04:19:47.715Z,1566965987.715 [CommandLine](FAULT): Scheduling is paused 2019-08-28T04:19:47.715Z,1566965987.715 [CBIT](INFO): Critical error at 20190828T041947 2019-08-28T04:19:47.716Z,1566965987.716 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2019-08-28T04:19:47.942Z,1566965987.942 [Depth_Keller](ERROR): Pressure reading out of range: 1650.297119 decibar 2019-08-28T04:19:48.661Z,1566965988.661 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2019-08-28T04:19:48.661Z,1566965988.661 [RudderServo](FAULT): Rudder failed to initialize 2019-08-28T04:19:48.661Z,1566965988.661 [RudderServo] Communications Fault, FailCount= 1 2019-08-28T04:19:48.661Z,1566965988.661 [RudderServo](ERROR): Communications Fault 2019-08-28T04:19:48.772Z,1566965988.772 [CBIT](ERROR): Communications Fault in component: RudderServo 2019-08-28T04:19:48.934Z,1566965988.934 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-08-28T04:19:48.934Z,1566965988.934 [RudderServo](INFO): Powering down 2019-08-28T04:19:49.616Z,1566965989.616 [RudderServo](DEBUG): Initializing EZServoServo. 2019-08-28T04:19:49.750Z,1566965989.750 [RudderServo](DEBUG): Initializing RudderServo. 2019-08-28T04:19:49.754Z,1566965989.754 [CBIT](INFO): Clearing failed state for component RudderServo 2019-08-28T04:19:49.754Z,1566965989.754 [RudderServo] No Fault, FailCount= 1 2019-08-28T04:20:14.647Z,1566966014.647 [NAL9602](INFO): Powering up NAL9602 2019-08-28T04:20:25.555Z,1566966025.555 [NAL9602](INFO): NAL9602 initialized 2019-08-28T04:20:26.377Z,1566966026.377 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:20:46.589Z,1566966046.589 [SBIT](IMPORTANT): Beginning Startup BIT 2019-08-28T04:20:46.593Z,1566966046.593 [CBIT](IMPORTANT): Beginning ground fault scan 2019-08-28T04:20:57.650Z,1566966057.650 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.008412 CHAN A1 (24V): 0.005718 CHAN A2 (12V): -0.005758 CHAN A3 (5V): -0.002571 CHAN B0 (3.3V): -0.000145 CHAN B1 (3.15aV): -0.000396 CHAN B2 (3.15bV): 0.000187 CHAN B3 (GND): 0.002213 OPEN: 0.006945 Full Scale Calc: 4.765 mA, -1.589 mA 2019-08-28T04:21:29.267Z,1566966089.267 [NAL9602](INFO): SBD MO Status=0, MOMSN=176, MT Status=0, MTMSN=0 2019-08-28T04:21:29.267Z,1566966089.267 [NAL9602](INFO): No messages in MT queue 2019-08-28T04:21:30.081Z,1566966090.081 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:21:32.501Z,1566966092.501 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:21:35.329Z,1566966095.329 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:21:38.157Z,1566966098.157 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:21:40.198Z,1566966100.198 [SBIT](IMPORTANT): SBIT PASSED 2019-08-28T04:21:40.270Z,1566966100.270 [CommandLine](IMPORTANT): got command configSet list 2019-08-28T04:21:40.270Z,1566966100.270 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2019-08-28T04:21:40.271Z,1566966100.271 [CommandLine](IMPORTANT): Micromodem.loadAtStartup=0 bool; 2019-08-28T04:21:40.271Z,1566966100.271 [CommandLine](IMPORTANT): VerticalControl.massDefault=10 millimeter; 2019-08-28T04:21:40.602Z,1566966100.602 [MissionManager](IMPORTANT): Started mission Startup 2019-08-28T04:21:40.602Z,1566966100.602 [Startup] Running Loop=1 2019-08-28T04:21:40.603Z,1566966100.603 [Startup](DEBUG): Aggregate::initialize Startup 2019-08-28T04:21:40.603Z,1566966100.603 [Startup:A.GoToSurface] Running Loop=1 2019-08-28T04:21:40.603Z,1566966100.603 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-08-28T04:21:40.603Z,1566966100.603 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-08-28T04:21:40.604Z,1566966100.604 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-08-28T04:21:40.604Z,1566966100.604 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-08-28T04:21:40.605Z,1566966100.605 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-08-28T04:21:40.605Z,1566966100.605 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-08-28T04:21:40.606Z,1566966100.606 [Startup:StartupSatComms] Running Loop=1 2019-08-28T04:21:40.607Z,1566966100.607 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2019-08-28T04:21:40.607Z,1566966100.607 [Startup:StartupSatComms:A] Running Loop=1 2019-08-28T04:21:41.009Z,1566966101.009 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2019-08-28T04:21:41.393Z,1566966101.393 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:21:44.217Z,1566966104.217 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:21:47.453Z,1566966107.453 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:21:50.281Z,1566966110.281 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:21:53.509Z,1566966113.509 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:21:56.333Z,1566966116.333 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:21:59.569Z,1566966119.569 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:22:02.397Z,1566966122.397 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:22:05.225Z,1566966125.225 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:22:08.453Z,1566966128.453 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:22:11.287Z,1566966131.287 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:22:14.520Z,1566966134.520 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:22:17.373Z,1566966137.373 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:22:20.225Z,1566966140.225 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:22:23.492Z,1566966143.492 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:22:26.305Z,1566966146.305 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:22:28.830Z,1566966148.830 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004382 2019-08-28T04:22:29.549Z,1566966149.549 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:22:32.365Z,1566966152.365 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:22:35.605Z,1566966155.605 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:22:38.425Z,1566966158.425 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:22:40.862Z,1566966160.862 [Startup:StartupSatComms:A](INFO): Timed out from 2019-08-28T04:21:40.6Z 2019-08-28T04:22:40.862Z,1566966160.862 [Startup:StartupSatComms:A] Stopped 2019-08-28T04:22:40.862Z,1566966160.862 [Startup:StartupSatComms:B] Running Loop=1 2019-08-28T04:22:41.253Z,1566966161.253 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:22:41.279Z,1566966161.279 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-08-28T04:22:41.887Z,1566966161.887 [DataOverHttps](INFO): GetToShoreFilename: data dir is Logs/20190828T041937 2019-08-28T04:22:41.887Z,1566966161.887 [DataOverHttps](INFO): GetToShoreFilename: active shore file is Logs/20190828T041937/Courier0004 2019-08-28T04:22:44.269Z,1566966164.269 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:22:47.489Z,1566966167.489 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:22:47.509Z,1566966167.509 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2019-08-28T04:22:47.509Z,1566966167.509 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-08-28T04:22:47.523Z,1566966167.523 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-08-28T04:22:47.938Z,1566966167.938 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-08-28T04:22:47.938Z,1566966167.938 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2019-08-28T04:22:50.317Z,1566966170.317 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:22:51.586Z,1566966171.586 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190827T234221/Courier0148.lzma 2019-08-28T04:22:53.147Z,1566966173.147 [DataOverHttps](INFO): Moved sent file to Logs/20190827T234221/Courier0148.lzma.bak 2019-08-28T04:22:53.147Z,1566966173.147 [DataOverHttps](INFO): SBD MOMSN=11706437 2019-08-28T04:22:53.549Z,1566966173.549 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:22:54.154Z,1566966174.154 [DataOverHttps](INFO): GetToShoreFilename: data dir is Logs/20190828T041937 2019-08-28T04:22:54.154Z,1566966174.154 [DataOverHttps](INFO): GetToShoreFilename: active shore file is Logs/20190828T041937/Courier0004 2019-08-28T04:22:55.289Z,1566966175.289 [DataOverHttps](INFO): GetToShoreFilename: checking Logs/20190828T041937/Courier0004 (1/1) 2019-08-28T04:22:56.385Z,1566966176.385 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:22:59.625Z,1566966179.625 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:23:02.441Z,1566966182.441 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:23:05.273Z,1566966185.273 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:23:08.497Z,1566966188.497 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:23:11.325Z,1566966191.325 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:23:13.048Z,1566966193.048 [DataOverHttps](INFO): Sending 99 bytes from file Logs/20190828T041937/Courier0000.lzma 2019-08-28T04:23:14.565Z,1566966194.565 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:23:15.054Z,1566966195.054 [DataOverHttps](INFO): Moved sent file to Logs/20190828T041937/Courier0000.lzma.bak 2019-08-28T04:23:15.054Z,1566966195.054 [DataOverHttps](INFO): SBD MOMSN=11706439 2019-08-28T04:23:16.062Z,1566966196.062 [DataOverHttps](INFO): GetToShoreFilename: data dir is Logs/20190828T041937 2019-08-28T04:23:16.062Z,1566966196.062 [DataOverHttps](INFO): GetToShoreFilename: active shore file is Logs/20190828T041937/Courier0004 2019-08-28T04:23:17.204Z,1566966197.204 [DataOverHttps](INFO): GetToShoreFilename: checking Logs/20190828T041937/Courier0004 (1/1) 2019-08-28T04:23:17.209Z,1566966197.209 [DataOverHttps](INFO): GetToShoreFilename: data dir is Logs/20190828T041937 2019-08-28T04:23:17.209Z,1566966197.209 [DataOverHttps](INFO): GetToShoreFilename: active shore file is Logs/20190828T041937/Express0005 2019-08-28T04:23:17.385Z,1566966197.385 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:23:17.780Z,1566966197.780 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,042224.00,A,3648.16259,N,12147.28034,W,0.641,0.00,280819,,,A*7B 2019-08-28T04:23:17.783Z,1566966197.783 [NAL9602](INFO): GPS fix at 20190828T042224: (36.802710, -121.788006) 2019-08-28T04:23:38.152Z,1566966218.152 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20190827T234221/Express0149.lzma 2019-08-28T04:23:40.159Z,1566966220.159 [DataOverHttps](INFO): Moved sent file to Logs/20190827T234221/Express0149.lzma.bak 2019-08-28T04:23:40.159Z,1566966220.159 [DataOverHttps](INFO): SBD MOMSN=11706443 2019-08-28T04:23:41.165Z,1566966221.165 [DataOverHttps](INFO): GetToShoreFilename: data dir is Logs/20190828T041937 2019-08-28T04:23:41.165Z,1566966221.165 [DataOverHttps](INFO): GetToShoreFilename: active shore file is Logs/20190828T041937/Courier0004 2019-08-28T04:23:41.260Z,1566966221.260 [Startup:StartupSatComms:B](INFO): Timed out from 2019-08-28T04:22:40.9Z 2019-08-28T04:23:41.260Z,1566966221.260 [Startup:StartupSatComms:B] Stopped 2019-08-28T04:23:41.265Z,1566966221.265 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2019-08-28T04:23:41.265Z,1566966221.265 [Startup:StartupSatComms] Stopped 2019-08-28T04:23:41.265Z,1566966221.265 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2019-08-28T04:23:41.266Z,1566966221.266 [Startup](INFO): Completed Startup 2019-08-28T04:23:41.266Z,1566966221.266 [MissionManager](INFO): Startup is completed. 2019-08-28T04:23:41.266Z,1566966221.266 [MissionManager](INFO): Uninitializing Mission Startup 2019-08-28T04:23:41.266Z,1566966221.266 [Startup] Stopped 2019-08-28T04:23:41.266Z,1566966221.266 [Startup](DEBUG): Aggregate::uninitialize Startup 2019-08-28T04:23:41.266Z,1566966221.266 [Startup:A.GoToSurface] Stopped 2019-08-28T04:23:41.267Z,1566966221.267 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-08-28T04:23:41.655Z,1566966221.655 [MissionManager](IMPORTANT): Started mission Default 2019-08-28T04:23:41.655Z,1566966221.655 [Default] Running Loop=1 2019-08-28T04:23:41.655Z,1566966221.655 [Default](DEBUG): Aggregate::initialize Default 2019-08-28T04:23:41.656Z,1566966221.656 [Default:B.GoToSurface] Running Loop=1 2019-08-28T04:23:41.656Z,1566966221.656 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-08-28T04:23:41.656Z,1566966221.656 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-08-28T04:23:41.656Z,1566966221.656 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-08-28T04:23:41.656Z,1566966221.656 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-08-28T04:23:41.657Z,1566966221.657 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-08-28T04:23:41.657Z,1566966221.657 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-08-28T04:23:41.657Z,1566966221.657 [Default:A.Wait] Running Loop=1 2019-08-28T04:23:41.658Z,1566966221.658 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-08-28T04:23:42.547Z,1566966222.547 [DataOverHttps](INFO): GetToShoreFilename: checking Logs/20190828T041937/Courier0004 (1/1) 2019-08-28T04:23:42.552Z,1566966222.552 [DataOverHttps](INFO): GetToShoreFilename: data dir is Logs/20190828T041937 2019-08-28T04:23:42.552Z,1566966222.552 [DataOverHttps](INFO): GetToShoreFilename: active shore file is Logs/20190828T041937/Express0005 2019-08-28T04:23:43.767Z,1566966223.767 [DataOverHttps](INFO): GetToShoreFilename: checking Logs/20190828T041937/Express0005 (1/1) 2019-08-28T04:23:50.514Z,1566966230.514 [NAL9602](INFO): Not Powering down - fast GPS 2019-08-28T04:23:54.988Z,1566966234.988 [Default:A.Wait](INFO): Done Waiting. 2019-08-28T04:23:54.988Z,1566966234.988 [Default:A.Wait] Stopped 2019-08-28T04:23:54.988Z,1566966234.988 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-08-28T04:23:55.390Z,1566966235.390 [Default:CheckIn] Running Loop=1 2019-08-28T04:23:55.391Z,1566966235.391 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-28T04:23:55.391Z,1566966235.391 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-28T04:23:55.805Z,1566966235.805 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2019-08-28T04:23:56.989Z,1566966236.989 [NAL9602](DEBUG): Fix Requested 2019-08-28T04:23:57.384Z,1566966237.384 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,042303.00,A,3648.15898,N,12147.28080,W,0.369,296.03,280819,,,A*75 2019-08-28T04:23:57.386Z,1566966237.386 [NAL9602](INFO): GPS fix at 20190828T042303: (36.802650, -121.788013) 2019-08-28T04:23:57.408Z,1566966237.408 [Default:CheckIn:Read_GPS] Stopped 2019-08-28T04:23:57.408Z,1566966237.408 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-28T04:23:57.828Z,1566966237.828 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-08-28T04:24:04.985Z,1566966244.985 [DataOverHttps](INFO): Sending 743 bytes from file Logs/20190828T041937/Express0001.lzma 2019-08-28T04:24:06.990Z,1566966246.990 [DataOverHttps](INFO): Moved sent file to Logs/20190828T041937/Express0001.lzma.bak 2019-08-28T04:24:06.991Z,1566966246.991 [DataOverHttps](INFO): SBD MOMSN=11706448 2019-08-28T04:24:07.998Z,1566966247.998 [DataOverHttps](INFO): GetToShoreFilename: data dir is Logs/20190828T041937 2019-08-28T04:24:07.998Z,1566966247.998 [DataOverHttps](INFO): GetToShoreFilename: active shore file is Logs/20190828T041937/Courier0007 2019-08-28T04:24:09.154Z,1566966249.154 [DataOverHttps](INFO): GetToShoreFilename: checking Logs/20190828T041937/Courier0007 (1/1) 2019-08-28T04:24:25.017Z,1566966265.017 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20190828T041937/Courier0004.lzma 2019-08-28T04:24:27.023Z,1566966267.023 [DataOverHttps](INFO): Moved sent file to Logs/20190828T041937/Courier0004.lzma.bak 2019-08-28T04:24:27.023Z,1566966267.023 [DataOverHttps](INFO): SBD MOMSN=11706465 2019-08-28T04:24:28.030Z,1566966268.030 [DataOverHttps](INFO): GetToShoreFilename: data dir is Logs/20190828T041937 2019-08-28T04:24:28.031Z,1566966268.031 [DataOverHttps](INFO): GetToShoreFilename: active shore file is Logs/20190828T041937/Courier0007 2019-08-28T04:24:29.235Z,1566966269.235 [DataOverHttps](INFO): GetToShoreFilename: checking Logs/20190828T041937/Courier0007 (1/1) 2019-08-28T04:24:29.240Z,1566966269.240 [DataOverHttps](INFO): GetToShoreFilename: data dir is Logs/20190828T041937 2019-08-28T04:24:29.240Z,1566966269.240 [DataOverHttps](INFO): GetToShoreFilename: active shore file is Logs/20190828T041937/Express0008 2019-08-28T04:24:30.461Z,1566966270.461 [DataOverHttps](INFO): GetToShoreFilename: checking Logs/20190828T041937/Express0008 (1/1) 2019-08-28T04:24:46.588Z,1566966286.588 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20190828T041937/Express0005.lzma 2019-08-28T04:24:48.594Z,1566966288.594 [DataOverHttps](INFO): Moved sent file to Logs/20190828T041937/Express0005.lzma.bak 2019-08-28T04:24:48.594Z,1566966288.594 [DataOverHttps](INFO): SBD MOMSN=11706468 2019-08-28T04:24:49.602Z,1566966289.602 [DataOverHttps](INFO): GetToShoreFilename: data dir is Logs/20190828T041937 2019-08-28T04:24:49.602Z,1566966289.602 [DataOverHttps](INFO): GetToShoreFilename: active shore file is Logs/20190828T041937/Courier0007 2019-08-28T04:24:50.818Z,1566966290.818 [DataOverHttps](INFO): GetToShoreFilename: checking Logs/20190828T041937/Courier0007 (1/1) 2019-08-28T04:24:50.822Z,1566966290.822 [DataOverHttps](INFO): GetToShoreFilename: data dir is Logs/20190828T041937 2019-08-28T04:24:50.822Z,1566966290.822 [DataOverHttps](INFO): GetToShoreFilename: active shore file is Logs/20190828T041937/Express0008 2019-08-28T04:24:52.065Z,1566966292.065 [DataOverHttps](INFO): GetToShoreFilename: checking Logs/20190828T041937/Express0008 (1/1) 2019-08-28T04:24:52.071Z,1566966292.071 [DataOverHttps](INFO): GetToShoreFilename: data dir is Logs/20190828T041937 2019-08-28T04:24:52.072Z,1566966292.072 [DataOverHttps](INFO): GetToShoreFilename: active shore file is Logs/20190828T041937/Courier0007 2019-08-28T04:24:52.352Z,1566966292.352 [Default:CheckIn:Read_Iridium] Stopped 2019-08-28T04:24:52.352Z,1566966292.352 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-28T04:24:52.352Z,1566966292.352 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-28T04:24:53.330Z,1566966293.330 [DataOverHttps](INFO): GetToShoreFilename: checking Logs/20190828T041937/Courier0007 (1/1) 2019-08-28T04:24:53.335Z,1566966293.335 [DataOverHttps](INFO): GetToShoreFilename: data dir is Logs/20190828T041937 2019-08-28T04:24:53.335Z,1566966293.335 [DataOverHttps](INFO): GetToShoreFilename: active shore file is Logs/20190828T041937/Express0008 2019-08-28T04:24:54.830Z,1566966294.830 [DataOverHttps](INFO): GetToShoreFilename: checking Logs/20190828T041937/Express0008 (1/1)