2021-04-11T15:53:21.513Z,1618156401.513 [Supervisor](DEBUG): Initializing supervisor.
2021-04-11T15:53:21.518Z,1618156401.518 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2021-04-11T15:53:21.518Z,1618156401.518 [SyncHandler](INFO): Protected caller Thread ID is 6960
2021-04-11T15:53:21.519Z,1618156401.519 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2021-04-11T15:53:21.520Z,1618156401.520 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2021-04-11T15:53:21.520Z,1618156401.520 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 6961
2021-04-11T15:53:21.524Z,1618156401.524 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2021-04-11T15:53:21.544Z,1618156401.544 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2021-04-11T15:53:21.545Z,1618156401.545 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2021-04-11T15:53:21.545Z,1618156401.545 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 6962
2021-04-11T15:53:21.547Z,1618156401.547 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2021-04-11T15:53:21.548Z,1618156401.548 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2021-04-11T15:53:21.549Z,1618156401.549 [logger ThreadHandler](INFO): Protected caller Thread ID is 6963
2021-04-11T15:53:21.552Z,1618156401.552 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2021-04-11T15:53:21.553Z,1618156401.553 [Supervisor](INFO): Looking for Config files in directory: Config/
2021-04-11T15:53:21.555Z,1618156401.555 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2021-04-11T15:53:21.882Z,1618156401.882 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2021-04-11T15:53:21.883Z,1618156401.883 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2021-04-11T15:53:22.485Z,1618156402.485 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2021-04-11T15:53:22.485Z,1618156402.485 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2021-04-11T15:53:22.583Z,1618156402.583 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2021-04-11T15:53:22.584Z,1618156402.584 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2021-04-11T15:53:23.109Z,1618156403.109 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2021-04-11T15:53:23.110Z,1618156403.110 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2021-04-11T15:53:23.204Z,1618156403.204 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2021-04-11T15:53:23.205Z,1618156403.205 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2021-04-11T15:53:23.287Z,1618156403.287 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2021-04-11T15:53:23.646Z,1618156403.646 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2021-04-11T15:53:23.647Z,1618156403.647 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2021-04-11T15:53:23.796Z,1618156403.796 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2021-04-11T15:53:23.796Z,1618156403.796 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2021-04-11T15:53:23.920Z,1618156403.920 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2021-04-11T15:53:23.920Z,1618156403.920 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2021-04-11T15:53:24.161Z,1618156404.161 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2021-04-11T15:53:24.161Z,1618156404.161 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2021-04-11T15:53:24.598Z,1618156404.598 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2021-04-11T15:53:24.599Z,1618156404.599 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2021-04-11T15:53:24.961Z,1618156404.961 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2021-04-11T15:53:24.962Z,1618156404.962 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2021-04-11T15:53:25.039Z,1618156405.039 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2021-04-11T15:53:25.229Z,1618156405.229 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2021-04-11T15:53:25.229Z,1618156405.229 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2021-04-11T15:53:25.436Z,1618156405.436 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2021-04-11T15:53:25.437Z,1618156405.437 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2021-04-11T15:53:25.691Z,1618156405.691 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2021-04-11T15:53:25.693Z,1618156405.693 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-brizo/
2021-04-11T15:53:25.694Z,1618156405.694 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Control.cfg
2021-04-11T15:53:26.052Z,1618156406.052 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Sensor.cfg
2021-04-11T15:53:26.337Z,1618156406.337 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Simulator.cfg
2021-04-11T15:53:26.475Z,1618156406.475 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/secure.cfg
2021-04-11T15:53:26.559Z,1618156406.559 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Servo.cfg
2021-04-11T15:53:26.665Z,1618156406.665 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/vehicle.cfg
2021-04-11T15:53:26.848Z,1618156406.848 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Battery.cfg
2021-04-11T15:53:27.105Z,1618156407.105 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2021-04-11T15:53:27.105Z,1618156407.105 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Science.cfg
2021-04-11T15:53:27.224Z,1618156407.224 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/logger.cfg
2021-04-11T15:53:27.318Z,1618156407.318 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/BIT.cfg
2021-04-11T15:53:27.421Z,1618156407.421 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Navigation.cfg
2021-04-11T15:53:27.515Z,1618156407.515 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2021-04-11T15:53:27.524Z,1618156407.524 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2021-04-11T15:53:27.634Z,1618156407.634 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2021-04-11T15:53:27.634Z,1618156407.634 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2021-04-11T15:53:27.651Z,1618156407.651 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2021-04-11T15:53:27.651Z,1618156407.651 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2021-04-11T15:53:27.707Z,1618156407.707 [DepthRateCalculator] Loaded
2021-04-11T15:53:27.708Z,1618156407.708 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2021-04-11T15:53:27.713Z,1618156407.713 [PitchRateCalculator] Loaded
2021-04-11T15:53:27.713Z,1618156407.713 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2021-04-11T15:53:27.724Z,1618156407.724 [SpeedCalculator] Loaded
2021-04-11T15:53:27.724Z,1618156407.724 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2021-04-11T15:53:27.771Z,1618156407.771 [TempGradientCalculator] Loaded
2021-04-11T15:53:27.771Z,1618156407.771 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2021-04-11T15:53:27.776Z,1618156407.776 [YawRateCalculator] Loaded
2021-04-11T15:53:27.776Z,1618156407.776 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2021-04-11T15:53:27.840Z,1618156407.840 [ElevatorOffsetCalculator] Loaded
2021-04-11T15:53:27.840Z,1618156407.840 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2021-04-11T15:53:27.840Z,1618156407.840 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2021-04-11T15:53:27.841Z,1618156407.841 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2021-04-11T15:53:27.910Z,1618156407.910 [VerticalControl](DEBUG): Construct VerticalControl.
2021-04-11T15:53:27.966Z,1618156407.966 [VerticalControl] Loaded
2021-04-11T15:53:27.966Z,1618156407.966 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2021-04-11T15:53:27.969Z,1618156407.969 [HorizontalControl](DEBUG): Construct HorizontalControl.
2021-04-11T15:53:28.006Z,1618156408.006 [HorizontalControl] Loaded
2021-04-11T15:53:28.006Z,1618156408.006 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2021-04-11T15:53:28.009Z,1618156408.009 [SpeedControl](DEBUG): Construct SpeedControl.
2021-04-11T15:53:28.011Z,1618156408.011 [SpeedControl] Loaded
2021-04-11T15:53:28.012Z,1618156408.012 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2021-04-11T15:53:28.014Z,1618156408.014 [LoopControl](DEBUG): Construct LoopControl.
2021-04-11T15:53:28.015Z,1618156408.015 [LoopControl] Loaded
2021-04-11T15:53:28.015Z,1618156408.015 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2021-04-11T15:53:28.015Z,1618156408.015 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2021-04-11T15:53:28.016Z,1618156408.016 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2021-04-11T15:53:28.112Z,1618156408.112 [DeadReckonUsingMultipleVelocitySources] Loaded
2021-04-11T15:53:28.112Z,1618156408.112 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2021-04-11T15:53:28.124Z,1618156408.124 [NavChart] Loaded
2021-04-11T15:53:28.125Z,1618156408.125 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2021-04-11T15:53:28.130Z,1618156408.130 [UniversalFixResidualReporter] Loaded
2021-04-11T15:53:28.131Z,1618156408.131 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2021-04-11T15:53:28.131Z,1618156408.131 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2021-04-11T15:53:28.132Z,1618156408.132 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2021-04-11T15:53:28.257Z,1618156408.257 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2021-04-11T15:53:28.258Z,1618156408.258 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2021-04-11T15:53:28.706Z,1618156408.706 [AHRS_M2] Loaded
2021-04-11T15:53:28.706Z,1618156408.706 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2021-04-11T15:53:28.735Z,1618156408.735 [BackseatComponent] Loaded
2021-04-11T15:53:28.735Z,1618156408.735 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2021-04-11T15:53:28.736Z,1618156408.736 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408674E0
2021-04-11T15:53:28.737Z,1618156408.737 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 7047
2021-04-11T15:53:28.739Z,1618156408.739 [LcmUniversalReporter] Loaded
2021-04-11T15:53:28.740Z,1618156408.740 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2021-04-11T15:53:29.515Z,1618156409.515 [BPC1] Loaded
2021-04-11T15:53:29.515Z,1618156409.515 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2021-04-11T15:53:29.586Z,1618156409.586 [DataOverHttps] Loaded
2021-04-11T15:53:29.586Z,1618156409.586 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2021-04-11T15:53:29.587Z,1618156409.587 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408974E0
2021-04-11T15:53:29.587Z,1618156409.587 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 7048
2021-04-11T15:53:29.606Z,1618156409.606 [Depth_Keller] Loaded
2021-04-11T15:53:29.607Z,1618156409.607 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2021-04-11T15:53:29.611Z,1618156409.611 [DropWeight] Loaded
2021-04-11T15:53:29.611Z,1618156409.611 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2021-04-11T15:53:29.645Z,1618156409.645 [DVL_micro] Loaded
2021-04-11T15:53:29.646Z,1618156409.646 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2021-04-11T15:53:29.703Z,1618156409.703 [NAL9602] Loaded
2021-04-11T15:53:29.703Z,1618156409.703 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2021-04-11T15:53:29.731Z,1618156409.731 [Onboard] Loaded
2021-04-11T15:53:29.732Z,1618156409.732 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2021-04-11T15:53:29.733Z,1618156409.733 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408C74E0
2021-04-11T15:53:29.733Z,1618156409.733 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 7049
2021-04-11T15:53:29.746Z,1618156409.746 [Radio_Surface] Loaded
2021-04-11T15:53:29.746Z,1618156409.746 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2021-04-11T15:53:29.747Z,1618156409.747 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408F74E0
2021-04-11T15:53:29.747Z,1618156409.747 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 7050
2021-04-11T15:53:29.826Z,1618156409.826 [DAT] Loaded
2021-04-11T15:53:29.826Z,1618156409.826 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2021-04-11T15:53:29.827Z,1618156409.827 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2021-04-11T15:53:29.827Z,1618156409.827 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2021-04-11T15:53:29.956Z,1618156409.956 [BuoyancyServo] Loaded
2021-04-11T15:53:29.956Z,1618156409.956 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2021-04-11T15:53:29.975Z,1618156409.975 [ElevatorServo] Loaded
2021-04-11T15:53:29.975Z,1618156409.975 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2021-04-11T15:53:29.993Z,1618156409.993 [MassServo] Loaded
2021-04-11T15:53:29.994Z,1618156409.994 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2021-04-11T15:53:30.011Z,1618156410.011 [RudderServo] Loaded
2021-04-11T15:53:30.011Z,1618156410.011 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2021-04-11T15:53:30.028Z,1618156410.028 [ThrusterServo] Loaded
2021-04-11T15:53:30.029Z,1618156410.029 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2021-04-11T15:53:30.029Z,1618156410.029 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2021-04-11T15:53:30.030Z,1618156410.030 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2021-04-11T15:53:30.106Z,1618156410.106 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2021-04-11T15:53:30.107Z,1618156410.107 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2021-04-11T15:53:30.148Z,1618156410.148 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2021-04-11T15:53:30.149Z,1618156410.149 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2021-04-11T15:53:30.508Z,1618156410.508 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2021-04-11T15:53:30.509Z,1618156410.509 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2021-04-11T15:53:30.723Z,1618156410.723 [CTD_Seabird] Loaded
2021-04-11T15:53:30.724Z,1618156410.724 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2021-04-11T15:53:30.725Z,1618156410.725 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A7F4E0
2021-04-11T15:53:30.725Z,1618156410.725 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 7051
2021-04-11T15:53:30.756Z,1618156410.756 [ESPComponent] Loaded
2021-04-11T15:53:30.757Z,1618156410.757 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2021-04-11T15:53:30.775Z,1618156410.775 [PAR_Licor] Loaded
2021-04-11T15:53:30.776Z,1618156410.776 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2021-04-11T15:53:30.807Z,1618156410.807 [WetLabsBB2FL] Loaded
2021-04-11T15:53:30.807Z,1618156410.807 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2021-04-11T15:53:30.808Z,1618156410.808 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AAF4E0
2021-04-11T15:53:30.808Z,1618156410.808 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 7052
2021-04-11T15:53:30.809Z,1618156410.809 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2021-04-11T15:53:30.810Z,1618156410.810 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2021-04-11T15:53:31.347Z,1618156411.347 [SBIT](DEBUG): Construct Startup Built In Test.
2021-04-11T15:53:31.357Z,1618156411.357 [SBIT] Loaded
2021-04-11T15:53:31.357Z,1618156411.357 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2021-04-11T15:53:31.360Z,1618156411.360 [IBIT](DEBUG): Construct Initiated Built In Test.
2021-04-11T15:53:31.372Z,1618156411.372 [IBIT] Loaded
2021-04-11T15:53:31.373Z,1618156411.373 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2021-04-11T15:53:31.378Z,1618156411.378 [CBIT](DEBUG): Construct Continuous Built In Test.
2021-04-11T15:53:31.491Z,1618156411.491 [CBIT] Loaded
2021-04-11T15:53:31.491Z,1618156411.491 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2021-04-11T15:53:31.492Z,1618156411.492 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2021-04-11T15:53:31.498Z,1618156411.498 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2021-04-11T15:53:31.500Z,1618156411.500 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2021-04-11T15:53:31.511Z,1618156411.511 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2021-04-11T15:53:31.512Z,1618156411.512 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B1B4E0
2021-04-11T15:53:31.512Z,1618156411.512 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 7053
2021-04-11T15:53:31.517Z,1618156411.517 [Supervisor](INFO): Main Thread ID is 6959
2021-04-11T15:53:31.517Z,1618156411.517 [Supervisor](DEBUG): Running supervisor.
2021-04-11T15:53:31.518Z,1618156411.518 [CommandLine ThreadHandler](INFO): Handler Thread ID is 7054
2021-04-11T15:53:31.522Z,1618156411.522 [controlThread ThreadHandler](INFO): Handler Thread ID is 7055
2021-04-11T15:53:31.522Z,1618156411.522 [controlThread](DEBUG): Initializing ControlThread
2021-04-11T15:53:31.523Z,1618156411.523 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2021-04-11T15:53:31.523Z,1618156411.523 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2021-04-11T15:53:31.524Z,1618156411.524 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2021-04-11T15:53:31.524Z,1618156411.524 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2021-04-11T15:53:31.525Z,1618156411.525 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2021-04-11T15:53:31.525Z,1618156411.525 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2021-04-11T15:53:31.526Z,1618156411.526 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2021-04-11T15:53:31.527Z,1618156411.527 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2021-04-11T15:53:31.528Z,1618156411.528 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2021-04-11T15:53:31.529Z,1618156411.529 [LoopControl](DEBUG): Initialize LoopControlComponent.
2021-04-11T15:53:31.530Z,1618156411.530 [NavChart](DEBUG): Initialize NavChart Navigation.
2021-04-11T15:53:31.530Z,1618156411.530 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2021-04-11T15:53:31.541Z,1618156411.541 [SBIT](INFO): Initialize SBIT Component.
2021-04-11T15:53:31.542Z,1618156411.542 [SBIT](IMPORTANT): git: 2021-04-08-1-g2cf736d20
2021-04-11T15:53:31.542Z,1618156411.542 [SBIT](INFO): git hash: 2cf736d2050aa38b8c70bc5b54d41b1e0a6791a1
2021-04-11T15:53:31.542Z,1618156411.542 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2021-04-11T15:53:31.543Z,1618156411.543 [SBIT](IMPORTANT): Kernel Version:#1 PREEMPT Tue Sep 24 11:12:27 PDT 2019
2021-04-11T15:53:31.544Z,1618156411.544 [SBIT](INFO): Beginning SBIT in 22.000000 seconds.
2021-04-11T15:53:31.544Z,1618156411.544 [IBIT](INFO): Initialize IBIT Component.
2021-04-11T15:53:31.545Z,1618156411.545 [CBIT](DEBUG): Initialize CBIT Component.
2021-04-11T15:53:31.546Z,1618156411.546 [logger ThreadHandler](INFO): Handler Thread ID is 7056
2021-04-11T15:53:31.557Z,1618156411.557 [CBIT](DEBUG): Initialized mux pins.
2021-04-11T15:53:31.557Z,1618156411.557 [CBIT](DEBUG): Initializing the watchdog timer.
2021-04-11T15:53:31.565Z,1618156411.565 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 7057
2021-04-11T15:53:31.577Z,1618156411.577 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 7058
2021-04-11T15:53:31.578Z,1618156411.578 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2021-04-11T15:53:31.581Z,1618156411.581 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2021-04-11T15:53:31.582Z,1618156411.582 [CBIT](DEBUG): Initializing heartbeat.
2021-04-11T15:53:31.589Z,1618156411.589 [Onboard ThreadHandler](INFO): Handler Thread ID is 7059
2021-04-11T15:53:31.607Z,1618156411.607 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 7060
2021-04-11T15:53:31.626Z,1618156411.626 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 7061
2021-04-11T15:53:31.626Z,1618156411.626 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2021-04-11T15:53:31.631Z,1618156411.631 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 7063
2021-04-11T15:53:31.634Z,1618156411.634 [WetLabsBB2FL](INFO): Powering up
2021-04-11T15:53:31.635Z,1618156411.635 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 7065
2021-04-11T15:53:31.638Z,1618156411.638 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2021-04-11T15:53:31.638Z,1618156411.638 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2021-04-11T15:53:31.639Z,1618156411.639 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2021-04-11T15:53:31.639Z,1618156411.639 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2021-04-11T15:53:31.639Z,1618156411.639 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2021-04-11T15:53:31.639Z,1618156411.639 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2021-04-11T15:53:31.639Z,1618156411.639 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2021-04-11T15:53:31.639Z,1618156411.639 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2021-04-11T15:53:31.639Z,1618156411.639 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2021-04-11T15:53:31.640Z,1618156411.640 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2021-04-11T15:53:31.640Z,1618156411.640 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2021-04-11T15:53:31.640Z,1618156411.640 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2021-04-11T15:53:31.640Z,1618156411.640 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2021-04-11T15:53:31.640Z,1618156411.640 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2021-04-11T15:53:31.640Z,1618156411.640 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2021-04-11T15:53:31.641Z,1618156411.641 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2021-04-11T15:53:31.653Z,1618156411.653 [CBIT](DEBUG): Deactivating GF circuits.
2021-04-11T15:53:31.653Z,1618156411.653 [CBIT](DEBUG): Deactivating emergency mode.
2021-04-11T15:53:31.689Z,1618156411.689 [CBIT](DEBUG): Backplane powered.
2021-04-11T15:53:31.690Z,1618156411.690 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2021-04-11T15:53:31.703Z,1618156411.703 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2021-04-11T15:53:31.733Z,1618156411.733 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2021-04-11T15:53:31.734Z,1618156411.734 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2021-04-11T15:53:31.809Z,1618156411.809 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2021-04-11T15:53:31.810Z,1618156411.810 [Default:A.Wait](DEBUG): Construct Wait.
2021-04-11T15:53:31.812Z,1618156411.812 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-04-11T15:53:31.832Z,1618156411.832 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2021-04-11T15:53:31.864Z,1618156411.864 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2021-04-11T15:53:31.874Z,1618156411.874 [Default:E.Execute](DEBUG): Construct Execute.
2021-04-11T15:53:31.896Z,1618156411.896 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn on</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2021-04-11T15:53:31.901Z,1618156411.901 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,DAT,ESPComponent,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,LcmUniversalReporter,Reporter,LogSplitter,
2021-04-11T15:53:31.921Z,1618156411.921 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2021-04-11T15:53:32.013Z,1618156412.013 [Radio_Surface](INFO): Powering up
2021-04-11T15:53:32.325Z,1618156412.325 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2021-04-11T15:53:32.325Z,1618156412.325 [DAT](INFO): Powering up
2021-04-11T15:53:32.325Z,1618156412.325 [DAT](DEBUG): Initializing DAT.
2021-04-11T15:53:32.329Z,1618156412.329 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2021-04-11T15:53:32.428Z,1618156412.428 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2021-04-11T15:53:32.441Z,1618156412.441 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2021-04-11T15:53:32.442Z,1618156412.442 [ElevatorServo](DEBUG): Initializing EZServoServo.
2021-04-11T15:53:32.449Z,1618156412.449 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2021-04-11T15:53:32.450Z,1618156412.450 [MassServo](DEBUG): Initializing EZServoServo.
2021-04-11T15:53:32.461Z,1618156412.461 [MassServo](DEBUG): Initializing MassServo.
2021-04-11T15:53:32.462Z,1618156412.462 [RudderServo](DEBUG): Initializing EZServoServo.
2021-04-11T15:53:32.469Z,1618156412.469 [RudderServo](DEBUG): Initializing RudderServo.
2021-04-11T15:53:32.470Z,1618156412.470 [ThrusterServo](DEBUG): Initializing EZServoServo.
2021-04-11T15:53:32.478Z,1618156412.478 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2021-04-11T15:53:34.245Z,1618156414.245 [WetLabsBB2FL](INFO): Powering down
2021-04-11T15:53:45.275Z,1618156425.275 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004703
2021-04-11T15:53:46.297Z,1618156426.297 [DAT](INFO): commRate: 800
2021-04-11T15:53:48.307Z,1618156428.307 [DAT](INFO): entering command mode
2021-04-11T15:53:48.711Z,1618156428.711 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:53:49.112Z,1618156429.112 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:53:49.515Z,1618156429.515 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:53:49.944Z,1618156429.944 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:53:50.324Z,1618156430.324 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:53:50.727Z,1618156430.727 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:53:51.135Z,1618156431.135 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:53:51.535Z,1618156431.535 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:53:51.939Z,1618156431.939 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:53:52.352Z,1618156432.352 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:53:52.759Z,1618156432.759 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:53:53.151Z,1618156433.151 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:53:53.555Z,1618156433.555 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:53:53.964Z,1618156433.964 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:53:53.000Z,1618156434.000 [SBIT](IMPORTANT): Beginning Startup BIT
2021-04-11T15:53:54.008Z,1618156434.008 [CBIT](IMPORTANT): Beginning ground fault scan
2021-04-11T15:53:54.367Z,1618156434.367 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:53:54.780Z,1618156434.780 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:53:55.171Z,1618156435.171 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:53:55.580Z,1618156435.580 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:53:55.979Z,1618156435.979 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:53:56.383Z,1618156436.383 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:53:56.787Z,1618156436.787 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:53:57.203Z,1618156437.203 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:53:57.633Z,1618156437.633 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:53:57.999Z,1618156437.999 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:53:58.411Z,1618156438.411 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:53:58.812Z,1618156438.812 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:53:59.211Z,1618156439.211 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:53:59.615Z,1618156439.615 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:54:00.028Z,1618156440.028 [NAL9602](INFO): Powering up NAL9602
2021-04-11T15:54:00.034Z,1618156440.034 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:54:00.427Z,1618156440.427 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:54:00.827Z,1618156440.827 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:54:01.232Z,1618156441.232 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:54:01.635Z,1618156441.635 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:54:02.043Z,1618156442.043 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:54:02.488Z,1618156442.488 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:54:02.847Z,1618156442.847 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:54:03.251Z,1618156443.251 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:54:03.655Z,1618156443.655 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:54:03.655Z,1618156443.655 [DAT](FAULT): failed to enter command mode
2021-04-11T15:54:04.065Z,1618156444.065 [DAT](INFO): entering command mode
2021-04-11T15:54:04.472Z,1618156444.472 [DAT](INFO): setting verbose to 3
2021-04-11T15:54:04.869Z,1618156444.869 [DAT](INFO): set verbose to 3
2021-04-11T15:54:04.869Z,1618156444.869 [DAT](INFO): setting DatVerbose to 27440
2021-04-11T15:54:05.004Z,1618156445.004 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.000791
CHAN A1 (24V): -0.002177
CHAN A2 (12V): -0.000417
CHAN A3 (5V): -0.000122
CHAN B0 (3.3V): 0.000193
CHAN B1 (3.15aV): 0.000369
CHAN B2 (3.15bV): 0.000495
CHAN B3 (GND): 0.000861
OPEN: 0.003875
Full Scale Calc: 4.765 mA, -1.589 mA
2021-04-11T15:54:05.282Z,1618156445.282 [DAT](INFO): set DatVerbose to 27440
2021-04-11T15:54:05.282Z,1618156445.282 [DAT](INFO): setting transmit power to 8
2021-04-11T15:54:05.680Z,1618156445.680 [DAT](INFO): set transmit power to 8
2021-04-11T15:54:05.681Z,1618156445.681 [DAT](INFO): setting local address to 8
2021-04-11T15:54:06.081Z,1618156446.081 [DAT](INFO): set local address to 8
2021-04-11T15:54:10.935Z,1618156450.935 [NAL9602](INFO): NAL9602 initialized
2021-04-11T15:54:37.198Z,1618156477.198 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-04-11T15:54:48.135Z,1618156488.135 [SBIT](IMPORTANT): SBIT PASSED
2021-04-11T15:54:48.135Z,1618156488.135 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2021-04-11T15:54:48.136Z,1618156488.136 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;

