2018-11-02T17:31:55.563Z,1541179915.563 [Supervisor](DEBUG): Initializing supervisor. 2018-11-02T17:31:55.586Z,1541179915.586 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2018-11-02T17:31:55.586Z,1541179915.586 [SyncHandler](INFO): Protected caller Thread ID is 7953 2018-11-02T17:31:55.587Z,1541179915.587 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2018-11-02T17:31:55.588Z,1541179915.588 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2018-11-02T17:31:55.588Z,1541179915.588 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 7954 2018-11-02T17:31:55.618Z,1541179915.618 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2018-11-02T17:31:55.630Z,1541179915.630 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2018-11-02T17:31:55.631Z,1541179915.631 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2018-11-02T17:31:55.631Z,1541179915.631 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 7955 2018-11-02T17:31:55.632Z,1541179915.632 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2018-11-02T17:31:55.633Z,1541179915.633 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2018-11-02T17:31:55.634Z,1541179915.634 [logger ThreadHandler](INFO): Protected caller Thread ID is 7956 2018-11-02T17:31:55.636Z,1541179915.636 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2018-11-02T17:31:55.636Z,1541179915.636 [Supervisor](INFO): Looking for Config files in directory: Config/ 2018-11-02T17:31:55.638Z,1541179915.638 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2018-11-02T17:31:56.055Z,1541179916.055 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2018-11-02T17:31:56.056Z,1541179916.056 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2018-11-02T17:31:56.267Z,1541179916.267 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2018-11-02T17:31:56.267Z,1541179916.267 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2018-11-02T17:31:56.782Z,1541179916.782 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2018-11-02T17:31:56.783Z,1541179916.783 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2018-11-02T17:31:56.932Z,1541179916.932 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2018-11-02T17:31:56.933Z,1541179916.933 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2018-11-02T17:31:57.040Z,1541179917.040 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2018-11-02T17:31:57.041Z,1541179917.041 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2018-11-02T17:31:57.537Z,1541179917.537 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2018-11-02T17:31:57.538Z,1541179917.538 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2018-11-02T17:31:58.230Z,1541179918.230 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2018-11-02T17:31:58.231Z,1541179918.231 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2018-11-02T17:31:58.724Z,1541179918.724 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2018-11-02T17:31:58.725Z,1541179918.725 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2018-11-02T17:31:58.832Z,1541179918.832 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2018-11-02T17:31:58.832Z,1541179918.832 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2018-11-02T17:31:58.932Z,1541179918.932 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2018-11-02T17:31:58.932Z,1541179918.932 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2018-11-02T17:31:59.165Z,1541179919.165 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2018-11-02T17:31:59.166Z,1541179919.166 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2018-11-02T17:31:59.379Z,1541179919.379 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2018-11-02T17:31:59.380Z,1541179919.380 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2018-11-02T17:32:00.046Z,1541179920.046 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2018-11-02T17:32:00.047Z,1541179920.047 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2018-11-02T17:32:00.315Z,1541179920.315 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2018-11-02T17:32:00.316Z,1541179920.316 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2018-11-02T17:32:00.399Z,1541179920.399 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2018-11-02T17:32:00.400Z,1541179920.400 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2018-11-02T17:32:00.505Z,1541179920.505 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2018-11-02T17:32:00.632Z,1541179920.632 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2018-11-02T17:32:00.729Z,1541179920.729 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2018-11-02T17:32:00.816Z,1541179920.816 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2018-11-02T17:32:00.985Z,1541179920.985 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2018-11-02T17:32:01.176Z,1541179921.176 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg 2018-11-02T17:32:01.254Z,1541179921.254 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2018-11-02T17:32:01.502Z,1541179921.502 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2018-11-02T17:32:01.502Z,1541179921.502 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2018-11-02T17:32:01.588Z,1541179921.588 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg 2018-11-02T17:32:01.681Z,1541179921.681 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2018-11-02T17:32:01.792Z,1541179921.792 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2018-11-02T17:32:02.119Z,1541179922.119 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/ 2018-11-02T17:32:02.119Z,1541179922.119 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2018-11-02T17:32:02.121Z,1541179922.121 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2018-11-02T17:32:02.436Z,1541179922.436 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2018-11-02T17:32:02.436Z,1541179922.436 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2018-11-02T17:32:02.496Z,1541179922.496 [DepthRateCalculator] Loaded 2018-11-02T17:32:02.496Z,1541179922.496 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2018-11-02T17:32:02.503Z,1541179922.503 [PitchRateCalculator] Loaded 2018-11-02T17:32:02.503Z,1541179922.503 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2018-11-02T17:32:02.520Z,1541179922.520 [SpeedCalculator] Loaded 2018-11-02T17:32:02.521Z,1541179922.521 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2018-11-02T17:32:02.543Z,1541179922.543 [TempGradientCalculator] Loaded 2018-11-02T17:32:02.543Z,1541179922.543 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2018-11-02T17:32:02.549Z,1541179922.549 [YawRateCalculator] Loaded 2018-11-02T17:32:02.550Z,1541179922.550 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2018-11-02T17:32:02.598Z,1541179922.598 [ElevatorOffsetCalculator] Loaded 2018-11-02T17:32:02.598Z,1541179922.598 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2018-11-02T17:32:02.599Z,1541179922.599 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2018-11-02T17:32:02.600Z,1541179922.600 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2018-11-02T17:32:02.709Z,1541179922.709 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2018-11-02T17:32:02.710Z,1541179922.710 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2018-11-02T17:32:02.855Z,1541179922.855 [BuoyancyServo] Loaded 2018-11-02T17:32:02.855Z,1541179922.855 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2018-11-02T17:32:02.871Z,1541179922.871 [ElevatorServo] Loaded 2018-11-02T17:32:02.871Z,1541179922.871 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2018-11-02T17:32:02.886Z,1541179922.886 [MassServo] Loaded 2018-11-02T17:32:02.887Z,1541179922.887 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2018-11-02T17:32:02.903Z,1541179922.903 [RudderServo] Loaded 2018-11-02T17:32:02.903Z,1541179922.903 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2018-11-02T17:32:02.918Z,1541179922.918 [ThrusterServo] Loaded 2018-11-02T17:32:02.918Z,1541179922.918 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2018-11-02T17:32:02.919Z,1541179922.919 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2018-11-02T17:32:02.920Z,1541179922.920 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2018-11-02T17:32:02.943Z,1541179922.943 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2018-11-02T17:32:02.944Z,1541179922.944 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2018-11-02T17:32:03.087Z,1541179923.087 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2018-11-02T17:32:03.087Z,1541179923.087 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2018-11-02T17:32:03.869Z,1541179923.869 [DataOverHttps] Loaded 2018-11-02T17:32:03.869Z,1541179923.869 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2018-11-02T17:32:03.902Z,1541179923.902 [Depth_Keller] Loaded 2018-11-02T17:32:03.903Z,1541179923.903 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2018-11-02T17:32:03.920Z,1541179923.920 [DropWeight] Loaded 2018-11-02T17:32:03.922Z,1541179923.922 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2018-11-02T17:32:04.208Z,1541179924.208 [NAL9602] Loaded 2018-11-02T17:32:04.208Z,1541179924.208 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2018-11-02T17:32:04.225Z,1541179924.225 [Onboard] Loaded 2018-11-02T17:32:04.225Z,1541179924.225 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2018-11-02T17:32:04.236Z,1541179924.236 [Radio_Surface] Loaded 2018-11-02T17:32:04.237Z,1541179924.237 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2018-11-02T17:32:04.238Z,1541179924.238 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4088F4E0 2018-11-02T17:32:04.238Z,1541179924.238 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 8040 2018-11-02T17:32:04.400Z,1541179924.400 [PNI_TCM] Loaded 2018-11-02T17:32:04.400Z,1541179924.400 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread. 2018-11-02T17:32:04.464Z,1541179924.464 [Rowe_600LCM] Loaded 2018-11-02T17:32:04.464Z,1541179924.464 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread. 2018-11-02T17:32:04.465Z,1541179924.465 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 408BF4E0 2018-11-02T17:32:04.466Z,1541179924.466 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 8041 2018-11-02T17:32:06.838Z,1541179926.838 [BPC1] Loaded 2018-11-02T17:32:06.838Z,1541179926.838 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2018-11-02T17:32:06.838Z,1541179926.838 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2018-11-02T17:32:06.839Z,1541179926.839 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2018-11-02T17:32:07.014Z,1541179927.014 [SBIT](DEBUG): Construct Startup Built In Test. 2018-11-02T17:32:07.037Z,1541179927.037 [SBIT] Loaded 2018-11-02T17:32:07.037Z,1541179927.037 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2018-11-02T17:32:07.038Z,1541179927.038 [IBIT](DEBUG): Construct Initiated Built In Test. 2018-11-02T17:32:07.050Z,1541179927.050 [IBIT] Loaded 2018-11-02T17:32:07.050Z,1541179927.050 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2018-11-02T17:32:07.053Z,1541179927.053 [CBIT](DEBUG): Construct Continuous Built In Test. 2018-11-02T17:32:07.210Z,1541179927.210 [CBIT] Loaded 2018-11-02T17:32:07.210Z,1541179927.210 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2018-11-02T17:32:07.211Z,1541179927.211 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2018-11-02T17:32:07.211Z,1541179927.211 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2018-11-02T17:32:07.441Z,1541179927.441 [Aanderaa_O2] Loaded 2018-11-02T17:32:07.441Z,1541179927.441 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2018-11-02T17:32:07.530Z,1541179927.530 [CTD_NeilBrown] Loaded 2018-11-02T17:32:07.530Z,1541179927.530 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2018-11-02T17:32:07.531Z,1541179927.531 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4098A4E0 2018-11-02T17:32:07.532Z,1541179927.532 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 8042 2018-11-02T17:32:07.591Z,1541179927.591 [CTD_Seabird] Loaded 2018-11-02T17:32:07.591Z,1541179927.591 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2018-11-02T17:32:07.592Z,1541179927.592 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409BA4E0 2018-11-02T17:32:07.593Z,1541179927.593 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 8043 2018-11-02T17:32:07.608Z,1541179927.608 [PAR_Licor] Loaded 2018-11-02T17:32:07.608Z,1541179927.608 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2018-11-02T17:32:07.660Z,1541179927.660 [WetLabsBB2FL] Loaded 2018-11-02T17:32:07.660Z,1541179927.660 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2018-11-02T17:32:07.662Z,1541179927.662 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409EA4E0 2018-11-02T17:32:07.662Z,1541179927.662 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 8044 2018-11-02T17:32:07.663Z,1541179927.663 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2018-11-02T17:32:07.663Z,1541179927.663 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2018-11-02T17:32:07.757Z,1541179927.757 [VerticalControl](DEBUG): Construct VerticalControl. 2018-11-02T17:32:07.855Z,1541179927.855 [VerticalControl] Loaded 2018-11-02T17:32:07.855Z,1541179927.855 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2018-11-02T17:32:07.856Z,1541179927.856 [HorizontalControl](DEBUG): Construct HorizontalControl. 2018-11-02T17:32:07.916Z,1541179927.916 [HorizontalControl] Loaded 2018-11-02T17:32:07.917Z,1541179927.917 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2018-11-02T17:32:07.917Z,1541179927.917 [SpeedControl](DEBUG): Construct SpeedControl. 2018-11-02T17:32:07.919Z,1541179927.919 [SpeedControl] Loaded 2018-11-02T17:32:07.919Z,1541179927.919 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2018-11-02T17:32:07.920Z,1541179927.920 [LoopControl](DEBUG): Construct LoopControl. 2018-11-02T17:32:07.920Z,1541179927.920 [LoopControl] Loaded 2018-11-02T17:32:07.921Z,1541179927.921 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2018-11-02T17:32:07.921Z,1541179927.921 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2018-11-02T17:32:07.922Z,1541179927.922 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2018-11-02T17:32:07.961Z,1541179927.961 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2018-11-02T17:32:07.962Z,1541179927.962 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2018-11-02T17:32:08.073Z,1541179928.073 [DeadReckonUsingSpeedCalculator] Loaded 2018-11-02T17:32:08.073Z,1541179928.073 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2018-11-02T17:32:08.090Z,1541179928.090 [NavChart] Loaded 2018-11-02T17:32:08.091Z,1541179928.091 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2018-11-02T17:32:08.095Z,1541179928.095 [UniversalFixResidualReporter] Loaded 2018-11-02T17:32:08.095Z,1541179928.095 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2018-11-02T17:32:08.096Z,1541179928.096 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2018-11-02T17:32:08.099Z,1541179928.099 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2018-11-02T17:32:08.101Z,1541179928.101 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2018-11-02T17:32:08.108Z,1541179928.108 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2018-11-02T17:32:08.109Z,1541179928.109 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A764E0 2018-11-02T17:32:08.109Z,1541179928.109 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 8045 2018-11-02T17:32:08.116Z,1541179928.116 [Supervisor](INFO): Main Thread ID is 7952 2018-11-02T17:32:08.116Z,1541179928.116 [Supervisor](DEBUG): Running supervisor. 2018-11-02T17:32:08.117Z,1541179928.117 [CommandLine ThreadHandler](INFO): Handler Thread ID is 8046 2018-11-02T17:32:08.119Z,1541179928.119 [controlThread ThreadHandler](INFO): Handler Thread ID is 8047 2018-11-02T17:32:08.120Z,1541179928.120 [controlThread](DEBUG): Initializing ControlThread 2018-11-02T17:32:08.121Z,1541179928.121 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2018-11-02T17:32:08.121Z,1541179928.121 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2018-11-02T17:32:08.121Z,1541179928.121 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2018-11-02T17:32:08.122Z,1541179928.122 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2018-11-02T17:32:08.122Z,1541179928.122 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2018-11-02T17:32:08.123Z,1541179928.123 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2018-11-02T17:32:08.132Z,1541179928.132 [SBIT](INFO): Initialize SBIT Component. 2018-11-02T17:32:08.132Z,1541179928.132 [SBIT](IMPORTANT): git: 2018-11-02 2018-11-02T17:32:08.132Z,1541179928.132 [SBIT](INFO): git hash: 766718804c5d96cf896f07eddb44b232c8585615 2018-11-02T17:32:08.133Z,1541179928.133 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2018-11-02T17:32:08.133Z,1541179928.133 [SBIT](IMPORTANT): Kernel Version:#2 PREEMPT Thu Jan 11 20:13:48 PST 2018 2018-11-02T17:32:08.134Z,1541179928.134 [SBIT](INFO): Beginning SBIT in 23.000000 seconds. 2018-11-02T17:32:08.135Z,1541179928.135 [IBIT](INFO): Initialize IBIT Component. 2018-11-02T17:32:08.135Z,1541179928.135 [CBIT](DEBUG): Initialize CBIT Component. 2018-11-02T17:32:08.136Z,1541179928.136 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2018-11-02T17:32:08.136Z,1541179928.136 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2018-11-02T17:32:08.137Z,1541179928.137 [logger ThreadHandler](INFO): Handler Thread ID is 8048 2018-11-02T17:32:08.157Z,1541179928.157 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 8049 2018-11-02T17:32:08.163Z,1541179928.163 [Radio_Surface](INFO): Powering up 2018-11-02T17:32:08.170Z,1541179928.170 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 8050 2018-11-02T17:32:08.172Z,1541179928.172 [Rowe_600LCM](INFO): Initializing 2018-11-02T17:32:08.173Z,1541179928.173 [Rowe_600LCM](INFO): Checking LCM 2018-11-02T17:32:08.183Z,1541179928.183 [Rowe_600LCM](INFO): LCM OK 2018-11-02T17:32:08.183Z,1541179928.183 [Rowe_600LCM](INFO): Powering up 2018-11-02T17:32:08.189Z,1541179928.189 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 8051 2018-11-02T17:32:08.190Z,1541179928.190 [CTD_NeilBrown](INFO): Powering down 2018-11-02T17:32:08.214Z,1541179928.214 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 8052 2018-11-02T17:32:08.214Z,1541179928.214 [CTD_Seabird](INFO): Initializing 2018-11-02T17:32:08.215Z,1541179928.215 [CTD_Seabird](INFO): Checking LCM 2018-11-02T17:32:08.215Z,1541179928.215 [CTD_Seabird](INFO): LCM OK 2018-11-02T17:32:08.215Z,1541179928.215 [CTD_Seabird](INFO): Powering up 2018-11-02T17:32:08.229Z,1541179928.229 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 8053 2018-11-02T17:32:08.230Z,1541179928.230 [WetLabsBB2FL](INFO): Powering down 2018-11-02T17:32:08.245Z,1541179928.245 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2018-11-02T17:32:08.247Z,1541179928.247 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2018-11-02T17:32:08.248Z,1541179928.248 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2018-11-02T17:32:08.248Z,1541179928.248 [LoopControl](DEBUG): Initialize LoopControlComponent. 2018-11-02T17:32:08.249Z,1541179928.249 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-11-02T17:32:08.250Z,1541179928.250 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-11-02T17:32:08.250Z,1541179928.250 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-11-02T17:32:08.251Z,1541179928.251 [NavChart](DEBUG): Initialize NavChart Navigation. 2018-11-02T17:32:08.251Z,1541179928.251 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2018-11-02T17:32:08.252Z,1541179928.252 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2018-11-02T17:32:08.280Z,1541179928.280 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2018-11-02T17:32:08.285Z,1541179928.285 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 8054 2018-11-02T17:32:08.291Z,1541179928.291 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2018-11-02T17:32:08.291Z,1541179928.291 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2018-11-02T17:32:08.291Z,1541179928.291 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2018-11-02T17:32:08.291Z,1541179928.291 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2018-11-02T17:32:08.291Z,1541179928.291 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2018-11-02T17:32:08.292Z,1541179928.292 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2018-11-02T17:32:08.292Z,1541179928.292 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2018-11-02T17:32:08.292Z,1541179928.292 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2018-11-02T17:32:08.292Z,1541179928.292 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2018-11-02T17:32:08.292Z,1541179928.292 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2018-11-02T17:32:08.293Z,1541179928.293 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2018-11-02T17:32:08.293Z,1541179928.293 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2018-11-02T17:32:08.293Z,1541179928.293 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2018-11-02T17:32:08.293Z,1541179928.293 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2018-11-02T17:32:08.294Z,1541179928.294 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2018-11-02T17:32:08.294Z,1541179928.294 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2018-11-02T17:32:08.327Z,1541179928.327 [MissionManager](DEBUG): 2018-11-02T17:32:08.328Z,1541179928.328 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2018-11-02T17:32:08.403Z,1541179928.403 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2018-11-02T17:32:08.404Z,1541179928.404 [Default:A.Wait](DEBUG): Construct Wait. 2018-11-02T17:32:08.414Z,1541179928.414 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2018-11-02T17:32:08.451Z,1541179928.451 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2018-11-02T17:32:08.476Z,1541179928.476 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2018-11-02T17:32:08.549Z,1541179928.549 [Default:E.Execute](DEBUG): Construct Execute. 2018-11-02T17:32:08.579Z,1541179928.579 [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 2018-11-02T17:32:08.595Z,1541179928.595 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,Aanderaa_O2,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2018-11-02T17:32:08.663Z,1541179928.663 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2018-11-02T17:32:08.746Z,1541179928.746 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar 2018-11-02T17:32:08.926Z,1541179928.926 [DepthRateCalculator](ERROR): Depth measurement is not active 2018-11-02T17:32:09.274Z,1541179929.274 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2018-11-02T17:32:09.274Z,1541179929.274 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2018-11-02T17:32:09.294Z,1541179929.294 [ElevatorServo](DEBUG): Initializing EZServoServo. 2018-11-02T17:32:09.294Z,1541179929.294 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2018-11-02T17:32:09.317Z,1541179929.317 [MassServo](DEBUG): Initializing EZServoServo. 2018-11-02T17:32:09.317Z,1541179929.317 [MassServo](DEBUG): Initializing MassServo. 2018-11-02T17:32:09.323Z,1541179929.323 [RudderServo](DEBUG): Initializing EZServoServo. 2018-11-02T17:32:09.324Z,1541179929.324 [RudderServo](DEBUG): Initializing RudderServo. 2018-11-02T17:32:09.349Z,1541179929.349 [ThrusterServo](DEBUG): Initializing EZServoServo. 2018-11-02T17:32:09.350Z,1541179929.350 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2018-11-02T17:32:10.257Z,1541179930.257 [ElevatorServo](ERROR): Elevator initialization uart error I:serial timeout 2018-11-02T17:32:10.257Z,1541179930.257 [ElevatorServo](FAULT): Elevator failed to initialize 2018-11-02T17:32:10.257Z,1541179930.257 [ElevatorServo] Communications Fault, FailCount= 1 2018-11-02T17:32:10.257Z,1541179930.257 [ElevatorServo](ERROR): Communications Fault 2018-11-02T17:32:10.421Z,1541179930.421 [CBIT](ERROR): Communications Fault in component: ElevatorServo 2018-11-02T17:32:12.504Z,1541179932.504 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-11-02T17:32:12.648Z,1541179932.648 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null & 2018-11-02T17:32:13.036Z,1541179933.036 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-11-02T17:32:13.045Z,1541179933.045 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-11-02T17:32:13.046Z,1541179933.046 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-11-02T17:32:13.906Z,1541179933.906 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface 2018-11-02T17:32:14.090Z,1541179934.090 [CTD_Seabird](INFO): Started Seabird LCM interface with command:nohup ./lrauv-framework/onboard/bin/gpctd -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyC6 -b 9600 >& /dev/null & 2018-11-02T17:32:14.092Z,1541179934.092 [CTD_Seabird](INFO): LCM subscribed to channel:seabird_gpctd_t.seabird-gpctd 2018-11-02T17:32:15.030Z,1541179935.030 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface 2018-11-02T17:32:15.030Z,1541179935.030 [CTD_Seabird](INFO): Powering down 2018-11-02T17:32:22.019Z,1541179942.019 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2018-11-02T17:32:22.020Z,1541179942.020 [ElevatorServo](INFO): Powering down 2018-11-02T17:32:22.550Z,1541179942.550 [Aanderaa_O2](INFO): Powering down 2018-11-02T17:32:22.701Z,1541179942.701 [ElevatorServo](DEBUG): Initializing EZServoServo. 2018-11-02T17:32:22.701Z,1541179942.701 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2018-11-02T17:32:22.722Z,1541179942.722 [CBIT](INFO): Clearing failed state for component ElevatorServo 2018-11-02T17:32:22.722Z,1541179942.722 [ElevatorServo] No Fault, FailCount= 1 2018-11-02T17:32:22.924Z,1541179942.924 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.007056 2018-11-02T17:32:31.833Z,1541179951.833 [SBIT](IMPORTANT): Beginning Startup BIT 2018-11-02T17:32:31.838Z,1541179951.838 [CBIT](IMPORTANT): Beginning ground fault scan 2018-11-02T17:32:34.251Z,1541179954.251 [NAL9602](INFO): Powering up NAL9602 2018-11-02T17:32:42.817Z,1541179962.817 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 4.657929 CHAN A1 (24V): -0.008879 CHAN A2 (12V): -0.002545 CHAN A3 (5V): -0.001310 CHAN B0 (3.3V): -0.000175 CHAN B1 (3.15aV): 0.000140 CHAN B2 (3.15bV): 4.767929 CHAN B3 (GND): -0.000219 OPEN: -0.000344 Full Scale Calc: 4.765 mA, -1.589 mA 2018-11-02T17:32:54.811Z,1541179974.811 [NAL9602](ERROR): NAL9602 initialization error. 2018-11-02T17:32:54.811Z,1541179974.811 [NAL9602] Communications Fault, FailCount= 1 2018-11-02T17:32:54.811Z,1541179974.811 [NAL9602](ERROR): Communications Fault 2018-11-02T17:32:55.071Z,1541179975.071 [CBIT](ERROR): Communications Fault in component: NAL9602 2018-11-02T17:32:55.207Z,1541179975.207 [NAL9602](INFO): Powering down 2018-11-02T17:32:56.282Z,1541179976.282 [CBIT](INFO): Clearing failed state for component NAL9602 2018-11-02T17:32:56.282Z,1541179976.282 [NAL9602] No Fault, FailCount= 1 2018-11-02T17:33:25.495Z,1541180005.495 [NAL9602](INFO): Powering up NAL9602 2018-11-02T17:33:30.050Z,1541180010.050 [SBIT](IMPORTANT): SBIT PASSED 2018-11-02T17:33:30.097Z,1541180010.097 [CommandLine](IMPORTANT): got command configSet list 2018-11-02T17:33:30.098Z,1541180010.098 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2018-11-02T17:33:30.101Z,1541180010.101 [CommandLine](IMPORTANT): BPC1.batteryMissingStickThreshold=25 count; 2018-11-02T17:33:30.101Z,1541180010.101 [CommandLine](IMPORTANT): BPC1.batteryMuxCycleTime=10 minute; 2018-11-02T17:33:30.101Z,1541180010.101 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=1 minute; 2018-11-02T17:33:30.102Z,1541180010.102 [CommandLine](IMPORTANT): BPC1.loadAtStartup=0 bool; 2018-11-02T17:33:30.102Z,1541180010.102 [CommandLine](IMPORTANT): CTD_NeilBrown.loadAtStartup=0 bool; 2018-11-02T17:33:30.102Z,1541180010.102 [CommandLine](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool; 2018-11-02T17:33:30.102Z,1541180010.102 [CommandLine](IMPORTANT): Express none VerticalTemperatureHomogeneityIndexCalculator.vertical_temperature_homogeneity_index; 2018-11-02T17:33:30.102Z,1541180010.102 [CommandLine](IMPORTANT): Express linearApproximation height_above_sea_floor 5.000000 meter; 2018-11-02T17:33:30.102Z,1541180010.102 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=1 bool; 2018-11-02T17:33:30.102Z,1541180010.102 [CommandLine](IMPORTANT): StratificationFrontDetector.loadAtStartup=0 bool; 2018-11-02T17:33:30.102Z,1541180010.102 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=213 cubic_centimeter; 2018-11-02T17:33:30.103Z,1541180010.103 [CommandLine](IMPORTANT): VerticalControl.massDefault=4 millimeter; 2018-11-02T17:33:30.355Z,1541180010.355 [MissionManager](IMPORTANT): Started mission Startup 2018-11-02T17:33:30.355Z,1541180010.355 [Startup] Running Loop=1 2018-11-02T17:33:30.356Z,1541180010.356 [Startup](DEBUG): Aggregate::initialize Startup 2018-11-02T17:33:30.356Z,1541180010.356 [Startup:A.GoToSurface] Running Loop=1 2018-11-02T17:33:30.356Z,1541180010.356 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2018-11-02T17:33:30.356Z,1541180010.356 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2018-11-02T17:33:30.373Z,1541180010.373 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2018-11-02T17:33:30.374Z,1541180010.374 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2018-11-02T17:33:30.374Z,1541180010.374 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2018-11-02T17:33:30.375Z,1541180010.375 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2018-11-02T17:33:30.421Z,1541180010.421 [Startup:StartupSatComms] Running Loop=1 2018-11-02T17:33:30.421Z,1541180010.421 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2018-11-02T17:33:30.421Z,1541180010.421 [Startup:StartupSatComms:A] Running Loop=1 2018-11-02T17:33:30.762Z,1541180010.762 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2018-11-02T17:33:36.694Z,1541180016.694 [NAL9602](INFO): NAL9602 initialized 2018-11-02T17:33:55.096Z,1541180035.096 [NAL9602](INFO): SBD MO Status=2, MOMSN=10405, MT Status=2, MTMSN=0 2018-11-02T17:33:55.096Z,1541180035.096 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2018-11-02T17:34:06.731Z,1541180046.731 [BPC1](FAULT): Battery stick #1 (s/n: 0138) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2018-11-02T17:34:06.732Z,1541180046.732 [BPC1](FAULT): Battery stick #7 (s/n: 012D) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2018-11-02T17:34:06.733Z,1541180046.733 [BPC1](FAULT): Battery stick #9 (s/n: 0100) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2018-11-02T17:34:06.734Z,1541180046.734 [BPC1](FAULT): Battery stick #14 (s/n: 011D) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2018-11-02T17:34:06.735Z,1541180046.735 [BPC1](FAULT): Battery stick #15 (s/n: 014E) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2018-11-02T17:34:06.735Z,1541180046.735 [BPC1](FAULT): Battery stick #18 (s/n: 0140) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AC0. 2018-11-02T17:34:06.736Z,1541180046.736 [BPC1](FAULT): Battery stick #21 (s/n: 00CD) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2018-11-02T17:34:06.773Z,1541180046.773 [BPC1](FAULT): Battery stick #22 (s/n: 009F) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2018-11-02T17:34:06.774Z,1541180046.774 [BPC1](FAULT): Battery stick #25 (s/n: 00E8) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2018-11-02T17:34:06.775Z,1541180046.775 [BPC1](FAULT): Battery stick #26 (s/n: 00D1) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2018-11-02T17:34:06.776Z,1541180046.776 [BPC1](FAULT): Battery stick #28 (s/n: 0092) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2018-11-02T17:34:06.781Z,1541180046.781 [BPC1](FAULT): Battery stick #30 (s/n: 00E9) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2018-11-02T17:34:06.782Z,1541180046.782 [BPC1](FAULT): Battery stick #32 (s/n: 0157) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AC0. 2018-11-02T17:34:06.782Z,1541180046.782 [BPC1](FAULT): Battery stick #40 (s/n: 0095) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2018-11-02T17:34:06.783Z,1541180046.783 [BPC1](FAULT): Battery stick #43 (s/n: 00AE) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2018-11-02T17:34:06.784Z,1541180046.784 [BPC1](FAULT): Battery stick #44 (s/n: 00CB) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2018-11-02T17:34:06.793Z,1541180046.793 [BPC1](FAULT): Battery stick #45 (s/n: 00F7) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AC0. 2018-11-02T17:34:06.794Z,1541180046.794 [BPC1](FAULT): Battery stick #46 (s/n: 00A1) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2018-11-02T17:34:06.795Z,1541180046.795 [BPC1](FAULT): Battery stick #49 (s/n: 0103) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2018-11-02T17:34:06.795Z,1541180046.795 [BPC1](FAULT): Battery stick #50 (s/n: 0152) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2018-11-02T17:34:06.796Z,1541180046.796 [BPC1](FAULT): Battery stick #51 (s/n: 014A) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2018-11-02T17:34:06.805Z,1541180046.805 [BPC1](FAULT): Battery stick #53 (s/n: 015E) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2018-11-02T17:34:06.806Z,1541180046.806 [BPC1](FAULT): Battery stick #54 (s/n: 008E) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2018-11-02T17:34:06.807Z,1541180046.807 [BPC1](FAULT): Battery stick #56 (s/n: 0091) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AC0. 2018-11-02T17:34:06.808Z,1541180046.808 [BPC1](FAULT): Battery stick #57 (s/n: 0153) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2018-11-02T17:34:06.825Z,1541180046.825 [BPC1](FAULT): Battery stick #62 (s/n: 00DA) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2018-11-02T17:34:06.825Z,1541180046.825 [BPC1](INFO): Calculating totals. Valid battery stick count: 29. Valid reserve battery stick count: 3. 2018-11-02T17:34:26.012Z,1541180066.012 [NAL9602](INFO): SBD MO Status=2, MOMSN=10405, MT Status=2, MTMSN=0 2018-11-02T17:34:26.012Z,1541180066.012 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2018-11-02T17:34:30.501Z,1541180070.501 [Startup:StartupSatComms:A](INFO): Timed out from 2018-11-02T17:33:30.4Z 2018-11-02T17:34:30.501Z,1541180070.501 [Startup:StartupSatComms:A] Stopped 2018-11-02T17:34:30.501Z,1541180070.501 [Startup:StartupSatComms:B] Running Loop=1 2018-11-02T17:34:30.887Z,1541180070.887 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2018-11-02T17:34:35.988Z,1541180075.988 [DataOverHttps](INFO): Sending 189 bytes from file Logs/20181102T173155/Courier0000.lzma 2018-11-02T17:34:36.787Z,1541180076.787 [DataOverHttps](INFO): Moved sent file to Logs/20181102T173155/Courier0000.lzma.bak 2018-11-02T17:34:36.787Z,1541180076.787 [DataOverHttps](INFO): SBD MOMSN=8781810 2018-11-02T17:34:46.732Z,1541180086.732 [DataOverHttps](INFO): Sending 1262 bytes from file Logs/20181102T173155/Express0001.lzma 2018-11-02T17:34:47.519Z,1541180087.519 [DataOverHttps](INFO): Moved sent file to Logs/20181102T173155/Express0001.lzma.bak 2018-11-02T17:34:47.519Z,1541180087.519 [DataOverHttps](INFO): SBD MOMSN=8781813 2018-11-02T17:34:47.973Z,1541180087.973 [Startup:StartupSatComms:B] Stopped 2018-11-02T17:34:47.973Z,1541180087.973 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2018-11-02T17:34:47.974Z,1541180087.974 [Startup:StartupSatComms] Stopped 2018-11-02T17:34:47.974Z,1541180087.974 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2018-11-02T17:34:47.974Z,1541180087.974 [Startup](INFO): Completed Startup 2018-11-02T17:34:47.975Z,1541180087.975 [MissionManager](INFO): Startup is completed. 2018-11-02T17:34:47.975Z,1541180087.975 [MissionManager](INFO): Uninitializing Mission Startup 2018-11-02T17:34:47.975Z,1541180087.975 [Startup] Stopped 2018-11-02T17:34:47.975Z,1541180087.975 [Startup](DEBUG): Aggregate::uninitialize Startup 2018-11-02T17:34:47.975Z,1541180087.975 [Startup:A.GoToSurface] Stopped 2018-11-02T17:34:47.975Z,1541180087.975 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2018-11-02T17:34:48.368Z,1541180088.368 [MissionManager](IMPORTANT): Started mission Default 2018-11-02T17:34:48.385Z,1541180088.385 [Default] Running Loop=1 2018-11-02T17:34:48.385Z,1541180088.385 [Default](DEBUG): Aggregate::initialize Default 2018-11-02T17:34:48.385Z,1541180088.385 [Default:B.GoToSurface] Running Loop=1 2018-11-02T17:34:48.385Z,1541180088.385 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2018-11-02T17:34:48.385Z,1541180088.385 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2018-11-02T17:34:48.386Z,1541180088.386 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2018-11-02T17:34:48.386Z,1541180088.386 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2018-11-02T17:34:48.386Z,1541180088.386 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2018-11-02T17:34:48.387Z,1541180088.387 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2018-11-02T17:34:48.387Z,1541180088.387 [Default:A.Wait] Running Loop=1 2018-11-02T17:34:48.387Z,1541180088.387 [Default:A.Wait](DEBUG): Initialize Wait Component. 2018-11-02T17:35:01.619Z,1541180101.619 [Default:A.Wait](INFO): Done Waiting. 2018-11-02T17:35:01.619Z,1541180101.619 [Default:A.Wait] Stopped 2018-11-02T17:35:01.619Z,1541180101.619 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2018-11-02T17:35:02.015Z,1541180102.015 [Default:CheckIn] Running Loop=1 2018-11-02T17:35:02.015Z,1541180102.015 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-11-02T17:35:02.015Z,1541180102.015 [Default:CheckIn:Read_GPS] Running Loop=1 2018-11-02T17:35:02.418Z,1541180102.418 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2018-11-02T17:35:08.446Z,1541180108.446 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-11-02T17:35:08.446Z,1541180108.446 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1 2018-11-02T17:35:08.446Z,1541180108.446 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2018-11-02T17:35:08.542Z,1541180108.542 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2018-11-02T17:35:08.967Z,1541180108.967 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2018-11-02T17:35:08.968Z,1541180108.968 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1 2018-11-02T17:35:09.212Z,1541180109.212 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-11-02T17:35:09.212Z,1541180109.212 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-11-02T17:35:09.213Z,1541180109.213 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-11-02T17:35:11.584Z,1541180111.584 [NAL9602](INFO): SBD MO Status=2, MOMSN=10405, MT Status=2, MTMSN=0 2018-11-02T17:35:11.584Z,1541180111.584 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2018-11-02T17:35:33.184Z,1541180133.184 [NAL9602](INFO): SBD MO Status=2, MOMSN=10405, MT Status=2, MTMSN=0 2018-11-02T17:35:33.184Z,1541180133.184 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2018-11-02T17:36:43.308Z,1541180203.308 [NAL9602](INFO): SBD MO Status=2, MOMSN=10405, MT Status=2, MTMSN=0 2018-11-02T17:36:43.308Z,1541180203.308 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2018-11-02T17:38:07.009Z,1541180287.009 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2018-11-02T17:38:07.009Z,1541180287.009 [Rowe_600LCM] Communications Fault, FailCount= 1 2018-11-02T17:38:07.009Z,1541180287.009 [Rowe_600LCM](ERROR): Communications Fault 2018-11-02T17:38:07.133Z,1541180287.133 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2018-11-02T17:38:07.413Z,1541180287.413 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-11-02T17:38:07.724Z,1541180287.724 [Rowe_600LCM](INFO): Powering down 2018-11-02T17:38:09.418Z,1541180289.418 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-11-02T17:38:09.418Z,1541180289.418 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2 2018-11-02T17:38:09.419Z,1541180289.419 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2018-11-02T17:38:09.513Z,1541180289.513 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2018-11-02T17:38:09.917Z,1541180289.917 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2018-11-02T17:38:09.917Z,1541180289.917 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2 2018-11-02T17:38:10.205Z,1541180290.205 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-11-02T17:38:10.206Z,1541180290.206 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-11-02T17:38:10.206Z,1541180290.206 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-11-02T17:38:12.968Z,1541180292.968 [NAL9602](INFO): SBD MO Status=2, MOMSN=10405, MT Status=2, MTMSN=0 2018-11-02T17:38:12.968Z,1541180292.968 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2018-11-02T17:38:39.766Z,1541180319.766 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-11-02T17:38:45.408Z,1541180325.408 [NAL9602](INFO): GPS fix at 20181102T173803: (36.802836, -121.788199) 2018-11-02T17:38:45.476Z,1541180325.476 [Default:CheckIn:Read_GPS] Stopped 2018-11-02T17:38:45.476Z,1541180325.476 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-11-02T17:38:45.827Z,1541180325.827 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2018-11-02T17:38:51.629Z,1541180331.629 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20181102T173155/Courier0004.lzma 2018-11-02T17:38:52.422Z,1541180332.422 [DataOverHttps](INFO): Moved sent file to Logs/20181102T173155/Courier0004.lzma.bak 2018-11-02T17:38:52.422Z,1541180332.422 [DataOverHttps](INFO): SBD MOMSN=8781867 2018-11-02T17:39:02.264Z,1541180342.264 [DataOverHttps](INFO): Sending 386 bytes from file Logs/20181102T173155/Express0005.lzma 2018-11-02T17:39:03.063Z,1541180343.063 [DataOverHttps](INFO): Moved sent file to Logs/20181102T173155/Express0005.lzma.bak 2018-11-02T17:39:03.063Z,1541180343.063 [DataOverHttps](INFO): SBD MOMSN=8781870 2018-11-02T17:39:03.512Z,1541180343.512 [Default:CheckIn:Read_Iridium] Stopped 2018-11-02T17:39:03.512Z,1541180343.512 [Default:CheckIn:C.Wait] Running Loop=1 2018-11-02T17:39:03.512Z,1541180343.512 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-11-02T17:39:21.854Z,1541180361.854 [NAL9602](INFO): Powering down 2018-11-02T17:44:04.241Z,1541180644.241 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-11-02T17:44:04.242Z,1541180644.242 [Default:CheckIn:C.Wait] Stopped 2018-11-02T17:44:04.242Z,1541180644.242 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-11-02T17:44:04.242Z,1541180644.242 [Default:CheckIn:D] Running Loop=1 2018-11-02T17:44:04.652Z,1541180644.652 [Default:CheckIn:D] Stopped 2018-11-02T17:44:04.652Z,1541180644.652 [Default:CheckIn:E] Running Loop=1 2018-11-02T17:44:07.748Z,1541180647.748 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 9.271354 min 2018-11-02T17:44:07.750Z,1541180647.750 [Default:CheckIn:E] Stopped 2018-11-02T17:44:07.750Z,1541180647.750 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-11-02T17:44:07.750Z,1541180647.750 [Default:CheckIn] Stopped 2018-11-02T17:44:07.750Z,1541180647.750 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-11-02T17:44:07.750Z,1541180647.750 [Default:CheckIn](INFO): Running loop #2 2018-11-02T17:44:07.750Z,1541180647.750 [Default:CheckIn] Running Loop=2 2018-11-02T17:44:07.750Z,1541180647.750 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-11-02T17:44:07.751Z,1541180647.751 [Default:CheckIn:Read_GPS] Running Loop=1 2018-11-02T17:44:08.267Z,1541180648.267 [NAL9602](INFO): Powering up 2018-11-02T17:44:19.467Z,1541180659.467 [NAL9602](INFO): NAL9602 initialized 2018-11-02T17:44:51.462Z,1541180691.462 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2018-11-02T17:44:51.541Z,1541180691.541 [NAL9602](FAULT): received: +CSQ:0 OK405, 2, 0, 0, 0 OK 2018-11-02T17:44:51.541Z,1541180691.541 [NAL9602] Data Fault, FailCount= 2 2018-11-02T17:44:51.541Z,1541180691.541 [NAL9602](ERROR): Data Fault 2018-11-02T17:44:51.713Z,1541180691.713 [CBIT](ERROR): Data Fault in component: NAL9602 2018-11-02T17:44:51.859Z,1541180691.859 [NAL9602](INFO): Powering down 2018-11-02T17:44:52.801Z,1541180692.801 [CBIT](INFO): Clearing failed state for component NAL9602 2018-11-02T17:44:52.801Z,1541180692.801 [NAL9602] No Fault, FailCount= 2 2018-11-02T17:45:21.982Z,1541180721.982 [NAL9602](INFO): Powering up NAL9602 2018-11-02T17:45:33.182Z,1541180733.182 [NAL9602](INFO): NAL9602 initialized 2018-11-02T17:46:00.779Z,1541180760.779 [NAL9602](INFO): SBD MO Status=2, MOMSN=10405, MT Status=2, MTMSN=0 2018-11-02T17:46:00.780Z,1541180760.780 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2018-11-02T17:46:26.884Z,1541180786.884 [NAL9602](INFO): SBD MO Status=2, MOMSN=10405, MT Status=2, MTMSN=0 2018-11-02T17:46:26.884Z,1541180786.884 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2018-11-02T17:47:17.507Z,1541180837.507 [CommandLine](IMPORTANT): got command failComponent 2018-11-02T17:47:17.507Z,1541180837.507 [CommandLine](IMPORTANT): Failed components: 2018-11-02T17:47:17.507Z,1541180837.507 [CommandLine](IMPORTANT): Rowe_600LCM: Communications Fault 2018-11-02T17:47:29.770Z,1541180849.770 [CommandLine](IMPORTANT): got command restart system 2018-11-02T17:47:31.925Z,1541180851.925 [Supervisor](INFO): Stop Mission called by Supervisor::terminate 2018-11-02T17:47:31.929Z,1541180851.929 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2018-11-02T17:47:31.929Z,1541180851.929 [CommandLine ThreadHandler](INFO): Thread cancelled. 2018-11-02T17:47:31.930Z,1541180851.930 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2018-11-02T17:47:31.930Z,1541180851.930 [CommandLine ThreadHandler](INFO): Thread cancelled. 2018-11-02T17:47:31.931Z,1541180851.931 [CommandLine](INFO): Join timeout helper Thread ID is 8077 2018-11-02T17:47:31.931Z,1541180851.931 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2018-11-02T17:47:31.931Z,1541180851.931 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2018-11-02T17:47:31.932Z,1541180851.932 [NavChartDb](INFO): Join timeout helper Thread ID is 8078 2018-11-02T17:47:32.233Z,1541180852.233 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2018-11-02T17:47:32.233Z,1541180852.233 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2018-11-02T17:47:32.234Z,1541180852.234 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2018-11-02T17:47:32.234Z,1541180852.234 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2018-11-02T17:47:32.234Z,1541180852.234 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 8079 2018-11-02T17:47:32.525Z,1541180852.525 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2018-11-02T17:47:32.525Z,1541180852.525 [WetLabsBB2FL](INFO): Powering down 2018-11-02T17:47:32.526Z,1541180852.526 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2018-11-02T17:47:32.533Z,1541180852.533 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2018-11-02T17:47:32.533Z,1541180852.533 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2018-11-02T17:47:32.533Z,1541180852.533 [CTD_Seabird](INFO): Join timeout helper Thread ID is 8080 2018-11-02T17:47:32.605Z,1541180852.605 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2018-11-02T17:47:32.773