2019-10-21T22:42:15.062Z,1571697735.062 [Supervisor](DEBUG): Initializing supervisor.
2019-10-21T22:42:15.066Z,1571697735.066 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-10-21T22:42:15.066Z,1571697735.066 [SyncHandler](INFO): Protected caller Thread ID is 5311
2019-10-21T22:42:15.067Z,1571697735.067 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-10-21T22:42:15.068Z,1571697735.068 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-10-21T22:42:15.068Z,1571697735.068 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 5312
2019-10-21T22:42:15.070Z,1571697735.070 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-10-21T22:42:15.091Z,1571697735.091 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-10-21T22:42:15.092Z,1571697735.092 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-10-21T22:42:15.093Z,1571697735.093 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 5313
2019-10-21T22:42:15.093Z,1571697735.093 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-10-21T22:42:15.095Z,1571697735.095 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-10-21T22:42:15.095Z,1571697735.095 [logger ThreadHandler](INFO): Protected caller Thread ID is 5314
2019-10-21T22:42:15.097Z,1571697735.097 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-10-21T22:42:15.097Z,1571697735.097 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-10-21T22:42:15.110Z,1571697735.110 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-10-21T22:42:15.373Z,1571697735.373 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-10-21T22:42:15.374Z,1571697735.374 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-10-21T22:42:15.460Z,1571697735.460 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-10-21T22:42:16.060Z,1571697736.060 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-10-21T22:42:16.061Z,1571697736.061 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-10-21T22:42:16.473Z,1571697736.473 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-10-21T22:42:16.474Z,1571697736.474 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-10-21T22:42:16.573Z,1571697736.573 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-10-21T22:42:16.573Z,1571697736.573 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-10-21T22:42:16.957Z,1571697736.957 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-10-21T22:42:16.958Z,1571697736.958 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-10-21T22:42:17.236Z,1571697737.236 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-10-21T22:42:17.236Z,1571697737.236 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-10-21T22:42:17.801Z,1571697737.801 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-10-21T22:42:17.802Z,1571697737.802 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-10-21T22:42:18.118Z,1571697738.118 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-10-21T22:42:18.119Z,1571697738.119 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-10-21T22:42:18.491Z,1571697738.491 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-10-21T22:42:18.491Z,1571697738.491 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-10-21T22:42:19.520Z,1571697739.520 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-10-21T22:42:19.521Z,1571697739.521 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-10-21T22:42:20.559Z,1571697740.559 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-10-21T22:42:20.560Z,1571697740.560 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-10-21T22:42:20.822Z,1571697740.822 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-10-21T22:42:20.823Z,1571697740.823 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-10-21T22:42:20.992Z,1571697740.992 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-10-21T22:42:20.992Z,1571697740.992 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-10-21T22:42:21.161Z,1571697741.161 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-10-21T22:42:21.170Z,1571697741.170 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2019-10-21T22:42:21.181Z,1571697741.181 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2019-10-21T22:42:21.333Z,1571697741.333 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2019-10-21T22:42:21.421Z,1571697741.421 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2019-10-21T22:42:21.613Z,1571697741.613 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2019-10-21T22:42:21.806Z,1571697741.806 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2019-10-21T22:42:22.004Z,1571697742.004 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2019-10-21T22:42:22.148Z,1571697742.148 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2019-10-21T22:42:22.387Z,1571697742.387 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2019-10-21T22:42:22.527Z,1571697742.527 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2019-10-21T22:42:22.694Z,1571697742.694 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2019-10-21T22:42:22.921Z,1571697742.921 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2019-10-21T22:42:23.308Z,1571697743.308 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2019-10-21T22:42:23.679Z,1571697743.679 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-10-21T22:42:23.916Z,1571697743.916 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-10-21T22:42:23.936Z,1571697743.936 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-10-21T22:42:24.020Z,1571697744.020 [VerticalControl](DEBUG): Construct VerticalControl.
2019-10-21T22:42:24.196Z,1571697744.196 [VerticalControl] Loaded
2019-10-21T22:42:24.196Z,1571697744.196 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-10-21T22:42:24.197Z,1571697744.197 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-10-21T22:42:24.266Z,1571697744.266 [HorizontalControl] Loaded
2019-10-21T22:42:24.266Z,1571697744.266 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-10-21T22:42:24.267Z,1571697744.267 [SpeedControl](DEBUG): Construct SpeedControl.
2019-10-21T22:42:24.272Z,1571697744.272 [SpeedControl] Loaded
2019-10-21T22:42:24.272Z,1571697744.272 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-10-21T22:42:24.273Z,1571697744.273 [LoopControl](DEBUG): Construct LoopControl.
2019-10-21T22:42:24.273Z,1571697744.273 [LoopControl] Loaded
2019-10-21T22:42:24.274Z,1571697744.274 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-10-21T22:42:24.274Z,1571697744.274 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-10-21T22:42:24.275Z,1571697744.275 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-10-21T22:42:24.287Z,1571697744.287 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-10-21T22:42:24.288Z,1571697744.288 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-10-21T22:42:24.447Z,1571697744.447 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-10-21T22:42:24.448Z,1571697744.448 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-10-21T22:42:24.593Z,1571697744.593 [BuoyancyServo] Loaded
2019-10-21T22:42:24.593Z,1571697744.593 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-10-21T22:42:24.604Z,1571697744.604 [ElevatorServo] Loaded
2019-10-21T22:42:24.605Z,1571697744.605 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-10-21T22:42:24.617Z,1571697744.617 [MassServo] Loaded
2019-10-21T22:42:24.617Z,1571697744.617 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-10-21T22:42:24.628Z,1571697744.628 [RudderServo] Loaded
2019-10-21T22:42:24.629Z,1571697744.629 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-10-21T22:42:24.640Z,1571697744.640 [ThrusterServo] Loaded
2019-10-21T22:42:24.640Z,1571697744.640 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-10-21T22:42:24.641Z,1571697744.641 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-10-21T22:42:24.641Z,1571697744.641 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-10-21T22:42:24.758Z,1571697744.758 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-10-21T22:42:24.758Z,1571697744.758 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-10-21T22:42:24.810Z,1571697744.810 [NavChart] Loaded
2019-10-21T22:42:24.810Z,1571697744.810 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-10-21T22:42:24.814Z,1571697744.814 [UniversalFixResidualReporter] Loaded
2019-10-21T22:42:24.814Z,1571697744.814 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-10-21T22:42:24.823Z,1571697744.823 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-10-21T22:42:24.824Z,1571697744.824 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-10-21T22:42:24.928Z,1571697744.928 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-10-21T22:42:24.928Z,1571697744.928 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-10-21T22:42:25.257Z,1571697745.257 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2019-10-21T22:42:25.262Z,1571697745.262 [AHRS_M2](INFO): created writer for : platform_orientation
2019-10-21T22:42:25.268Z,1571697745.268 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2019-10-21T22:42:25.273Z,1571697745.273 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2019-10-21T22:42:25.273Z,1571697745.273 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2019-10-21T22:42:25.278Z,1571697745.278 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2019-10-21T22:42:25.279Z,1571697745.279 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2019-10-21T22:42:25.284Z,1571697745.284 [AHRS_M2](INFO): created writer for : platform_roll_angle
2019-10-21T22:42:25.371Z,1571697745.371 [AHRS_M2] Loaded
2019-10-21T22:42:25.372Z,1571697745.372 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-10-21T22:42:25.451Z,1571697745.451 [DataOverHttps] Loaded
2019-10-21T22:42:25.451Z,1571697745.451 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-10-21T22:42:25.452Z,1571697745.452 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4086C4E0
2019-10-21T22:42:25.452Z,1571697745.452 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 5396
2019-10-21T22:42:25.466Z,1571697745.466 [Depth_Keller] Loaded
2019-10-21T22:42:25.466Z,1571697745.466 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-10-21T22:42:25.471Z,1571697745.471 [DropWeight] Loaded
2019-10-21T22:42:25.471Z,1571697745.471 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-10-21T22:42:25.567Z,1571697745.567 [NAL9602] Loaded
2019-10-21T22:42:25.567Z,1571697745.567 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-10-21T22:42:25.582Z,1571697745.582 [Onboard] Loaded
2019-10-21T22:42:25.588Z,1571697745.588 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-10-21T22:42:25.617Z,1571697745.617 [Radio_Surface] Loaded
2019-10-21T22:42:25.617Z,1571697745.617 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-10-21T22:42:25.623Z,1571697745.623 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4089C4E0
2019-10-21T22:42:25.623Z,1571697745.623 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 5397
2019-10-21T22:42:27.511Z,1571697747.511 [BPC1] Loaded
2019-10-21T22:42:27.511Z,1571697747.511 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-10-21T22:42:27.511Z,1571697747.511 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-10-21T22:42:27.512Z,1571697747.512 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-10-21T22:42:27.553Z,1571697747.553 [DepthRateCalculator] Loaded
2019-10-21T22:42:27.553Z,1571697747.553 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-10-21T22:42:27.558Z,1571697747.558 [PitchRateCalculator] Loaded
2019-10-21T22:42:27.558Z,1571697747.558 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-10-21T22:42:27.572Z,1571697747.572 [SpeedCalculator] Loaded
2019-10-21T22:42:27.572Z,1571697747.572 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-10-21T22:42:27.593Z,1571697747.593 [TempGradientCalculator] Loaded
2019-10-21T22:42:27.594Z,1571697747.594 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-10-21T22:42:27.598Z,1571697747.598 [YawRateCalculator] Loaded
2019-10-21T22:42:27.599Z,1571697747.599 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-10-21T22:42:27.673Z,1571697747.673 [ElevatorOffsetCalculator] Loaded
2019-10-21T22:42:27.673Z,1571697747.673 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-10-21T22:42:27.673Z,1571697747.673 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-10-21T22:42:27.674Z,1571697747.674 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-10-21T22:42:27.877Z,1571697747.877 [Aanderaa_O2] Loaded
2019-10-21T22:42:27.877Z,1571697747.877 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2019-10-21T22:42:27.890Z,1571697747.890 [CANONSampler] Loaded
2019-10-21T22:42:27.891Z,1571697747.891 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2019-10-21T22:42:27.900Z,1571697747.900 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-10-21T22:42:27.905Z,1571697747.905 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-10-21T22:42:27.905Z,1571697747.905 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-10-21T22:42:27.910Z,1571697747.910 [CTD_Seabird](INFO): created writer for : depth
2019-10-21T22:42:27.910Z,1571697747.910 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-10-21T22:42:27.915Z,1571697747.915 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-10-21T22:42:27.916Z,1571697747.916 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-10-21T22:42:27.921Z,1571697747.921 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-10-21T22:42:27.921Z,1571697747.921 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-10-21T22:42:27.926Z,1571697747.926 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-10-21T22:42:27.927Z,1571697747.927 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-10-21T22:42:27.932Z,1571697747.932 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-10-21T22:42:27.933Z,1571697747.933 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-10-21T22:42:27.937Z,1571697747.937 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-10-21T22:42:27.965Z,1571697747.965 [CTD_Seabird] Loaded
2019-10-21T22:42:27.965Z,1571697747.965 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-10-21T22:42:27.966Z,1571697747.966 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 4099F4E0
2019-10-21T22:42:27.967Z,1571697747.967 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 5398
2019-10-21T22:42:28.084Z,1571697748.084 [PAR_Licor] Loaded
2019-10-21T22:42:28.086Z,1571697748.086 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-10-21T22:42:28.142Z,1571697748.142 [WetLabsBB2FL] Loaded
2019-10-21T22:42:28.143Z,1571697748.143 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-10-21T22:42:28.144Z,1571697748.144 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409CF4E0
2019-10-21T22:42:28.144Z,1571697748.144 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 5399
2019-10-21T22:42:28.145Z,1571697748.145 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-10-21T22:42:28.145Z,1571697748.145 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-10-21T22:42:28.179Z,1571697748.179 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-10-21T22:42:28.179Z,1571697748.179 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-10-21T22:42:28.549Z,1571697748.549 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-10-21T22:42:28.549Z,1571697748.549 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-10-21T22:42:28.680Z,1571697748.680 [SBIT](DEBUG): Construct Startup Built In Test.
2019-10-21T22:42:28.691Z,1571697748.691 [SBIT] Loaded
2019-10-21T22:42:28.691Z,1571697748.691 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-10-21T22:42:28.692Z,1571697748.692 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-10-21T22:42:28.704Z,1571697748.704 [IBIT] Loaded
2019-10-21T22:42:28.705Z,1571697748.705 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-10-21T22:42:28.708Z,1571697748.708 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-10-21T22:42:28.911Z,1571697748.911 [CBIT] Loaded
2019-10-21T22:42:28.911Z,1571697748.911 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-10-21T22:42:28.912Z,1571697748.912 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-10-21T22:42:28.916Z,1571697748.916 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-10-21T22:42:28.917Z,1571697748.917 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-10-21T22:42:28.924Z,1571697748.924 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-10-21T22:42:28.925Z,1571697748.925 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40ACE4E0
2019-10-21T22:42:28.925Z,1571697748.925 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 5400
2019-10-21T22:42:28.940Z,1571697748.940 [Supervisor](INFO): Main Thread ID is 5114
2019-10-21T22:42:28.940Z,1571697748.940 [Supervisor](DEBUG): Running supervisor.
2019-10-21T22:42:28.941Z,1571697748.941 [CommandLine ThreadHandler](INFO): Handler Thread ID is 5401
2019-10-21T22:42:28.943Z,1571697748.943 [controlThread ThreadHandler](INFO): Handler Thread ID is 5402
2019-10-21T22:42:28.944Z,1571697748.944 [controlThread](DEBUG): Initializing ControlThread
2019-10-21T22:42:28.944Z,1571697748.944 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-10-21T22:42:28.946Z,1571697748.946 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-10-21T22:42:28.947Z,1571697748.947 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-10-21T22:42:28.947Z,1571697748.947 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-10-21T22:42:28.949Z,1571697748.949 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-10-21T22:42:28.949Z,1571697748.949 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-10-21T22:42:28.953Z,1571697748.953 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-10-21T22:42:28.953Z,1571697748.953 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-10-21T22:42:28.954Z,1571697748.954 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-10-21T22:42:28.954Z,1571697748.954 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-10-21T22:42:28.955Z,1571697748.955 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-10-21T22:42:28.955Z,1571697748.955 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-10-21T22:42:28.959Z,1571697748.959 [SBIT](INFO): Initialize SBIT Component.
2019-10-21T22:42:28.959Z,1571697748.959 [SBIT](IMPORTANT): git: 2019-10-18
2019-10-21T22:42:28.959Z,1571697748.959 [SBIT](INFO): git hash: 6ae7fb07418ec55f2c4bd6dfbf631ba443720c7a
2019-10-21T22:42:28.960Z,1571697748.960 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-10-21T22:42:28.961Z,1571697748.961 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
2019-10-21T22:42:28.962Z,1571697748.962 [SBIT](INFO): Beginning SBIT in 39.000000 seconds.
2019-10-21T22:42:28.963Z,1571697748.963 [IBIT](INFO): Initialize IBIT Component.
2019-10-21T22:42:28.964Z,1571697748.964 [CBIT](DEBUG): Initialize CBIT Component.
2019-10-21T22:42:28.964Z,1571697748.964 [logger ThreadHandler](INFO): Handler Thread ID is 5403
2019-10-21T22:42:28.974Z,1571697748.974 [CBIT](DEBUG): Initialized mux pins.
2019-10-21T22:42:28.975Z,1571697748.975 [CBIT](DEBUG): Initializing the watchdog timer.
2019-10-21T22:42:28.983Z,1571697748.983 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 5404
2019-10-21T22:42:28.984Z,1571697748.984 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-10-21T22:42:28.995Z,1571697748.995 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 5405
2019-10-21T22:42:28.998Z,1571697748.998 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-10-21T22:42:28.999Z,1571697748.999 [CBIT](DEBUG): Initializing heartbeat.
2019-10-21T22:42:29.007Z,1571697749.007 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 5406
2019-10-21T22:42:29.007Z,1571697749.007 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-10-21T22:42:29.011Z,1571697749.011 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-10-21T22:42:29.012Z,1571697749.012 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 5408
2019-10-21T22:42:29.013Z,1571697749.013 [WetLabsBB2FL](INFO): Powering down
2019-10-21T22:42:29.040Z,1571697749.040 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 5409
2019-10-21T22:42:29.043Z,1571697749.043 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-10-21T22:42:29.043Z,1571697749.043 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-10-21T22:42:29.044Z,1571697749.044 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-10-21T22:42:29.044Z,1571697749.044 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-10-21T22:42:29.044Z,1571697749.044 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-10-21T22:42:29.044Z,1571697749.044 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-10-21T22:42:29.044Z,1571697749.044 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-10-21T22:42:29.045Z,1571697749.045 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-10-21T22:42:29.045Z,1571697749.045 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-10-21T22:42:29.045Z,1571697749.045 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-10-21T22:42:29.045Z,1571697749.045 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-10-21T22:42:29.045Z,1571697749.045 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-10-21T22:42:29.046Z,1571697749.046 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-10-21T22:42:29.046Z,1571697749.046 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-10-21T22:42:29.046Z,1571697749.046 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-10-21T22:42:29.046Z,1571697749.046 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-10-21T22:42:29.070Z,1571697749.070 [CBIT](DEBUG): Deactivating GF circuits.
2019-10-21T22:42:29.071Z,1571697749.071 [CBIT](DEBUG): Deactivating emergency mode.
2019-10-21T22:42:29.106Z,1571697749.106 [CBIT](DEBUG): Backplane powered.
2019-10-21T22:42:29.107Z,1571697749.107 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-10-21T22:42:29.117Z,1571697749.117 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-10-21T22:42:29.152Z,1571697749.152 [MissionManager](DEBUG):
2019-10-21T22:42:29.153Z,1571697749.153 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-10-21T22:42:29.236Z,1571697749.236 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-10-21T22:42:29.275Z,1571697749.275 [Default:A.Wait](DEBUG): Construct Wait.
2019-10-21T22:42:29.277Z,1571697749.277 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-10-21T22:42:29.300Z,1571697749.300 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-10-21T22:42:29.335Z,1571697749.335 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-10-21T22:42:29.340Z,1571697749.340 [Default:E.Execute](DEBUG): Construct Execute.
2019-10-21T22:42:29.376Z,1571697749.376 [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-10-21T22:42:29.381Z,1571697749.381 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,Onboard,BPC1,Aanderaa_O2,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-10-21T22:42:29.394Z,1571697749.394 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-10-21T22:42:29.399Z,1571697749.399 [Radio_Surface](INFO): Powering up
2019-10-21T22:42:29.519Z,1571697749.519 [CANONSampler](INFO): Powering down
2019-10-21T22:42:29.680Z,1571697749.680 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-10-21T22:42:29.693Z,1571697749.693 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-10-21T22:42:29.695Z,1571697749.695 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-10-21T22:42:29.711Z,1571697749.711 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-10-21T22:42:29.712Z,1571697749.712 [MassServo](DEBUG): Initializing EZServoServo.
2019-10-21T22:42:29.712Z,1571697749.712 [MassServo](DEBUG): Initializing MassServo.
2019-10-21T22:42:29.713Z,1571697749.713 [RudderServo](DEBUG): Initializing EZServoServo.
2019-10-21T22:42:29.720Z,1571697749.720 [RudderServo](DEBUG): Initializing RudderServo.
2019-10-21T22:42:29.721Z,1571697749.721 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-10-21T22:42:29.739Z,1571697749.739 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-10-21T22:42:30.575Z,1571697750.575 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-10-21T22:42:30.575Z,1571697750.575 [RudderServo](FAULT): Rudder failed to initialize
2019-10-21T22:42:30.575Z,1571697750.575 [RudderServo] Communications Fault, FailCount= 1
2019-10-21T22:42:30.575Z,1571697750.575 [RudderServo](ERROR): Communications Fault
2019-10-21T22:42:30.686Z,1571697750.686 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-10-21T22:42:30.899Z,1571697750.899 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-10-21T22:42:30.899Z,1571697750.899 [RudderServo](INFO): Powering down
2019-10-21T22:42:31.547Z,1571697751.547 [RudderServo](DEBUG): Initializing EZServoServo.
2019-10-21T22:42:31.679Z,1571697751.679 [RudderServo](DEBUG): Initializing RudderServo.
2019-10-21T22:42:31.714Z,1571697751.714 [CBIT](INFO): Clearing failed state for component RudderServo
2019-10-21T22:42:31.714Z,1571697751.714 [RudderServo] No Fault, FailCount= 1
2019-10-21T22:42:32.927Z,1571697752.927 [Aanderaa_O2](INFO): Powering down
2019-10-21T22:42:36.039Z,1571697756.039 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2019-10-21T22:42:55.677Z,1571697775.677 [NAL9602](INFO): Powering up NAL9602
2019-10-21T22:43:06.585Z,1571697786.585 [NAL9602](INFO): NAL9602 initialized
2019-10-21T22:43:08.650Z,1571697788.650 [SBIT](IMPORTANT): Beginning Startup BIT
2019-10-21T22:43:08.659Z,1571697788.659 [CBIT](IMPORTANT): Beginning ground fault scan
2019-10-21T22:43:19.327Z,1571697799.327 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 4.657929
CHAN A1 (24V): -0.181053
CHAN A2 (12V): -0.002622
CHAN A3 (5V): 4.753929
CHAN B0 (3.3V): 0.001850
CHAN B1 (3.15aV): -0.000441
CHAN B2 (3.15bV): -0.000382
CHAN B3 (GND): -0.000066
OPEN: -0.000206
Full Scale Calc: 4.765 mA, -1.589 mA
2019-10-21T22:43:40.080Z,1571697820.080 [NAL9602](INFO): SBD MO Status=2, MOMSN=16895, MT Status=2, MTMSN=0
2019-10-21T22:43:40.081Z,1571697820.081 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-10-21T22:43:56.779Z,1571697836.779 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-10-21T22:44:02.025Z,1571697842.025 [SBIT](IMPORTANT): SBIT PASSED
2019-10-21T22:44:02.112Z,1571697842.112 [CommandLine](IMPORTANT): got command configSet list
2019-10-21T22:44:02.112Z,1571697842.112 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-10-21T22:44:02.113Z,1571697842.113 [CommandLine](IMPORTANT): CBIT.gf24Offset=154 microampere;
2019-10-21T22:44:02.114Z,1571697842.114 [CommandLine](IMPORTANT): CTD_NeilBrown.loadAtStartup=0 bool;
2019-10-21T22:44:02.114Z,1571697842.114 [CommandLine](IMPORTANT): DAT.loadAtStartup=0 bool;
2019-10-21T22:44:02.114Z,1571697842.114 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup=0 bool;
2019-10-21T22:44:02.114Z,1571697842.114 [CommandLine](IMPORTANT): VerticalControl.massDefault=-0.5 centimeter;
2019-10-21T22:44:02.442Z,1571697842.442 [MissionManager](IMPORTANT): Started mission Startup
2019-10-21T22:44:02.442Z,1571697842.442 [Startup] Running Loop=1
2019-10-21T22:44:02.442Z,1571697842.442 [Startup](DEBUG): Aggregate::initialize Startup
2019-10-21T22:44:02.442Z,1571697842.442 [Startup:A.GoToSurface] Running Loop=1
2019-10-21T22:44:02.443Z,1571697842.443 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-10-21T22:44:02.443Z,1571697842.443 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-10-21T22:44:02.444Z,1571697842.444 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-10-21T22:44:02.444Z,1571697842.444 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-10-21T22:44:02.444Z,1571697842.444 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-10-21T22:44:02.445Z,1571697842.445 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-10-21T22:44:02.446Z,1571697842.446 [Startup:StartupSatComms] Running Loop=1
2019-10-21T22:44:02.446Z,1571697842.446 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-10-21T22:44:02.446Z,1571697842.446 [Startup:StartupSatComms:A] Running Loop=1
2019-10-21T22:44:02.856Z,1571697842.856 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-10-21T22:44:09.308Z,1571697849.308 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-10-21T22:44:09.717Z,1571697849.717 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-10-21T22:44:21.816Z,1571697861.816 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-10-21T22:44:48.474Z,1571697888.474 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-10-21T22:45:01.007Z,1571697901.007 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-10-21T22:45:02.637Z,1571697902.637 [Startup:StartupSatComms:A](INFO): Timed out from 2019-10-21T22:44:02.4Z
2019-10-21T22:45:02.637Z,1571697902.637 [Startup:StartupSatComms:A] Stopped
2019-10-21T22:45:02.637Z,1571697902.637 [Startup:StartupSatComms:B] Running Loop=1
2019-10-21T22:45:03.037Z,1571697903.037 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-10-21T22:45:13.556Z,1571697913.556 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-10-21T22:45:13.946Z,1571697913.946 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-10-21T22:45:26.448Z,1571697926.448 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2019-10-21T22:45:26.448Z,1571697926.448 [BPC1](ERROR): BPC1B failed to parse battery stick message.
2019-10-21T22:45:26.867Z,1571697926.867 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-10-21T22:45:29.293Z,1571697929.293 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-10-21T22:45:29.293Z,1571697929.293 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-10-21T22:45:29.303Z,1571697929.303 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-10-21T22:45:29.717Z,1571697929.717 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-10-21T22:45:29.717Z,1571697929.717 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-10-21T22:45:39.380Z,1571697939.380 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-10-21T22:46:02.833Z,1571697962.833 [Startup:StartupSatComms:B](INFO): Timed out from 2019-10-21T22:45:02.6Z
2019-10-21T22:46:02.833Z,1571697962.833 [Startup:StartupSatComms:B] Stopped
2019-10-21T22:46:02.833Z,1571697962.833 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-10-21T22:46:02.833Z,1571697962.833 [Startup:StartupSatComms] Stopped
2019-10-21T22:46:02.834Z,1571697962.834 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-10-21T22:46:02.835Z,1571697962.835 [Startup](INFO): Completed Startup
2019-10-21T22:46:02.835Z,1571697962.835 [MissionManager](INFO): Startup is completed.
2019-10-21T22:46:02.836Z,1571697962.836 [MissionManager](INFO): Uninitializing Mission Startup
2019-10-21T22:46:02.836Z,1571697962.836 [Startup] Stopped
2019-10-21T22:46:02.836Z,1571697962.836 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-10-21T22:46:02.836Z,1571697962.836 [Startup:A.GoToSurface] Stopped
2019-10-21T22:46:02.836Z,1571697962.836 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-10-21T22:46:03.253Z,1571697963.253 [MissionManager](IMPORTANT): Started mission Default
2019-10-21T22:46:03.253Z,1571697963.253 [Default] Running Loop=1
2019-10-21T22:46:03.253Z,1571697963.253 [Default](DEBUG): Aggregate::initialize Default
2019-10-21T22:46:03.253Z,1571697963.253 [Default:B.GoToSurface] R