2021-04-11T15:54:48.136Z,1618156488.136 [SBIT](IMPORTANT): BackseatComponent.loadAtStartup=1 bool;

2021-04-11T15:54:48.136Z,1618156488.136 [SBIT](IMPORTANT): BackseatComponent.simulateHardware=1 bool;

2021-04-11T15:54:48.136Z,1618156488.136 [SBIT](IMPORTANT): DAT.surfaceThreshold=-0.5 meter;

2021-04-11T15:54:48.136Z,1618156488.136 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=1 bool;

2021-04-11T15:54:48.136Z,1618156488.136 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=1 minute;

2021-04-11T15:54:48.137Z,1618156488.137 [SBIT](IMPORTANT): ESPComponent.simulateHardware=1 bool;

2021-04-11T15:54:48.137Z,1618156488.137 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=194.169302 cubic_centimeter;

2021-04-11T15:54:48.137Z,1618156488.137 [SBIT](IMPORTANT): VerticalControl.massDefault=-0.743969 millimeter;

2021-04-11T15:54:48.530Z,1618156488.530 [MissionManager](IMPORTANT): Started mission Startup
2021-04-11T15:54:48.531Z,1618156488.531 [Startup] Running Loop=1
2021-04-11T15:54:48.531Z,1618156488.531 [Startup](DEBUG): Aggregate::initialize Startup
2021-04-11T15:54:48.531Z,1618156488.531 [Startup:A.GoToSurface] Running Loop=1
2021-04-11T15:54:48.531Z,1618156488.531 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-04-11T15:54:48.532Z,1618156488.532 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-04-11T15:54:48.532Z,1618156488.532 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-04-11T15:54:48.532Z,1618156488.532 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-04-11T15:54:48.533Z,1618156488.533 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-04-11T15:54:48.533Z,1618156488.533 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-04-11T15:54:48.535Z,1618156488.535 [Startup:StartupSatComms] Running Loop=1
2021-04-11T15:54:48.535Z,1618156488.535 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2021-04-11T15:54:48.535Z,1618156488.535 [Startup:StartupSatComms:A] Running Loop=1
2021-04-11T15:54:48.920Z,1618156488.920 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2021-04-11T15:54:49.375Z,1618156489.375 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-04-11T15:55:01.091Z,1618156501.091 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-04-11T15:55:13.213Z,1618156513.213 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-04-11T15:55:24.926Z,1618156524.926 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-04-11T15:55:31.630Z,1618156531.630 [CommandLine](IMPORTANT): got command configSet DAT.sbdAddress -1.000000 enum persist
2021-04-11T15:55:36.638Z,1618156536.638 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-04-11T15:55:47.481Z,1618156547.481 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2021-04-11T15:55:47.484Z,1618156547.484 [BPC1](ERROR): BPC1A failed to parse battery stick message.
2021-04-11T15:55:48.711Z,1618156548.711 [Startup:StartupSatComms:A](INFO): Timed out from 2021-04-11T15:54:48.5Z
2021-04-11T15:55:48.711Z,1618156548.711 [Startup:StartupSatComms:A] Stopped
2021-04-11T15:55:48.711Z,1618156548.711 [Startup:StartupSatComms:B] Running Loop=1
2021-04-11T15:55:49.115Z,1618156549.115 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-04-11T15:55:55.597Z,1618156555.597 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210410T182532/Courier0013.lzma
2021-04-11T15:55:56.599Z,1618156556.599 [DataOverHttps](INFO): Moved sent file to Logs/20210410T182532/Courier0013.lzma.bak
2021-04-11T15:55:56.599Z,1618156556.599 [DataOverHttps](INFO): SBD MOMSN=15558288
2021-04-11T15:55:59.271Z,1618156559.271 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-04-11T15:56:11.385Z,1618156571.385 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-04-11T15:56:12.185Z,1618156572.185 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20210411T155321/Courier0000.lzma
2021-04-11T15:56:13.187Z,1618156573.187 [DataOverHttps](INFO): Moved sent file to Logs/20210411T155321/Courier0000.lzma.bak
2021-04-11T15:56:13.187Z,1618156573.187 [DataOverHttps](INFO): SBD MOMSN=15558290
2021-04-11T15:56:23.102Z,1618156583.102 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-04-11T15:56:25.545Z,1618156585.545 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-04-11T15:56:28.761Z,1618156588.761 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210410T182532/Express0014.lzma
2021-04-11T15:56:29.763Z,1618156589.763 [DataOverHttps](INFO): Moved sent file to Logs/20210410T182532/Express0014.lzma.bak
2021-04-11T15:56:29.763Z,1618156589.763 [DataOverHttps](INFO): SBD MOMSN=15558293
2021-04-11T15:56:31.530Z,1618156591.530 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2021-04-11T15:56:31.531Z,1618156591.531 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-11T15:56:31.541Z,1618156591.541 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-11T15:56:31.959Z,1618156591.959 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-11T15:56:31.960Z,1618156591.960 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2021-04-11T15:56:35.301Z,1618156595.301 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-04-11T15:56:45.334Z,1618156605.334 [DataOverHttps](INFO): Sending 950 bytes from file Logs/20210411T155321/Express0001.lzma
2021-04-11T15:56:46.344Z,1618156606.344 [DataOverHttps](INFO): Moved sent file to Logs/20210411T155321/Express0001.lzma.bak
2021-04-11T15:56:46.344Z,1618156606.344 [DataOverHttps](INFO): SBD MOMSN=15558296
2021-04-11T15:56:46.940Z,1618156606.940 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-04-11T15:56:48.117Z,1618156608.117 [Startup:StartupSatComms:B] Stopped
2021-04-11T15:56:48.117Z,1618156608.117 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2021-04-11T15:56:48.117Z,1618156608.117 [Startup:StartupSatComms] Stopped
2021-04-11T15:56:48.117Z,1618156608.117 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2021-04-11T15:56:48.118Z,1618156608.118 [Startup](INFO): Completed Startup
2021-04-11T15:56:48.118Z,1618156608.118 [MissionManager](INFO): Startup is completed.
2021-04-11T15:56:48.118Z,1618156608.118 [MissionManager](INFO): Uninitializing Mission Startup
2021-04-11T15:56:48.118Z,1618156608.118 [Startup] Stopped
2021-04-11T15:56:48.119Z,1618156608.119 [Startup](DEBUG): Aggregate::uninitialize Startup
2021-04-11T15:56:48.119Z,1618156608.119 [Startup:A.GoToSurface] Stopped
2021-04-11T15:56:48.119Z,1618156608.119 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-04-11T15:56:48.520Z,1618156608.520 [MissionManager](IMPORTANT): Started mission Default
2021-04-11T15:56:48.520Z,1618156608.520 [Default] Running Loop=1
2021-04-11T15:56:48.520Z,1618156608.520 [Default](DEBUG): Aggregate::initialize Default
2021-04-11T15:56:48.520Z,1618156608.520 [Default:B.GoToSurface] Running Loop=1
2021-04-11T15:56:48.520Z,1618156608.520 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-04-11T15:56:48.520Z,1618156608.520 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-04-11T15:56:48.521Z,1618156608.521 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-04-11T15:56:48.521Z,1618156608.521 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-04-11T15:56:48.522Z,1618156608.522 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-04-11T15:56:48.522Z,1618156608.522 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-04-11T15:56:48.522Z,1618156608.522 [Default:A.Wait] Running Loop=1
2021-04-11T15:56:48.522Z,1618156608.522 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-04-11T15:57:01.854Z,1618156621.854 [Default:A.Wait](INFO): Done Waiting.
2021-04-11T15:57:01.854Z,1618156621.854 [Default:A.Wait] Stopped
2021-04-11T15:57:01.854Z,1618156621.854 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-04-11T15:57:02.251Z,1618156622.251 [Default:CheckIn] Running Loop=1
2021-04-11T15:57:02.251Z,1618156622.251 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-11T15:57:02.251Z,1618156622.251 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-11T15:57:02.642Z,1618156622.642 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2021-04-11T15:57:28.984Z,1618156648.984 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-04-11T15:57:42.688Z,1618156662.688 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-04-11T15:58:25.217Z,1618156705.217 [CommandLine](IMPORTANT): got command run ./Missions/send_rep_test.xml
2021-04-11T15:58:25.217Z,1618156705.217 [MissionManager](INFO): Loading Mission: ./Missions/send_rep_test.xml
2021-04-11T15:58:25.285Z,1618156705.285 [MissionManager](INFO): DefineArg esp_sample_at_depth.SendRepeat = 1.000000 count
2021-04-11T15:58:25.288Z,1618156705.288 [MissionManager](INFO): DefineOutput esp_sample_at_depth.CntSamples = 1.000000 count
2021-04-11T15:58:25.407Z,1618156705.407 [esp_sample_at_depth:SendRep:C.Wait](DEBUG): Construct Wait.
2021-04-11T15:58:25.421Z,1618156705.421 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Control="Tethys/Control"
         xmlns:Sample="Tethys/Sample"
         xmlns:Science="Tethys/Science"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                             Tethys/Sample http://okeanids.mbari.org/tethys/Xml/Sample.xsd
                             Tethys/Science http://okeanids.mbari.org/tethys/Xml/Science.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="esp_sample_at_depth">

    <Description>
        This mission takes ESP samples at the designated depth.
    </Description>

    <DefineArg Name="SendRepeat"><Units:count/><Value>1</Value></DefineArg>

    <DefineOutput Name="CntSamples"><Description>
        Count of water samples (initilized to 1).
    </Description><Units:count/><Value>1</Value></DefineOutput>


<!-- Callable aggregate -->

    <Aggregate Id="SendDataTo1Modem">

        <When>
            <Called/>
        </When>

        <Aggregate Id="SendDataToModem">

            <Sequence/>

            <Aggregate Id="SendDataCntSamples">

                <Sequence/>

                <Syslog Severity="Important"> CntSamples = <Arg Name="CntSamples"/><Units:count/></Syslog>

                <SendData Service="Direct" Destination="modem:6:_.LRAUVcntSamples">
                    <Arg Name="CntSamples"/>
                </SendData>

            </Aggregate>

            <Aggregate Id="SendDataESPSampleNumber">

                <Sequence/>

                <Break>
                    <IsNaN><Science:ESPComponent.sample_number/></IsNaN>
                </Break>

                <Syslog Severity="Important"> ESPComponent.sample_number = <Science:ESPComponent.sample_number/><Units:count/></Syslog>

                <SendData Service="Direct" Destination="modem:6:_.ESPsampleNumber">
                    <Science:ESPComponent.sample_number/><Units:count/>
                </SendData>

            </Aggregate>

            <Aggregate Id="SendDataESPCartridgeType">

                <Sequence/>

                <Break>
                    <IsNaN><Science:ESPComponent.cartridge/></IsNaN>
                </Break>

                <Syslog Severity="Important"> ESPComponent.cartridge = <Science:ESPComponent.cartridge/><Units:count/></Syslog>

                <SendData Service="Direct" Destination="modem:6:_.ESPcartridgeType">
                    <Science:ESPComponent.cartridge/><Units:count/>
                </SendData>

            </Aggregate>

            <Aggregate Id="SendDataESPSampleVolume">

                <Sequence/>

                <Break>
                    <IsNaN><Science:ESPComponent.sampleVolume/></IsNaN>
                </Break>

                <Syslog Severity="Important">Science:ESPComponent.sampleVolume = <Science:ESPComponent.sampleVolume/><Units:milliliter/></Syslog>

                <SendData Service="Direct" Destination="modem:6:_.ESPsampleVolume">
                    <Science:ESPComponent.sampleVolume/><Units:milliliter/>
                </SendData>

            </Aggregate>

            <Aggregate Id="SendDataSampleDepth">

                <Sequence/>

                <Break>
                    <IsNaN><Universal:depth/></IsNaN>
                </Break>

                <Syslog Severity="Important">Universal:depth = <Universal:depth/><Units:meter/></Syslog>

                <SendData Service="Direct" Destination="modem:6:_.sampleDepth">
                    <Universal:depth/><Units:meter/>
                </SendData>

            </Aggregate>

            <Aggregate Id="SendDataSampleTemp">

                <Sequence/>

                <Break>
                    <IsNaN><Universal:sea_water_temperature/></IsNaN>
                </Break>

                <Syslog Severity="Important">Universal:sea_water_temperature = <Universal:sea_water_temperature/><Units:celsius/></Syslog>

                <SendData Service="Direct" Destination="modem:6:_.sampleTemperature">
                    <Universal:sea_water_temperature/><Units:celsius/>
                </SendData>

            </Aggregate>

            <Aggregate Id="SendDataSampleChl">

                <Sequence/>

                <Break>
                    <IsNaN><Universal:mass_concentration_of_chlorophyll_in_sea_water/></IsNaN>
                </Break>

                <Syslog Severity="Important">Universal:mass_concentration_of_chlorophyll_in_sea_water = <Universal:mass_concentration_of_chlorophyll_in_sea_water/><Units:microgram_per_liter/></Syslog>

                <SendData Service="Direct" Destination="modem:6:_.sampleChlorophyll">
                    <Universal:mass_concentration_of_chlorophyll_in_sea_water/><Units:microgram_per_liter/>
                </SendData>

            </Aggregate>

        </Aggregate>

    </Aggregate>


<!-- Start mission sequence -->

    <Aggregate Id="SendRep">

        <Sequence Repeat="SendRepeat"/>

      
        <Call Id="ReportSample" RefId="SendDataTo1Modem"/>

        <Assign><Sequence/><Arg Name="CntSamples"/><Arg Name="CntSamples"/><Add><Units:count/><Value>1</Value></Add></Assign>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:second/><Value>10</Value></Setting>
        </Guidance:Wait>

    </Aggregate>

</Mission>


2021-04-11T15:58:25.423Z,1618156705.423 [CommandLine](IMPORTANT): Running ./Missions/send_rep_test.xml
2021-04-11T15:58:25.542Z,1618156705.542 [Default] Stopped
2021-04-11T15:58:25.542Z,1618156705.542 [Default](DEBUG): Aggregate::uninitialize Default
2021-04-11T15:58:25.543Z,1618156705.543 [Default:B.GoToSurface] Stopped
2021-04-11T15:58:25.543Z,1618156705.543 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-04-11T15:58:25.543Z,1618156705.543 [Default:CheckIn] Stopped
2021-04-11T15:58:25.543Z,1618156705.543 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-11T15:58:25.543Z,1618156705.543 [Default:CheckIn:Read_GPS] Stopped
2021-04-11T15:58:25.543Z,1618156705.543 [MissionManager](IMPORTANT): Started mission esp_sample_at_depth
2021-04-11T15:58:25.543Z,1618156705.543 [esp_sample_at_depth] Running Loop=1
2021-04-11T15:58:25.543Z,1618156705.543 [esp_sample_at_depth](DEBUG): Aggregate::initialize esp_sample_at_depth
2021-04-11T15:58:25.543Z,1618156705.543 [esp_sample_at_depth:SendRep] Running Loop=1
2021-04-11T15:58:25.544Z,1618156705.544 [esp_sample_at_depth:SendRep](DEBUG): Aggregate::initialize esp_sample_at_depth:SendRep
2021-04-11T15:58:25.544Z,1618156705.544 [esp_sample_at_depth:SendRep:ReportSample] Running Loop=1
2021-04-11T15:58:25.544Z,1618156705.544 [esp_sample_at_depth:SendRep:ReportSample](DEBUG): Aggregate::initialize esp_sample_at_depth:SendRep:ReportSample
2021-04-11T15:58:25.544Z,1618156705.544 [esp_sample_at_depth:SendDataTo1Modem] Running Loop=1
2021-04-11T15:58:25.544Z,1618156705.544 [esp_sample_at_depth:SendDataTo1Modem](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem
2021-04-11T15:58:25.544Z,1618156705.544 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem] Running Loop=1
2021-04-11T15:58:25.544Z,1618156705.544 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem
2021-04-11T15:58:25.544Z,1618156705.544 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples] Running Loop=1
2021-04-11T15:58:25.545Z,1618156705.545 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples
2021-04-11T15:58:25.545Z,1618156705.545 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:A] Running Loop=1
2021-04-11T15:58:25.545Z,1618156705.545 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:A](IMPORTANT): CntSamples = 1.000000 count 
2021-04-11T15:58:25.546Z,1618156705.546 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:A] Stopped
2021-04-11T15:58:25.546Z,1618156705.546 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:B] Running Loop=1
2021-04-11T15:58:25.934Z,1618156705.934 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:B](INFO): Queuing up send data for esp_sample_at_depth.CntSamples.
2021-04-11T15:58:25.934Z,1618156705.934 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:B] Stopped
2021-04-11T15:58:25.935Z,1618156705.935 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples](INFO): Completed esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples
2021-04-11T15:58:25.935Z,1618156705.935 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples] Stopped
2021-04-11T15:58:25.935Z,1618156705.935 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples
2021-04-11T15:58:25.935Z,1618156705.935 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber] Running Loop=1
2021-04-11T15:58:25.935Z,1618156705.935 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber
2021-04-11T15:58:25.935Z,1618156705.935 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber:A] Running Loop=1
2021-04-11T15:58:26.293Z,1618156706.293 [DAT](INFO): modem://6: set _.LRAUVcntSamples 1.000000 count
2021-04-11T15:58:26.295Z,1618156706.295 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-04-11T15:58:26.303Z,1618156706.303 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber] Stopped
2021-04-11T15:58:26.303Z,1618156706.303 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber
2021-04-11T15:58:26.303Z,1618156706.303 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber:A] Stopped
2021-04-11T15:58:26.303Z,1618156706.303 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType] Running Loop=1
2021-04-11T15:58:26.304Z,1618156706.304 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType
2021-04-11T15:58:26.304Z,1618156706.304 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType:A] Running Loop=1
2021-04-11T15:58:26.696Z,1618156706.696 [DAT](INFO): entering command mode
2021-04-11T15:58:26.705Z,1618156706.705 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType] Stopped
2021-04-11T15:58:26.705Z,1618156706.705 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType
2021-04-11T15:58:26.705Z,1618156706.705 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType:A] Stopped
2021-04-11T15:58:26.705Z,1618156706.705 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume] Running Loop=1
2021-04-11T15:58:26.706Z,1618156706.706 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume
2021-04-11T15:58:26.706Z,1618156706.706 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume:A] Running Loop=1
2021-04-11T15:58:27.103Z,1618156707.103 [DAT](INFO): commRate: 800
2021-04-11T15:58:27.111Z,1618156707.111 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume:A](ERROR): data element is not active.
2021-04-11T15:58:27.111Z,1618156707.111 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume:A](IMPORTANT): Science:ESPComponent.sampleVolume = nan ml 
2021-04-11T15:58:27.111Z,1618156707.111 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume:A] Stopped
2021-04-11T15:58:27.112Z,1618156707.112 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume:B] Running Loop=1
2021-04-11T15:58:27.528Z,1618156707.528 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume:B](INFO): Queuing up send data for ESPComponent.sampleVolume.
2021-04-11T15:58:27.528Z,1618156707.528 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume:B] Stopped
2021-04-11T15:58:27.528Z,1618156707.528 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume](INFO): Completed esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume
2021-04-11T15:58:27.528Z,1618156707.528 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume] Stopped
2021-04-11T15:58:27.528Z,1618156707.528 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume
2021-04-11T15:58:27.528Z,1618156707.528 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth] Running Loop=1
2021-04-11T15:58:27.528Z,1618156707.528 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth
2021-04-11T15:58:27.529Z,1618156707.529 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth:A] Running Loop=1
2021-04-11T15:58:27.912Z,1618156707.912 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth:A](IMPORTANT): Universal:depth = 0.247755 m 
2021-04-11T15:58:27.912Z,1618156707.912 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth:A] Stopped
2021-04-11T15:58:27.913Z,1618156707.913 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth:B] Running Loop=1
2021-04-11T15:58:28.319Z,1618156708.319 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth:B](INFO): Queuing up send data for depth.
2021-04-11T15:58:28.319Z,1618156708.319 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth:B] Stopped
2021-04-11T15:58:28.320Z,1618156708.320 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth](INFO): Completed esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth
2021-04-11T15:58:28.320Z,1618156708.320 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth] Stopped
2021-04-11T15:58:28.320Z,1618156708.320 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth
2021-04-11T15:58:28.320Z,1618156708.320 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp] Running Loop=1
2021-04-11T15:58:28.320Z,1618156708.320 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp
2021-04-11T15:58:28.320Z,1618156708.320 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp:A] Running Loop=1
2021-04-11T15:58:28.700Z,1618156708.700 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp:A](ERROR): data element is not active.
2021-04-11T15:58:28.700Z,1618156708.700 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp:A](IMPORTANT): Universal:sea_water_temperature = nan degC 
2021-04-11T15:58:28.700Z,1618156708.700 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp:A] Stopped
2021-04-11T15:58:28.700Z,1618156708.700 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp:B] Running Loop=1
2021-04-11T15:58:29.100Z,1618156709.100 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp:B](ERROR): Failed to send data. sea_water_temperature has no value.
2021-04-11T15:58:29.100Z,1618156709.100 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp:B] Stopped
2021-04-11T15:58:29.100Z,1618156709.100 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp](INFO): Completed esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp
2021-04-11T15:58:29.100Z,1618156709.100 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp] Stopped
2021-04-11T15:58:29.100Z,1618156709.100 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp
2021-04-11T15:58:29.100Z,1618156709.100 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl] Running Loop=1
2021-04-11T15:58:29.100Z,1618156709.100 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl
2021-04-11T15:58:29.100Z,1618156709.100 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl:A] Running Loop=1
2021-04-11T15:58:29.496Z,1618156709.496 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:29.514Z,1618156709.514 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl:A](ERROR): data element is not active.
2021-04-11T15:58:29.514Z,1618156709.514 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl:A](IMPORTANT): Universal:mass_concentration_of_chlorophyll_in_sea_water = nan ug/l 
2021-04-11T15:58:29.514Z,1618156709.514 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl:A] Stopped
2021-04-11T15:58:29.515Z,1618156709.515 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl:B] Running Loop=1
2021-04-11T15:58:29.904Z,1618156709.904 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:29.936Z,1618156709.936 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl:B](ERROR): Failed to send data. mass_concentration_of_chlorophyll_in_sea_water has no value.
2021-04-11T15:58:29.936Z,1618156709.936 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl:B] Stopped
2021-04-11T15:58:29.936Z,1618156709.936 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl](INFO): Completed esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl
2021-04-11T15:58:29.936Z,1618156709.936 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl] Stopped
2021-04-11T15:58:29.936Z,1618156709.936 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl
2021-04-11T15:58:29.936Z,1618156709.936 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem](INFO): Completed esp_sample_at_depth:SendDataTo1Modem:SendDataToModem
2021-04-11T15:58:29.936Z,1618156709.936 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem] Stopped
2021-04-11T15:58:29.936Z,1618156709.936 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem
2021-04-11T15:58:29.937Z,1618156709.937 [esp_sample_at_depth:SendDataTo1Modem](INFO): Completed esp_sample_at_depth:SendDataTo1Modem
2021-04-11T15:58:29.937Z,1618156709.937 [esp_sample_at_depth:SendDataTo1Modem] Stopped
2021-04-11T15:58:29.937Z,1618156709.937 [esp_sample_at_depth:SendDataTo1Modem](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem
2021-04-11T15:58:30.313Z,1618156710.313 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:30.320Z,1618156710.320 [esp_sample_at_depth:SendRep:ReportSample](INFO): Completed esp_sample_at_depth:SendRep:ReportSample
2021-04-11T15:58:30.320Z,1618156710.320 [esp_sample_at_depth:SendRep:ReportSample] Stopped
2021-04-11T15:58:30.321Z,1618156710.321 [esp_sample_at_depth:SendRep:ReportSample](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendRep:ReportSample
2021-04-11T15:58:30.337Z,1618156710.337 [esp_sample_at_depth:SendRep:B] Running Loop=1
2021-04-11T15:58:30.704Z,1618156710.704 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:30.712Z,1618156710.712 [esp_sample_at_depth:SendRep:B] Stopped
2021-04-11T15:58:30.712Z,1618156710.712 [esp_sample_at_depth:SendRep:C.Wait] Running Loop=1
2021-04-11T15:58:30.713Z,1618156710.713 [esp_sample_at_depth:SendRep:C.Wait](DEBUG): Initialize Wait Component.
2021-04-11T15:58:31.118Z,1618156711.118 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:31.520Z,1618156711.520 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:31.916Z,1618156711.916 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:32.342Z,1618156712.342 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:32.754Z,1618156712.754 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:33.132Z,1618156713.132 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:33.540Z,1618156713.540 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:33.940Z,1618156713.940 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:34.358Z,1618156714.358 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:34.766Z,1618156714.766 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:35.165Z,1618156715.165 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:35.556Z,1618156715.556 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:35.966Z,1618156715.966 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:36.368Z,1618156716.368 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:36.772Z,1618156716.772 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:37.176Z,1618156717.176 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:37.601Z,1618156717.601 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:38.062Z,1618156718.062 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-04-11T15:58:38.070Z,1618156718.070 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:38.396Z,1618156718.396 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:38.800Z,1618156718.800 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:39.188Z,1618156719.188 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:39.596Z,1618156719.596 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:39.999Z,1618156719.999 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:40.533Z,1618156720.533 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:40.828Z,1618156720.828 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:41.232Z,1618156721.232 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:41.240Z,1618156721.240 [esp_sample_at_depth:SendRep:C.Wait](INFO): Done Waiting.
2021-04-11T15:58:41.240Z,1618156721.240 [esp_sample_at_depth:SendRep:C.Wait] Stopped
2021-04-11T15:58:41.240Z,1618156721.240 [esp_sample_at_depth:SendRep:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-11T15:58:41.240Z,1618156721.240 [esp_sample_at_depth:SendRep](INFO): Completed esp_sample_at_depth:SendRep
2021-04-11T15:58:41.240Z,1618156721.240 [esp_sample_at_depth:SendRep] Stopped
2021-04-11T15:58:41.240Z,1618156721.240 [esp_sample_at_depth:SendRep](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendRep
2021-04-11T15:58:41.240Z,1618156721.240 [esp_sample_at_depth](INFO): Completed esp_sample_at_depth
2021-04-11T15:58:41.241Z,1618156721.241 [MissionManager](INFO): esp_sample_at_depth is completed.
2021-04-11T15:58:41.241Z,1618156721.241 [MissionManager](INFO): Uninitializing Mission esp_sample_at_depth
2021-04-11T15:58:41.241Z,1618156721.241 [esp_sample_at_depth] Stopped
2021-04-11T15:58:41.241Z,1618156721.241 [esp_sample_at_depth](DEBUG): Aggregate::uninitialize esp_sample_at_depth
2021-04-11T15:58:41.632Z,1618156721.632 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:41.639Z,1618156721.639 [MissionManager](IMPORTANT): Started mission Default
2021-04-11T15:58:41.639Z,1618156721.639 [Default] Running Loop=1
2021-04-11T15:58:41.640Z,1618156721.640 [Default](DEBUG): Aggregate::initialize Default
2021-04-11T15:58:41.640Z,1618156721.640 [Default:B.GoToSurface] Running Loop=1
2021-04-11T15:58:41.640Z,1618156721.640 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-04-11T15:58:41.640Z,1618156721.640 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-04-11T15:58:41.640Z,1618156721.640 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-04-11T15:58:41.641Z,1618156721.641 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-04-11T15:58:41.641Z,1618156721.641 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-04-11T15:58:41.641Z,1618156721.641 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-04-11T15:58:41.642Z,1618156721.642 [Default:A.Wait] Running Loop=1
2021-04-11T15:58:41.642Z,1618156721.642 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-04-11T15:58:42.025Z,1618156722.025 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-11T15:58:42.026Z,1618156722.026 [DAT](FAULT): failed to enter command mode
2021-04-11T15:58:42.026Z,1618156722.026 [DAT](ERROR): Failure setting remote address to 6
2021-04-11T15:58:42.420Z,1618156722.420 [DAT](INFO): entering command mode
2021-04-11T15:58:42.843Z,1618156722.843 [DAT](INFO): setting remote address to 6
2021-04-11T15:58:43.247Z,1618156723.247 [DAT](INFO): set remote address to 6
2021-04-11T15:58:43.247Z,1618156723.247 [DAT](INFO): entering online mode
2021-04-11T15:58:43.655Z,1618156723.655 [DAT](INFO): commRate: 800
2021-04-11T15:58:43.655Z,1618156723.655 [DAT](INFO): online mode acknowledged
2021-04-11T15:58:43.656Z,1618156723.656 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-04-11T15:58:46.899Z,1618156726.899 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-04-11T15:58:53.752Z,1618156733.752 [DAT](FAULT): Ack receipt timeout failure.
2021-04-11T15:58:53.752Z,1618156733.752 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2021-04-11T15:58:54.145Z,1618156734.145 [DAT](INFO): modem://6: set _.ESPsampleVolume nan milliliter
2021-04-11T15:58:54.145Z,1618156734.145 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-04-11T15:58:54.544Z,1618156734.544 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-04-11T15:58:55.019Z,1618156735.019 [Default:A.Wait](INFO): Done Waiting.
2021-04-11T15:58:55.020Z,1618156735.020 [Default:A.Wait] Stopped
2021-04-11T15:58:55.020Z,1618156735.020 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-04-11T15:58:55.363Z,1618156735.363 [Default:CheckIn] Running Loop=1
2021-04-11T15:58:55.363Z,1618156735.363 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-11T15:58:55.363Z,1618156735.363 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-11T15:58:57.782Z,1618156737.782 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-04-11T15:59:04.666Z,1618156744.666 [DAT](FAULT): Ack receipt timeout failure.
2021-04-11T15:59:04.666Z,1618156744.666 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2021-04-11T15:59:05.069Z,1618156745.069 [DAT](INFO): modem://6: set _.sampleDepth 0.256399 meter
2021-04-11T15:59:05.069Z,1618156745.069 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-04-11T15:59:05.452Z,1618156745.452 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-04-11T15:59:06.716Z,1618156746.716 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-04-11T15:59:08.689Z,1618156748.689 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-04-11T15:59:13.943Z,1618156753.943 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-04-11T15:59:15.548Z,1618156755.548 [DAT](FAULT): Ack receipt timeout failure.
2021-04-11T15:59:15.548Z,1618156755.548 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2021-04-11T15:59:15.985Z,1618156755.985 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-04-11T15:59:16.356Z,1618156756.356 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-04-11T15:59:19.593Z,1618156759.593 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-04-11T15:59:26.470Z,1618156766.470 [DAT](FAULT): Ack receipt timeout failure.
2021-04-11T15:59:26.470Z,1618156766.470 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2021-04-11T15:59:26.864Z,1618156766.864 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2021-04-11T15:59:27.269Z,1618156767.269 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-04-11T15:59:27.678Z,1618156767.678 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-04-11T15:59:29.706Z,1618156769.706 [DAT](INFO): unknown deviceResponse_: WARNING: Modem reset during xmit; lowering xmit power level by 3 dB.

2021-04-11T15:59:30.097Z,1618156770.097 [DAT](INFO): unknown deviceResponse_: WARNING: Reduced xmit power level to 7 due to weak battery.

2021-04-11T15:59:30.099Z,1618156770.099 [DAT](INFO): commRate: 800
2021-04-11T15:59:31.738Z,1618156771.738 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-04-11T15:59:32.554Z,1618156772.554 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2021-04-11T15:59:32.555Z,1618156772.555 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-11T15:59:32.591Z,1618156772.591 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-11T15:59:32.953Z,1618156772.953 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-11T15:59:32.953Z,1618156772.953 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2021-04-11T15:59:37.786Z,1618156777.786 [DAT](FAULT): Ack receipt timeout failure.
2021-04-11T15:59:37.786Z,1618156777.786 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2021-04-11T15:59:38.186Z,1618156778.186 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2021-04-11T15:59:38.650Z,1618156778.650 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-04-11T15:59:39.022Z,1618156779.022 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-04-11T15:59:42.617Z,1618156782.617 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-04-11T15:59:49.096Z,1618156789.096 [DAT](FAULT): Ack receipt timeout failure.
2021-04-11T15:59:49.096Z,1618156789.096 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2021-04-11T15:59:49.487Z,1618156789.487 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2021-04-11T15:59:52.771Z,1618156792.771 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-04-11T16:00:19.529Z,1618156819.529 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2021-04-11T16:00:19.530Z,1618156819.530 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+0.0,1489.0,000
2021-04-11T16:00:20.242Z,1618156820.242 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-04-11T16:00:32.768Z,1618156832.768 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-04-11T16:00:41.266Z,1618156841.266 [CommandLine](IMPORTANT): got command configSet CTD_Seabird.loadAtStartup 0.000000 bool
2021-04-11T16:00:41.267Z,1618156841.267 [CommandLine](FAULT): configSet CTD_Seabird.loadAtStartup without persist will have no effect.
2021-04-11T16:00:48.117Z,1618156848.117 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-04-11T16:00:54.690Z,1618156854.690 [CommandLine](IMPORTANT): got command run ./Missions/send_rep_test.xml
2021-04-11T16:00:54.690Z,1618156854.690 [MissionManager](INFO): Loading Mission: ./Missions/send_rep_test.xml
2021-04-11T16:00:54.761Z,1618156854.761 [MissionManager](INFO): DefineArg esp_sample_at_depth.SendRepeat = 1.000000 count
2021-04-11T16:00:54.764Z,1618156854.764 [MissionManager](INFO): DefineOutput esp_sample_at_depth.CntSamples = 1.000000 count
2021-04-11T16:00:54.796Z,1618156854.796 [esp_sample_at_depth:SendRep:C.Wait](DEBUG): Construct Wait.
2021-04-11T16:00:54.828Z,1618156854.828 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Control="Tethys/Control"
         xmlns:Sample="Tethys/Sample"
         xmlns:Science="Tethys/Science"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                             Tethys/Sample http://okeanids.mbari.org/tethys/Xml/Sample.xsd
                             Tethys/Science http://okeanids.mbari.org/tethys/Xml/Science.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="esp_sample_at_depth">

    <Description>
        This mission takes ESP samples at the designated depth.
    </Description>

    <DefineArg Name="SendRepeat"><Units:count/><Value>1</Value></DefineArg>

    <DefineOutput Name="CntSamples"><Description>
        Count of water samples (initilized to 1).
    </Description><Units:count/><Value>1</Value></DefineOutput>


<!-- Callable aggregate -->

    <Aggregate Id="SendDataTo1Modem">

        <When>
            <Called/>
        </When>

        <Aggregate Id="SendDataToModem">

            <Sequence/>

            <Aggregate Id="SendDataCntSamples">

                <Sequence/>

                <Syslog Severity="Important"> CntSamples = <Arg Name="CntSamples"/><Units:count/></Syslog>

                <SendData Service="Direct" Destination="modem:6:_.LRAUVcntSamples">
                    <Arg Name="CntSamples"/>
                </SendData>

            </Aggregate>

            <Aggregate Id="SendDataESPSampleNumber">

                <Sequence/>

                <Break>
                    <IsNaN><Science:ESPComponent.sample_number/></IsNaN>
                </Break>

                <Syslog Severity="Important"> ESPComponent.sample_number = <Science:ESPComponent.sample_number/><Units:count/></Syslog>

                <SendData Service="Direct" Destination="modem:6:_.ESPsampleNumber">
                    <Science:ESPComponent.sample_number/><Units:count/>
                </SendData>

            </Aggregate>

            <Aggregate Id="SendDataESPCartridgeType">

                <Sequence/>

                <Break>
                    <IsNaN><Science:ESPComponent.cartridge/></IsNaN>
                </Break>

                <Syslog Severity="Important"> ESPComponent.cartridge = <Science:ESPComponent.cartridge/><Units:count/></Syslog>

                <SendData Service="Direct" Destination="modem:6:_.ESPcartridgeType">
                    <Science:ESPComponent.cartridge/><Units:count/>
                </SendData>

            </Aggregate>

            <Aggregate Id="SendDataESPSampleVolume">

                <Sequence/>

                <Break>
                    <IsNaN><Science:ESPComponent.sampleVolume/></IsNaN>
                </Break>

                <Syslog Severity="Important">Science:ESPComponent.sampleVolume = <Science:ESPComponent.sampleVolume/><Units:milliliter/></Syslog>

                <SendData Service="Direct" Destination="modem:6:_.ESPsampleVolume">
                    <Science:ESPComponent.sampleVolume/><Units:milliliter/>
                </SendData>

            </Aggregate>

            <Aggregate Id="SendDataSampleDepth">

                <Sequence/>

                <Break>
                    <IsNaN><Universal:depth/></IsNaN>
                </Break>

                <Syslog Severity="Important">Universal:depth = <Universal:depth/><Units:meter/></Syslog>

                <SendData Service="Direct" Destination="modem:6:_.sampleDepth">
                    <Universal:depth/><Units:meter/>
                </SendData>

            </Aggregate>

            <Aggregate Id="SendDataSampleTemp">

                <Sequence/>

                <Break>
                    <IsNaN><Universal:sea_water_temperature/></IsNaN>
                </Break>

                <Syslog Severity="Important">Universal:sea_water_temperature = <Universal:sea_water_temperature/><Units:celsius/></Syslog>

                <SendData Service="Direct" Destination="modem:6:_.sampleTemperature">
                    <Universal:sea_water_temperature/><Units:celsius/>
                </SendData>

            </Aggregate>

            <Aggregate Id="SendDataSampleChl">

                <Sequence/>

                <Break>
                    <IsNaN><Universal:mass_concentration_of_chlorophyll_in_sea_water/></IsNaN>
                </Break>

                <Syslog Severity="Important">Universal:mass_concentration_of_chlorophyll_in_sea_water = <Universal:mass_concentration_of_chlorophyll_in_sea_water/><Units:microgram_per_liter/></Syslog>

                <SendData Service="Direct" Destination="modem:6:_.sampleChlorophyll">
                    <Universal:mass_concentration_of_chlorophyll_in_sea_water/><Units:microgram_per_liter/>
                </SendData>

            </Aggregate>

        </Aggregate>

    </Aggregate>


<!-- Start mission sequence -->

    <Aggregate Id="SendRep">

        <Sequence Repeat="SendRepeat"/>

      
        <Call Id="ReportSample" RefId="SendDataTo1Modem"/>

        <Assign><Sequence/><Arg Name="CntSamples"/><Arg Name="CntSamples"/><Add><Units:count/><Value>1</Value></Add></Assign>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:second/><Value>10</Value></Setting>
        </Guidance:Wait>

    </Aggregate>

</Mission>


2021-04-11T16:00:54.830Z,1618156854.830 [CommandLine](IMPORTANT): Running ./Missions/send_rep_test.xml
2021-04-11T16:00:54.947Z,1618156854.947 [Default] Stopped
2021-04-11T16:00:54.947Z,1618156854.947 [Default](DEBUG): Aggregate::uninitialize Default
2021-04-11T16:00:54.948Z,1618156854.948 [Default:B.GoToSurface] Stopped
2021-04-11T16:00:54.948Z,1618156854.948 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-04-11T16:00:54.948Z,1618156854.948 [Default:CheckIn] Stopped
2021-04-11T16:00:54.948Z,1618156854.948 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-11T16:00:54.948Z,1618156854.948 [Default:CheckIn:Read_GPS] Stopped
2021-04-11T16:00:54.948Z,1618156854.948 [MissionManager](IMPORTANT): Started mission esp_sample_at_depth
2021-04-11T16:00:54.948Z,1618156854.948 [esp_sample_at_depth] Running Loop=1
2021-04-11T16:00:54.948Z,1618156854.948 [esp_sample_at_depth](DEBUG): Aggregate::initialize esp_sample_at_depth
2021-04-11T16:00:54.949Z,1618156854.949 [esp_sample_at_depth:SendRep] Running Loop=1
2021-04-11T16:00:54.949Z,1618156854.949 [esp_sample_at_depth:SendRep](DEBUG): Aggregate::initialize esp_sample_at_depth:SendRep
2021-04-11T16:00:54.949Z,1618156854.949 [esp_sample_at_depth:SendRep:ReportSample] Running Loop=1
2021-04-11T16:00:54.949Z,1618156854.949 [esp_sample_at_depth:SendRep:ReportSample](DEBUG): Aggregate::initialize esp_sample_at_depth:SendRep:ReportSample
2021-04-11T16:00:54.949Z,1618156854.949 [esp_sample_at_depth:SendDataTo1Modem] Running Loop=1
2021-04-11T16:00:54.949Z,1618156854.949 [esp_sample_at_depth:SendDataTo1Modem](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem
2021-04-11T16:00:54.950Z,1618156854.950 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem] Running Loop=1
2021-04-11T16:00:54.950Z,1618156854.950 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem
2021-04-11T16:00:54.950Z,1618156854.950 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples] Running Loop=1
2021-04-11T16:00:54.950Z,1618156854.950 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples
2021-04-11T16:00:54.950Z,1618156854.950 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:A] Running Loop=1
2021-04-11T16:00:54.951Z,1618156854.951 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:A](IMPORTANT): CntSamples = 1.000000 count 
2021-04-11T16:00:54.951Z,1618156854.951 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:A] Stopped
2021-04-11T16:00:54.951Z,1618156854.951 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:B] Running Loop=1
2021-04-11T16:00:55.357Z,1618156855.357 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:B](INFO): Queuing up send data for esp_sample_at_depth.CntSamples.
2021-04-11T16:00:55.357Z,1618156855.357 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:B] Stopped
2021-04-11T16:00:55.357Z,1618156855.357 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples](INFO): Completed esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples
2021-04-11T16:00:55.357Z,1618156855.357 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples] Stopped
2021-04-11T16:00:55.357Z,1618156855.357 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples
2021-04-11T16:00:55.358Z,1618156855.358 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber] Running Loop=1
2021-04-11T16:00:55.358Z,1618156855.358 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber
2021-04-11T16:00:55.358Z,1618156855.358 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber:A] Running Loop=1
2021-04-11T16:00:55.762Z,1618156855.762 [DAT](INFO): modem://6: set _.LRAUVcntSamples 1.000000 count
2021-04-11T16:00:55.763Z,1618156855.763 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-04-11T16:00:55.779Z,1618156855.779 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber] Stopped
2021-04-11T16:00:55.779Z,1618156855.779 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber
2021-04-11T16:00:55.779Z,1618156855.779 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber:A] Stopped
2021-04-11T16:00:55.779Z,1618156855.779 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType] Running Loop=1
2021-04-11T16:00:55.779Z,1618156855.779 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType
2021-04-11T16:00:55.779Z,1618156855.779 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType:A] Running Loop=1
2021-04-11T16:00:56.164Z,1618156856.164 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-04-11T16:00:56.199Z,1618156856.199 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType] Stopped
2021-04-11T16:00:56.199Z,1618156856.199 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType
2021-04-11T16:00:56.200Z,1618156856.200 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType:A] Stopped
2021-04-11T16:00:56.200Z,1618156856.200 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume] Running Loop=1
2021-04-11T16:00:56.200Z,1618156856.200 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume
2021-04-11T16:00:56.200Z,1618156856.200 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume:A] Running Loop=1
2021-04-11T16:00:56.588Z,1618156856.588 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume:A](ERROR): data element is not active.
2021-04-11T16:00:56.588Z,1618156856.588 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume:A](IMPORTANT): Science:ESPComponent.sampleVolume = nan ml 
2021-04-11T16:00:56.588Z,1618156856.588 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume:A] Stopped
2021-04-11T16:00:56.588Z,1618156856.588 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume:B] Running Loop=1
2021-04-11T16:00:56.988Z,1618156856.988 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume:B](INFO): Queuing up send data for ESPComponent.sampleVolume.
2021-04-11T16:00:56.988Z,1618156856.988 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume:B] Stopped
2021-04-11T16:00:56.988Z,1618156856.988 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume](INFO): Completed esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume
2021-04-11T16:00:56.988Z,1618156856.988 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume] Stopped
2021-04-11T16:00:56.988Z,1618156856.988 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume
2021-04-11T16:00:56.988Z,1618156856.988 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth] Running Loop=1
2021-04-11T16:00:56.988Z,1618156856.988 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth
2021-04-11T16:00:56.989Z,1618156856.989 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth:A] Running Loop=1
2021-04-11T16:00:57.373Z,1618156857.373 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth:A](IMPORTANT): Universal:depth = 0.272822 m 
2021-04-11T16:00:57.373Z,1618156857.373 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth:A] Stopped
2021-04-11T16:00:57.373Z,1618156857.373 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth:B] Running Loop=1
2021-04-11T16:00:57.804Z,1618156857.804 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth:B](INFO): Queuing up send data for depth.
2021-04-11T16:00:57.804Z,1618156857.804 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth:B] Stopped
2021-04-11T16:00:57.804Z,1618156857.804 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth](INFO): Completed esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth
2021-04-11T16:00:57.804Z,1618156857.804 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth] Stopped
2021-04-11T16:00:57.804Z,1618156857.804 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth
2021-04-11T16:00:57.804Z,1618156857.804 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp] Running Loop=1
2021-04-11T16:00:57.804Z,1618156857.804 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp
2021-04-11T16:00:57.804Z,1618156857.804 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp:A] Running Loop=1
2021-04-11T16:00:58.180Z,1618156858.180 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp:A](ERROR): data element is not active.
2021-04-11T16:00:58.180Z,1618156858.180 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp:A](IMPORTANT): Universal:sea_water_temperature = nan degC 
2021-04-11T16:00:58.180Z,1618156858.180 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp:A] Stopped
2021-04-11T16:00:58.180Z,1618156858.180 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp:B] Running Loop=1
2021-04-11T16:00:58.596Z,1618156858.596 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp:B](ERROR): Failed to send data. sea_water_temperature has no value.
2021-04-11T16:00:58.596Z,1618156858.596 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp:B] Stopped
2021-04-11T16:00:58.596Z,1618156858.596 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp](INFO): Completed esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp
2021-04-11T16:00:58.596Z,1618156858.596 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp] Stopped
2021-04-11T16:00:58.596Z,1618156858.596 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp
2021-04-11T16:00:58.596Z,1618156858.596 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl] Running Loop=1
2021-04-11T16:00:58.596Z,1618156858.596 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl
2021-04-11T16:00:58.597Z,1618156858.597 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl:A] Running Loop=1
2021-04-11T16:00:59.008Z,1618156859.008 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl:A](ERROR): data element is not active.
2021-04-11T16:00:59.008Z,1618156859.008 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl:A](IMPORTANT): Universal:mass_concentration_of_chlorophyll_in_sea_water = nan ug/l 
2021-04-11T16:00:59.008Z,1618156859.008 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl:A] Stopped
2021-04-11T16:00:59.008Z,1618156859.008 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl:B] Running Loop=1
2021-04-11T16:00:59.394Z,1618156859.394 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-04-11T16:00:59.411Z,1618156859.411 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl:B](ERROR): Failed to send data. mass_concentration_of_chlorophyll_in_sea_water has no value.
2021-04-11T16:00:59.411Z,1618156859.411 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl:B] Stopped
2021-04-11T16:00:59.411Z,1618156859.411 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl](INFO): Completed esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl
2021-04-11T16:00:59.411Z,1618156859.411 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl] Stopped
2021-04-11T16:00:59.411Z,1618156859.411 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl
2021-04-11T16:00:59.412Z,1618156859.412 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem](INFO): Completed esp_sample_at_depth:SendDataTo1Modem:SendDataToModem
2021-04-11T16:00:59.412Z,1618156859.412 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem] Stopped
2021-04-11T16:00:59.412Z,1618156859.412 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem
2021-04-11T16:00:59.412Z,1618156859.412 [esp_sample_at_depth:SendDataTo1Modem](INFO): Completed esp_sample_at_depth:SendDataTo1Modem
2021-04-11T16:00:59.412Z,1618156859.412 [esp_sample_at_depth:SendDataTo1Modem] Stopped
2021-04-11T16:00:59.412Z,1618156859.412 [esp_sample_at_depth:SendDataTo1Modem](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem
2021-04-11T16:00:59.807Z,1618156859.807 [esp_sample_at_depth:SendRep:ReportSample](INFO): Completed esp_sample_at_depth:SendRep:ReportSample
2021-04-11T16:00:59.807Z,1618156859.807 [esp_sample_at_depth:SendRep:ReportSample] Stopped
2021-04-11T16:00:59.807Z,1618156859.807 [esp_sample_at_depth:SendRep:ReportSample](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendRep:ReportSample
2021-04-11T16:00:59.807Z,1618156859.807 [esp_sample_at_depth:SendRep:B] Running Loop=1
2021-04-11T16:01:00.210Z,1618156860.210 [esp_sample_at_depth:SendRep:B] Stopped
2021-04-11T16:01:00.211Z,1618156860.211 [esp_sample_at_depth:SendRep:C.Wait] Running Loop=1
2021-04-11T16:01:00.211Z,1618156860.211 [esp_sample_at_depth:SendRep:C.Wait](DEBUG): Initialize Wait Component.
2021-04-11T16:01:01.089Z,1618156861.089 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-04-11T16:01:01.896Z,1618156861.896 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-04-11T16:01:06.248Z,1618156866.248 [DAT](FAULT): Ack receipt timeout failure.
2021-04-11T16:01:06.248Z,1618156866.248 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2021-04-11T16:01:06.648Z,1618156866.648 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2021-04-11T16:01:07.058Z,1618156867.058 [DAT](INFO): modem://6: set _.ESPsampleVolume nan milliliter
2021-04-11T16:01:07.059Z,1618156867.059 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-04-11T16:01:07.464Z,1618156867.464 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-04-11T16:01:10.711Z,1618156870.711 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-04-11T16:01:10.731Z,1618156870.731 [esp_sample_at_depth:SendRep:C.Wait](INFO): Done Waiting.
2021-04-11T16:01:10.731Z,1618156870.731 [esp_sample_at_depth:SendRep:C.Wait] Stopped
2021-04-11T16:01:10.731Z,1618156870.731 [esp_sample_at_depth:SendRep:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-11T16:01:10.731Z,1618156870.731 [esp_sample_at_depth:SendRep](INFO): Completed esp_sample_at_depth:SendRep
2021-04-11T16:01:10.731Z,1618156870.731 [esp_sample_at_depth:SendRep] Stopped
2021-04-11T16:01:10.731Z,1618156870.731 [esp_sample_at_depth:SendRep](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendRep
2021-04-11T16:01:10.731Z,1618156870.731 [esp_sample_at_depth](INFO): Completed esp_sample_at_depth
2021-04-11T16:01:10.732Z,1618156870.732 [MissionManager](INFO): esp_sample_at_depth is completed.
2021-04-11T16:01:10.732Z,1618156870.732 [MissionManager](INFO): Uninitializing Mission esp_sample_at_depth
2021-04-11T16:01:10.732Z,1618156870.732 [esp_sample_at_depth] Stopped
2021-04-11T16:01:10.732Z,1618156870.732 [esp_sample_at_depth](DEBUG): Aggregate::uninitialize esp_sample_at_depth
2021-04-11T16:01:11.127Z,1618156871.127 [MissionManager](IMPORTANT): Started mission Default
2021-04-11T16:01:11.127Z,1618156871.127 [Default] Running Loop=1
2021-04-11T16:01:11.128Z,1618156871.128 [Default](DEBUG): Aggregate::initialize Default
2021-04-11T16:01:11.128Z,1618156871.128 [Default:B.GoToSurface] Running Loop=1
2021-04-11T16:01:11.128Z,1618156871.128 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-04-11T16:01:11.128Z,1618156871.128 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-04-11T16:01:11.128Z,1618156871.128 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-04-11T16:01:11.129Z,1618156871.129 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-04-11T16:01:11.165Z,1618156871.165 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-04-11T16:01:11.166Z,1618156871.166 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-04-11T16:01:11.166Z,1618156871.166 [Default:A.Wait] Running Loop=1
2021-04-11T16:01:11.166Z,1618156871.166 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-04-11T16:01:15.597Z,1618156875.597 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-04-11T16:01:17.564Z,1618156877.564 [DAT](FAULT): Ack receipt timeout failure.
2021-04-11T16:01:17.564Z,1618156877.564 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2021-04-11T16:01:17.973Z,1618156877.973 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2021-04-11T16:01:18.386Z,1618156878.386 [DAT](INFO): modem://6: set _.sampleDepth 0.268933 meter
2021-04-11T16:01:18.386Z,1618156878.386 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-04-11T16:01:18.786Z,1618156878.786 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-04-11T16:01:22.018Z,1618156882.018 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-04-11T16:01:24.440Z,1618156884.440 [Default:A.Wait](INFO): Done Waiting.
2021-04-11T16:01:24.440Z,1618156884.440 [Default:A.Wait] Stopped
2021-04-11T16:01:24.440Z,1618156884.440 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-04-11T16:01:24.856Z,1618156884.856 [Default:CheckIn] Running Loop=1
2021-04-11T16:01:24.856Z,1618156884.856 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-11T16:01:24.857Z,1618156884.857 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-11T16:01:28.872Z,1618156888.872 [DAT](FAULT): Ack receipt timeout failure.
2021-04-11T16:01:28.872Z,1618156888.872 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2021-04-11T16:01:29.276Z,1618156889.276 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2021-04-11T16:01:35.340Z,1618156895.340 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-04-11T16:02:27.538Z,1618156947.538 [CommandLine](IMPORTANT): got command run ./Missions/send_rep_test.xml
2021-04-11T16:02:27.539Z,1618156947.539 [MissionManager](INFO): Loading Mission: ./Missions/send_rep_test.xml
2021-04-11T16:02:27.599Z,1618156947.599 [MissionManager](INFO): DefineArg esp_sample_at_depth.SendRepeat = 2.000000 count
2021-04-11T16:02:27.601Z,1618156947.601 [MissionManager](INFO): DefineOutput esp_sample_at_depth.CntSamples = 1.000000 count
2021-04-11T16:02:27.652Z,1618156947.652 [esp_sample_at_depth:SendRep:C.Wait](DEBUG): Construct Wait.
2021-04-11T16:02:27.659Z,1618156947.659 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Control="Tethys/Control"
         xmlns:Sample="Tethys/Sample"
         xmlns:Science="Tethys/Science"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                             Tethys/Sample http://okeanids.mbari.org/tethys/Xml/Sample.xsd
                             Tethys/Science http://okeanids.mbari.org/tethys/Xml/Science.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="esp_sample_at_depth">

    <Description>
        This mission takes ESP samples at the designated depth.
    </Description>

    <DefineArg Name="SendRepeat"><Units:count/><Value>2</Value></DefineArg>

    <DefineOutput Name="CntSamples"><Description>
        Count of water samples (initilized to 1).
    </Description><Units:count/><Value>1</Value></DefineOutput>


<!-- Callable aggregate -->

    <Aggregate Id="SendDataTo1Modem">

        <When>
            <Called/>
        </When>

        <Aggregate Id="SendDataToModem">

            <Sequence/>

            <Aggregate Id="SendDataCntSamples">

                <Sequence/>

                <Syslog Severity="Important"> CntSamples = <Arg Name="CntSamples"/><Units:count/></Syslog>

                <SendData Service="Direct" Destination="modem:6:_.LRAUVcntSamples">
                    <Arg Name="CntSamples"/>
                </SendData>

            </Aggregate>

            <Aggregate Id="SendDataESPSampleNumber">

                <Sequence/>

                <Break>
                    <IsNaN><Science:ESPComponent.sample_number/></IsNaN>
                </Break>

                <Syslog Severity="Important"> ESPComponent.sample_number = <Science:ESPComponent.sample_number/><Units:count/></Syslog>

                <SendData Service="Direct" Destination="modem:6:_.ESPsampleNumber">
                    <Science:ESPComponent.sample_number/><Units:count/>
                </SendData>

            </Aggregate>

            <Aggregate Id="SendDataESPCartridgeType">

                <Sequence/>

                <Break>
                    <IsNaN><Science:ESPComponent.cartridge/></IsNaN>
                </Break>

                <Syslog Severity="Important"> ESPComponent.cartridge = <Science:ESPComponent.cartridge/><Units:count/></Syslog>

                <SendData Service="Direct" Destination="modem:6:_.ESPcartridgeType">
                    <Science:ESPComponent.cartridge/><Units:count/>
                </SendData>

            </Aggregate>

            <Aggregate Id="SendDataESPSampleVolume">

                <Sequence/>

                <Break>
                    <IsNaN><Science:ESPComponent.sampleVolume/></IsNaN>
                </Break>

                <Syslog Severity="Important">Science:ESPComponent.sampleVolume = <Science:ESPComponent.sampleVolume/><Units:milliliter/></Syslog>

                <SendData Service="Direct" Destination="modem:6:_.ESPsampleVolume">
                    <Science:ESPComponent.sampleVolume/><Units:milliliter/>
                </SendData>

            </Aggregate>

            <Aggregate Id="SendDataSampleDepth">

                <Sequence/>

                <Break>
                    <IsNaN><Universal:depth/></IsNaN>
                </Break>

                <Syslog Severity="Important">Universal:depth = <Universal:depth/><Units:meter/></Syslog>

                <SendData Service="Direct" Destination="modem:6:_.sampleDepth">
                    <Universal:depth/><Units:meter/>
                </SendData>

            </Aggregate>

            <Aggregate Id="SendDataSampleTemp">

                <Sequence/>

                <Break>
                    <IsNaN><Universal:sea_water_temperature/></IsNaN>
                </Break>

                <Syslog Severity="Important">Universal:sea_water_temperature = <Universal:sea_water_temperature/><Units:celsius/></Syslog>

                <SendData Service="Direct" Destination="modem:6:_.sampleTemperature">
                    <Universal:sea_water_temperature/><Units:celsius/>
                </SendData>

            </Aggregate>

            <Aggregate Id="SendDataSampleChl">

                <Sequence/>

                <Break>
                    <IsNaN><Universal:mass_concentration_of_chlorophyll_in_sea_water/></IsNaN>
                </Break>

                <Syslog Severity="Important">Universal:mass_concentration_of_chlorophyll_in_sea_water = <Universal:mass_concentration_of_chlorophyll_in_sea_water/><Units:microgram_per_liter/></Syslog>

                <SendData Service="Direct" Destination="modem:6:_.sampleChlorophyll">
                    <Universal:mass_concentration_of_chlorophyll_in_sea_water/><Units:microgram_per_liter/>
                </SendData>

            </Aggregate>

        </Aggregate>

    </Aggregate>


<!-- Start mission sequence -->

    <Aggregate Id="SendRep">

        <Sequence Repeat="SendRepeat"/>

      
        <Call Id="ReportSample" RefId="SendDataTo1Modem"/>

        <Assign><Sequence/><Arg Name="CntSamples"/><Arg Name="CntSamples"/><Add><Units:count/><Value>1</Value></Add></Assign>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:second/><Value>10</Value></Setting>
        </Guidance:Wait>

    </Aggregate>

</Mission>


2021-04-11T16:02:27.661Z,1618156947.661 [CommandLine](IMPORTANT): Running ./Missions/send_rep_test.xml
2021-04-11T16:02:27.943Z,1618156947.943 [Default] Stopped
2021-04-11T16:02:27.943Z,1618156947.943 [Default](DEBUG): Aggregate::uninitialize Default
2021-04-11T16:02:27.943Z,1618156947.943 [Default:B.GoToSurface] Stopped
2021-04-11T16:02:27.944Z,1618156947.944 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-04-11T16:02:27.944Z,1618156947.944 [Default:CheckIn] Stopped
2021-04-11T16:02:27.944Z,1618156947.944 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-11T16:02:27.944Z,1618156947.944 [Default:CheckIn:Read_GPS] Stopped
2021-04-11T16:02:27.944Z,1618156947.944 [MissionManager](IMPORTANT): Started mission esp_sample_at_depth
2021-04-11T16:02:27.944Z,1618156947.944 [esp_sample_at_depth] Running Loop=1
2021-04-11T16:02:27.944Z,1618156947.944 [esp_sample_at_depth](DEBUG): Aggregate::initialize esp_sample_at_depth
2021-04-11T16:02:27.944Z,1618156947.944 [esp_sample_at_depth:SendRep] Running Loop=1
2021-04-11T16:02:27.945Z,1618156947.945 [esp_sample_at_depth:SendRep](DEBUG): Aggregate::initialize esp_sample_at_depth:SendRep
2021-04-11T16:02:27.945Z,1618156947.945 [esp_sample_at_depth:SendRep:ReportSample] Running Loop=1
2021-04-11T16:02:27.945Z,1618156947.945 [esp_sample_at_depth:SendRep:ReportSample](DEBUG): Aggregate::initialize esp_sample_at_depth:SendRep:ReportSample
2021-04-11T16:02:27.945Z,1618156947.945 [esp_sample_at_depth:SendDataTo1Modem] Running Loop=1
2021-04-11T16:02:27.945Z,1618156947.945 [esp_sample_at_depth:SendDataTo1Modem](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem
2021-04-11T16:02:27.946Z,1618156947.946 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem] Running Loop=1
2021-04-11T16:02:27.946Z,1618156947.946 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem
2021-04-11T16:02:27.946Z,1618156947.946 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples] Running Loop=1
2021-04-11T16:02:27.946Z,1618156947.946 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples
2021-04-11T16:02:27.946Z,1618156947.946 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:A] Running Loop=1
2021-04-11T16:02:27.947Z,1618156947.947 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:A](IMPORTANT): CntSamples = 1.000000 count 
2021-04-11T16:02:27.947Z,1618156947.947 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:A] Stopped
2021-04-11T16:02:27.947Z,1618156947.947 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:B] Running Loop=1
2021-04-11T16:02:28.362Z,1618156948.362 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:B](INFO): Queuing up send data for esp_sample_at_depth.CntSamples.
2021-04-11T16:02:28.362Z,1618156948.362 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:B] Stopped
2021-04-11T16:02:28.362Z,1618156948.362 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples](INFO): Completed esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples
2021-04-11T16:02:28.363Z,1618156948.363 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples] Stopped
2021-04-11T16:02:28.363Z,1618156948.363 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples
2021-04-11T16:02:28.363Z,1618156948.363 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber] Running Loop=1
2021-04-11T16:02:28.363Z,1618156948.363 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber
2021-04-11T16:02:28.363Z,1618156948.363 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber:A] Running Loop=1
2021-04-11T16:02:28.685Z,1618156948.685 [DAT](INFO): modem://6: set _.LRAUVcntSamples 1.000000 count
2021-04-11T16:02:28.685Z,1618156948.685 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-04-11T16:02:28.693Z,1618156948.693 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber] Stopped
2021-04-11T16:02:28.693Z,1618156948.693 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber
2021-04-11T16:02:28.693Z,1618156948.693 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber:A] Stopped
2021-04-11T16:02:28.693Z,1618156948.693 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType] Running Loop=1
2021-04-11T16:02:28.693Z,1618156948.693 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType
2021-04-11T16:02:28.693Z,1618156948.693 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType:A] Running Loop=1
2021-04-11T16:02:29.096Z,1618156949.096 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-04-11T16:02:29.134Z,1618156949.134 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType] Stopped
2021-04-11T16:02:29.134Z,1618156949.134 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType
2021-04-11T16:02:29.134Z,1618156949.134 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType:A] Stopped
2021-04-11T16:02:29.134Z,1618156949.134 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume] Running Loop=1
2021-04-11T16:02:29.134Z,1618156949.134 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume
2021-04-11T16:02:29.134Z,1618156949.134 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume:A] Running Loop=1
2021-04-11T16:02:29.510Z,1618156949.510 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume:A](ERROR): data element is not active.
2021-04-11T16:02:29.510Z,1618156949.510 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume:A](IMPORTANT): Science:ESPComponent.sampleVolume = nan ml 
2021-04-11T16:02:29.510Z,1618156949.510 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume:A] Stopped
2021-04-11T16:02:29.510Z,1618156949.510 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume:B] Running Loop=1
2021-04-11T16:02:29.892Z,1618156949.892 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume:B](INFO): Queuing up send data for ESPComponent.sampleVolume.
2021-04-11T16:02:29.892Z,1618156949.892 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume:B] Stopped
2021-04-11T16:02:29.892Z,1618156949.892 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume](INFO): Completed esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume
2021-04-11T16:02:29.892Z,1618156949.892 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume] Stopped
2021-04-11T16:02:29.892Z,1618156949.892 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume
2021-04-11T16:02:29.893Z,1618156949.893 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth] Running Loop=1
2021-04-11T16:02:29.893Z,1618156949.893 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth
2021-04-11T16:02:29.893Z,1618156949.893 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth:A] Running Loop=1
2021-04-11T16:02:30.288Z,1618156950.288 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth:A](IMPORTANT): Universal:depth = 0.266772 m 
2021-04-11T16:02:30.288Z,1618156950.288 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth:A] Stopped
2021-04-11T16:02:30.289Z,1618156950.289 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth:B] Running Loop=1
2021-04-11T16:02:30.716Z,1618156950.716 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth:B](INFO): Queuing up send data for depth.
2021-04-11T16:02:30.716Z,1618156950.716 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth:B] Stopped
2021-04-11T16:02:30.716Z,1618156950.716 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth](INFO): Completed esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth
2021-04-11T16:02:30.716Z,1618156950.716 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth] Stopped
2021-04-11T16:02:30.716Z,1618156950.716 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth
2021-04-11T16:02:30.716Z,1618156950.716 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp] Running Loop=1
2021-04-11T16:02:30.717Z,1618156950.717 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp
2021-04-11T16:02:30.717Z,1618156950.717 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp:A] Running Loop=1
2021-04-11T16:02:31.118Z,1618156951.118 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp:A](ERROR): data element is not active.
2021-04-11T16:02:31.119Z,1618156951.119 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp:A](IMPORTANT): Universal:sea_water_temperature = nan degC 
2021-04-11T16:02:31.119Z,1618156951.119 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp:A] Stopped
2021-04-11T16:02:31.119Z,1618156951.119 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp:B] Running Loop=1
2021-04-11T16:02:31.527Z,1618156951.527 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp:B](ERROR): Failed to send data. sea_water_temperature has no value.
2021-04-11T16:02:31.527Z,1618156951.527 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp:B] Stopped
2021-04-11T16:02:31.527Z,1618156951.527 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp](INFO): Completed esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp
2021-04-11T16:02:31.527Z,1618156951.527 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp] Stopped
2021-04-11T16:02:31.528Z,1618156951.528 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp
2021-04-11T16:02:31.528Z,1618156951.528 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl] Running Loop=1
2021-04-11T16:02:31.528Z,1618156951.528 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl
2021-04-11T16:02:31.528Z,1618156951.528 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl:A] Running Loop=1
2021-04-11T16:02:31.904Z,1618156951.904 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl:A](ERROR): data element is not active.
2021-04-11T16:02:31.904Z,1618156951.904 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl:A](IMPORTANT): Universal:mass_concentration_of_chlorophyll_in_sea_water = nan ug/l 
2021-04-11T16:02:31.904Z,1618156951.904 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl:A] Stopped
2021-04-11T16:02:31.904Z,1618156951.904 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl:B] Running Loop=1
2021-04-11T16:02:32.326Z,1618156952.326 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-04-11T16:02:32.334Z,1618156952.334 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl:B](ERROR): Failed to send data. mass_concentration_of_chlorophyll_in_sea_water has no value.
2021-04-11T16:02:32.334Z,1618156952.334 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl:B] Stopped
2021-04-11T16:02:32.334Z,1618156952.334 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl](INFO): Completed esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl
2021-04-11T16:02:32.334Z,1618156952.334 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl] Stopped
2021-04-11T16:02:32.334Z,1618156952.334 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl
2021-04-11T16:02:32.335Z,1618156952.335 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem](INFO): Completed esp_sample_at_depth:SendDataTo1Modem:SendDataToModem
2021-04-11T16:02:32.335Z,1618156952.335 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem] Stopped
2021-04-11T16:02:32.335Z,1618156952.335 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem
2021-04-11T16:02:32.335Z,1618156952.335 [esp_sample_at_depth:SendDataTo1Modem](INFO): Completed esp_sample_at_depth:SendDataTo1Modem
2021-04-11T16:02:32.335Z,1618156952.335 [esp_sample_at_depth:SendDataTo1Modem] Stopped
2021-04-11T16:02:32.335Z,1618156952.335 [esp_sample_at_depth:SendDataTo1Modem](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem
2021-04-11T16:02:32.727Z,1618156952.727 [esp_sample_at_depth:SendRep:ReportSample](INFO): Completed esp_sample_at_depth:SendRep:ReportSample
2021-04-11T16:02:32.727Z,1618156952.727 [esp_sample_at_depth:SendRep:ReportSample] Stopped
2021-04-11T16:02:32.727Z,1618156952.727 [esp_sample_at_depth:SendRep:ReportSample](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendRep:ReportSample
2021-04-11T16:02:32.728Z,1618156952.728 [esp_sample_at_depth:SendRep:B] Running Loop=1
2021-04-11T16:02:33.115Z,1618156953.115 [esp_sample_at_depth:SendRep:B] Stopped
2021-04-11T16:02:33.116Z,1618156953.116 [esp_sample_at_depth:SendRep:C.Wait] Running Loop=1
2021-04-11T16:02:33.116Z,1618156953.116 [esp_sample_at_depth:SendRep:C.Wait](DEBUG): Initialize Wait Component.
2021-04-11T16:02:33.534Z,1618156953.534 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2021-04-11T16:02:33.534Z,1618156953.534 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-11T16:02:33.574Z,1618156953.574 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-11T16:02:33.974Z,1618156953.974 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-11T16:02:33.974Z,1618156953.974 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2021-04-11T16:02:37.151Z,1618156957.151 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2021-04-11T16:02:37.151Z,1618156957.151 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+0.0,1489.0I,-00168,-01803,+00350,+00000,00168,-0150,+00000+00000000.00,+00000000.00,+00000000.00,9999.9
2021-04-11T16:02:39.164Z,1618156959.164 [DAT](FAULT): Ack receipt timeout failure.
2021-04-11T16:02:39.164Z,1618156959.164 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2021-04-11T16:02:39.602Z,1618156959.602 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2021-04-11T16:02:39.998Z,1618156959.998 [DAT](INFO): modem://6: set _.ESPsampleVolume nan milliliter
2021-04-11T16:02:39.999Z,1618156959.999 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-04-11T16:02:40.398Z,1618156960.398 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-04-11T16:02:41.658Z,1618156961.658 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-04-11T16:02:43.632Z,1618156963.632 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-04-11T16:02:43.640Z,1618156963.640 [esp_sample_at_depth:SendRep:C.Wait](INFO): Done Waiting.
2021-04-11T16:02:43.640Z,1618156963.640 [esp_sample_at_depth:SendRep:C.Wait] Stopped
2021-04-11T16:02:43.640Z,1618156963.640 [esp_sample_at_depth:SendRep:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-11T16:02:43.641Z,1618156963.641 [esp_sample_at_depth:SendRep](INFO): Completed esp_sample_at_depth:SendRep
2021-04-11T16:02:43.641Z,1618156963.641 [esp_sample_at_depth:SendRep] Stopped
2021-04-11T16:02:43.641Z,1618156963.641 [esp_sample_at_depth:SendRep](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendRep
2021-04-11T16:02:43.641Z,1618156963.641 [esp_sample_at_depth:SendRep](INFO): Running loop #2
2021-04-11T16:02:43.642Z,1618156963.642 [esp_sample_at_depth:SendRep] Running Loop=2
2021-04-11T16:02:43.642Z,1618156963.642 [esp_sample_at_depth:SendRep](DEBUG): Aggregate::initialize esp_sample_at_depth:SendRep
2021-04-11T16:02:43.642Z,1618156963.642 [esp_sample_at_depth:SendRep:ReportSample] Running Loop=1
2021-04-11T16:02:43.642Z,1618156963.642 [esp_sample_at_depth:SendRep:ReportSample](DEBUG): Aggregate::initialize esp_sample_at_depth:SendRep:ReportSample
2021-04-11T16:02:44.035Z,1618156964.035 [esp_sample_at_depth:SendDataTo1Modem] Running Loop=1
2021-04-11T16:02:44.035Z,1618156964.035 [esp_sample_at_depth:SendDataTo1Modem](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem
2021-04-11T16:02:44.035Z,1618156964.035 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem] Running Loop=1
2021-04-11T16:02:44.035Z,1618156964.035 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem
2021-04-11T16:02:44.035Z,1618156964.035 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples] Running Loop=1
2021-04-11T16:02:44.035Z,1618156964.035 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples
2021-04-11T16:02:44.035Z,1618156964.035 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:A] Running Loop=1
2021-04-11T16:02:44.036Z,1618156964.036 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:A](IMPORTANT): CntSamples = 2.000000 count 
2021-04-11T16:02:44.036Z,1618156964.036 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:A] Stopped
2021-04-11T16:02:44.036Z,1618156964.036 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:B] Running Loop=1
2021-04-11T16:02:44.432Z,1618156964.432 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:B](INFO): Queuing up send data for esp_sample_at_depth.CntSamples.
2021-04-11T16:02:44.553Z,1618156964.553 [MissionManager](CRITICAL): SIGSEGV: address not mapped to object
2021-04-11T16:02:44.553Z,1618156964.553 [MissionManager] Software Fault, FailCount= 1
2021-04-11T16:02:44.553Z,1618156964.553 [MissionManager](ERROR): Software Fault
2021-04-11T16:02:44.556Z,1618156964.556 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2021-04-11T16:02:44.556Z,1618156964.556 [SyncHandler](INFO): Protected caller Thread ID is 7113
2021-04-11T16:02:44.563Z,1618156964.563 [CommandLine](FAULT): Scheduling is paused
2021-04-11