2018-08-01T04:18:19.397Z,1533097099.397 [Supervisor](DEBUG): Initializing supervisor.
2018-08-01T04:18:19.400Z,1533097099.400 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-08-01T04:18:19.401Z,1533097099.401 [SyncHandler](INFO): Protected caller Thread ID is 946
2018-08-01T04:18:19.401Z,1533097099.401 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-08-01T04:18:19.402Z,1533097099.402 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-08-01T04:18:19.402Z,1533097099.402 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 947
2018-08-01T04:18:19.405Z,1533097099.405 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-08-01T04:18:19.417Z,1533097099.417 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-08-01T04:18:19.418Z,1533097099.418 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-08-01T04:18:19.418Z,1533097099.418 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 948
2018-08-01T04:18:19.419Z,1533097099.419 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-08-01T04:18:19.420Z,1533097099.420 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-08-01T04:18:19.420Z,1533097099.420 [logger ThreadHandler](INFO): Protected caller Thread ID is 949
2018-08-01T04:18:19.422Z,1533097099.422 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-08-01T04:18:19.422Z,1533097099.422 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-08-01T04:18:19.424Z,1533097099.424 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-08-01T04:18:19.522Z,1533097099.522 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-08-01T04:18:19.522Z,1533097099.522 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-08-01T04:18:19.627Z,1533097099.627 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-08-01T04:18:19.627Z,1533097099.627 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-08-01T04:18:19.836Z,1533097099.836 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-08-01T04:18:19.836Z,1533097099.836 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-08-01T04:18:20.178Z,1533097100.178 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-08-01T04:18:20.178Z,1533097100.178 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-08-01T04:18:20.531Z,1533097100.531 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-08-01T04:18:20.532Z,1533097100.532 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-08-01T04:18:21.009Z,1533097101.009 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-08-01T04:18:21.010Z,1533097101.010 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-08-01T04:18:21.443Z,1533097101.443 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-08-01T04:18:21.444Z,1533097101.444 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-08-01T04:18:21.931Z,1533097101.931 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-08-01T04:18:21.931Z,1533097101.931 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-08-01T04:18:22.012Z,1533097102.012 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-08-01T04:18:22.902Z,1533097102.902 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-08-01T04:18:22.902Z,1533097102.902 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-08-01T04:18:23.052Z,1533097103.052 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-08-01T04:18:23.053Z,1533097103.053 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-08-01T04:18:23.268Z,1533097103.268 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-08-01T04:18:23.269Z,1533097103.269 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-08-01T04:18:23.488Z,1533097103.488 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-08-01T04:18:23.489Z,1533097103.489 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-08-01T04:18:23.589Z,1533097103.589 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-08-01T04:18:23.589Z,1533097103.589 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-08-01T04:18:23.736Z,1533097103.736 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-08-01T04:18:23.738Z,1533097103.738 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2018-08-01T04:18:23.739Z,1533097103.739 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2018-08-01T04:18:23.974Z,1533097103.974 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-08-01T04:18:23.975Z,1533097103.975 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2018-08-01T04:18:24.082Z,1533097104.082 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2018-08-01T04:18:24.229Z,1533097104.229 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2018-08-01T04:18:24.324Z,1533097104.324 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2018-08-01T04:18:24.410Z,1533097104.410 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2018-08-01T04:18:24.556Z,1533097104.556 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2018-08-01T04:18:24.742Z,1533097104.742 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2018-08-01T04:18:24.841Z,1533097104.841 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2018-08-01T04:18:24.937Z,1533097104.937 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2018-08-01T04:18:25.036Z,1533097105.036 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2018-08-01T04:18:25.120Z,1533097105.120 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2018-08-01T04:18:25.121Z,1533097105.121 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-08-01T04:18:25.129Z,1533097105.129 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-08-01T04:18:25.227Z,1533097105.227 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-08-01T04:18:25.227Z,1533097105.227 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-08-01T04:18:25.240Z,1533097105.240 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-08-01T04:18:25.241Z,1533097105.241 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-08-01T04:18:25.281Z,1533097105.281 [DepthRateCalculator] Loaded
2018-08-01T04:18:25.281Z,1533097105.281 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-08-01T04:18:25.287Z,1533097105.287 [PitchRateCalculator] Loaded
2018-08-01T04:18:25.288Z,1533097105.288 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-08-01T04:18:25.304Z,1533097105.304 [SpeedCalculator] Loaded
2018-08-01T04:18:25.304Z,1533097105.304 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-08-01T04:18:25.325Z,1533097105.325 [TempGradientCalculator] Loaded
2018-08-01T04:18:25.326Z,1533097105.326 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-08-01T04:18:25.341Z,1533097105.341 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2018-08-01T04:18:25.341Z,1533097105.341 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2018-08-01T04:18:25.347Z,1533097105.347 [YawRateCalculator] Loaded
2018-08-01T04:18:25.347Z,1533097105.347 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-08-01T04:18:25.387Z,1533097105.387 [ElevatorOffsetCalculator] Loaded
2018-08-01T04:18:25.387Z,1533097105.387 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-08-01T04:18:25.388Z,1533097105.388 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-08-01T04:18:25.388Z,1533097105.388 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-08-01T04:18:25.413Z,1533097105.413 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-08-01T04:18:25.413Z,1533097105.413 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-08-01T04:18:25.692Z,1533097105.692 [DataOverHttps] Loaded
2018-08-01T04:18:25.692Z,1533097105.692 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-08-01T04:18:25.720Z,1533097105.720 [Depth_Keller] Loaded
2018-08-01T04:18:25.720Z,1533097105.720 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-08-01T04:18:25.819Z,1533097105.819 [NAL9602] Loaded
2018-08-01T04:18:25.819Z,1533097105.819 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-08-01T04:18:25.835Z,1533097105.835 [Onboard] Loaded
2018-08-01T04:18:25.836Z,1533097105.836 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-08-01T04:18:25.846Z,1533097105.846 [Radio_Surface] Loaded
2018-08-01T04:18:25.846Z,1533097105.846 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-08-01T04:18:25.847Z,1533097105.847 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407B74E0
2018-08-01T04:18:25.847Z,1533097105.847 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1028
2018-08-01T04:18:25.895Z,1533097105.895 [PNI_TCM] Loaded
2018-08-01T04:18:25.895Z,1533097105.895 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-08-01T04:18:27.662Z,1533097107.662 [BPC1] Loaded
2018-08-01T04:18:27.662Z,1533097107.662 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-08-01T04:18:27.663Z,1533097107.663 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-08-01T04:18:27.663Z,1533097107.663 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-08-01T04:18:27.791Z,1533097107.791 [SBIT](DEBUG): Construct Startup Built In Test.
2018-08-01T04:18:27.814Z,1533097107.814 [SBIT] Loaded
2018-08-01T04:18:27.814Z,1533097107.814 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-08-01T04:18:27.815Z,1533097107.815 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-08-01T04:18:27.827Z,1533097107.827 [IBIT] Loaded
2018-08-01T04:18:27.827Z,1533097107.827 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-08-01T04:18:27.830Z,1533097107.830 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-08-01T04:18:27.981Z,1533097107.981 [CBIT] Loaded
2018-08-01T04:18:27.981Z,1533097107.981 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-08-01T04:18:27.982Z,1533097107.982 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-08-01T04:18:27.982Z,1533097107.982 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-08-01T04:18:28.430Z,1533097108.430 [Aanderaa_O2] Loaded
2018-08-01T04:18:28.430Z,1533097108.430 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-08-01T04:18:28.502Z,1533097108.502 [CTD_Seabird] Loaded
2018-08-01T04:18:28.502Z,1533097108.502 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2018-08-01T04:18:28.509Z,1533097108.509 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 4087A4E0
2018-08-01T04:18:28.509Z,1533097108.509 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1029
2018-08-01T04:18:28.564Z,1533097108.564 [ESPComponent] Loaded
2018-08-01T04:18:28.564Z,1533097108.564 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2018-08-01T04:18:28.579Z,1533097108.579 [PAR_Licor] Loaded
2018-08-01T04:18:28.579Z,1533097108.579 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-08-01T04:18:28.654Z,1533097108.654 [WetLabsBB2FL] Loaded
2018-08-01T04:18:28.655Z,1533097108.655 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-08-01T04:18:28.681Z,1533097108.681 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 408AA4E0
2018-08-01T04:18:28.681Z,1533097108.681 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1030
2018-08-01T04:18:28.682Z,1533097108.682 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-08-01T04:18:28.682Z,1533097108.682 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-08-01T04:18:28.975Z,1533097108.975 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-08-01T04:18:28.976Z,1533097108.976 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-08-01T04:18:29.043Z,1533097109.043 [VerticalControl](DEBUG): Construct VerticalControl.
2018-08-01T04:18:29.138Z,1533097109.138 [VerticalControl] Loaded
2018-08-01T04:18:29.138Z,1533097109.138 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-08-01T04:18:29.139Z,1533097109.139 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-08-01T04:18:29.200Z,1533097109.200 [HorizontalControl] Loaded
2018-08-01T04:18:29.201Z,1533097109.201 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-08-01T04:18:29.201Z,1533097109.201 [SpeedControl](DEBUG): Construct SpeedControl.
2018-08-01T04:18:29.207Z,1533097109.207 [SpeedControl] Loaded
2018-08-01T04:18:29.207Z,1533097109.207 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-08-01T04:18:29.208Z,1533097109.208 [LoopControl](DEBUG): Construct LoopControl.
2018-08-01T04:18:29.208Z,1533097109.208 [LoopControl] Loaded
2018-08-01T04:18:29.208Z,1533097109.208 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-08-01T04:18:29.209Z,1533097109.209 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-08-01T04:18:29.209Z,1533097109.209 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-08-01T04:18:29.291Z,1533097109.291 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2018-08-01T04:18:29.291Z,1533097109.291 [StratificationFrontDetector](DEBUG): (re)initializing
2018-08-01T04:18:29.291Z,1533097109.291 [StratificationFrontDetector] Loaded
2018-08-01T04:18:29.291Z,1533097109.291 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2018-08-01T04:18:29.292Z,1533097109.292 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-08-01T04:18:29.293Z,1533097109.293 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-08-01T04:18:29.390Z,1533097109.390 [BuoyancyServo] Loaded
2018-08-01T04:18:29.390Z,1533097109.390 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-08-01T04:18:29.401Z,1533097109.401 [ElevatorServo] Loaded
2018-08-01T04:18:29.402Z,1533097109.402 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-08-01T04:18:29.413Z,1533097109.413 [MassServo] Loaded
2018-08-01T04:18:29.413Z,1533097109.413 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-08-01T04:18:29.424Z,1533097109.424 [RudderServo] Loaded
2018-08-01T04:18:29.424Z,1533097109.424 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-08-01T04:18:29.435Z,1533097109.435 [ThrusterServo] Loaded
2018-08-01T04:18:29.436Z,1533097109.436 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-08-01T04:18:29.436Z,1533097109.436 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-08-01T04:18:29.437Z,1533097109.437 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-08-01T04:18:29.527Z,1533097109.527 [DeadReckonUsingSpeedCalculator] Loaded
2018-08-01T04:18:29.527Z,1533097109.527 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-08-01T04:18:29.544Z,1533097109.544 [NavChart] Loaded
2018-08-01T04:18:29.544Z,1533097109.544 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-08-01T04:18:29.548Z,1533097109.548 [UniversalFixResidualReporter] Loaded
2018-08-01T04:18:29.549Z,1533097109.549 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-08-01T04:18:29.549Z,1533097109.549 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-08-01T04:18:29.553Z,1533097109.553 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-08-01T04:18:29.553Z,1533097109.553 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-08-01T04:18:29.560Z,1533097109.560 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-08-01T04:18:29.561Z,1533097109.561 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A034E0
2018-08-01T04:18:29.562Z,1533097109.562 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1031
2018-08-01T04:18:29.566Z,1533097109.566 [Supervisor](INFO): Main Thread ID is 798
2018-08-01T04:18:29.566Z,1533097109.566 [Supervisor](DEBUG): Running supervisor.
2018-08-01T04:18:29.567Z,1533097109.567 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1032
2018-08-01T04:18:29.570Z,1533097109.570 [controlThread ThreadHandler](INFO): Handler Thread ID is 1033
2018-08-01T04:18:29.570Z,1533097109.570 [controlThread](DEBUG): Initializing ControlThread
2018-08-01T04:18:29.571Z,1533097109.571 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-08-01T04:18:29.571Z,1533097109.571 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-08-01T04:18:29.572Z,1533097109.572 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-08-01T04:18:29.572Z,1533097109.572 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-08-01T04:18:29.573Z,1533097109.573 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2018-08-01T04:18:29.574Z,1533097109.574 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-08-01T04:18:29.574Z,1533097109.574 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-08-01T04:18:29.578Z,1533097109.578 [SBIT](INFO): Initialize SBIT Component.
2018-08-01T04:18:29.579Z,1533097109.579 [SBIT](IMPORTANT): git: 2018-07-25
2018-08-01T04:18:29.579Z,1533097109.579 [SBIT](INFO): git hash: 2912d14d75d7acdc47d6eebe250915c9e75a6268
2018-08-01T04:18:29.579Z,1533097109.579 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-08-01T04:18:29.581Z,1533097109.581 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
Kernel Reported: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-08-01T04:18:29.582Z,1533097109.582 [SBIT](INFO): Beginning SBIT in 59.000000 seconds.
2018-08-01T04:18:29.582Z,1533097109.582 [IBIT](INFO): Initialize IBIT Component.
2018-08-01T04:18:29.583Z,1533097109.583 [CBIT](DEBUG): Initialize CBIT Component.
2018-08-01T04:18:29.583Z,1533097109.583 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-08-01T04:18:29.584Z,1533097109.584 [logger ThreadHandler](INFO): Handler Thread ID is 1034
2018-08-01T04:18:29.601Z,1533097109.601 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1035
2018-08-01T04:18:29.607Z,1533097109.607 [Radio_Surface](INFO): Powering up
2018-08-01T04:18:29.613Z,1533097109.613 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1036
2018-08-01T04:18:29.614Z,1533097109.614 [CTD_Seabird](INFO): Initializing
2018-08-01T04:18:29.614Z,1533097109.614 [CTD_Seabird](INFO): Checking LCM
2018-08-01T04:18:29.623Z,1533097109.623 [CTD_Seabird](INFO): LCM OK
2018-08-01T04:18:29.624Z,1533097109.624 [CTD_Seabird](INFO): Powering up
2018-08-01T04:18:29.629Z,1533097109.629 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1037
2018-08-01T04:18:29.631Z,1533097109.631 [WetLabsBB2FL](INFO): Powering down
2018-08-01T04:18:29.657Z,1533097109.657 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1038
2018-08-01T04:18:29.660Z,1533097109.660 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-08-01T04:18:29.660Z,1533097109.660 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-08-01T04:18:29.661Z,1533097109.661 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-08-01T04:18:29.661Z,1533097109.661 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-08-01T04:18:29.661Z,1533097109.661 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-08-01T04:18:29.662Z,1533097109.662 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-08-01T04:18:29.662Z,1533097109.662 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-08-01T04:18:29.662Z,1533097109.662 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-08-01T04:18:29.662Z,1533097109.662 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-08-01T04:18:29.662Z,1533097109.662 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-08-01T04:18:29.663Z,1533097109.663 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-08-01T04:18:29.663Z,1533097109.663 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-08-01T04:18:29.663Z,1533097109.663 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-08-01T04:18:29.663Z,1533097109.663 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-08-01T04:18:29.663Z,1533097109.663 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-08-01T04:18:29.663Z,1533097109.663 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-08-01T04:18:29.693Z,1533097109.693 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-08-01T04:18:29.695Z,1533097109.695 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-08-01T04:18:29.696Z,1533097109.696 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-08-01T04:18:29.696Z,1533097109.696 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-08-01T04:18:29.698Z,1533097109.698 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-01T04:18:29.699Z,1533097109.699 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-01T04:18:29.699Z,1533097109.699 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-01T04:18:29.700Z,1533097109.700 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-08-01T04:18:29.700Z,1533097109.700 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-08-01T04:18:29.702Z,1533097109.702 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-08-01T04:18:29.718Z,1533097109.718 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-08-01T04:18:29.753Z,1533097109.753 [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>


2018-08-01T04:18:29.754Z,1533097109.754 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-08-01T04:18:29.854Z,1533097109.854 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-08-01T04:18:29.855Z,1533097109.855 [Default:A.Wait](DEBUG): Construct Wait.
2018-08-01T04:18:29.857Z,1533097109.857 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-08-01T04:18:29.876Z,1533097109.876 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-08-01T04:18:29.903Z,1533097109.903 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-08-01T04:18:29.921Z,1533097109.921 [Default:E.Execute](DEBUG): Construct Execute.
2018-08-01T04:18:29.925Z,1533097109.925 [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 300</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>


2018-08-01T04:18:29.947Z,1533097109.947 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,NAL9602,Onboard,PNI_TCM,BPC1,Aanderaa_O2,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-08-01T04:18:29.972Z,1533097109.972 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-08-01T04:18:30.343Z,1533097110.343 [ESPComponent](INFO): powering down ESP
2018-08-01T04:18:30.897Z,1533097110.897 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T04:18:31.025Z,1533097111.025 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-08-01T04:18:31.033Z,1533097111.033 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-08-01T04:18:31.048Z,1533097111.048 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-08-01T04:18:31.049Z,1533097111.049 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-08-01T04:18:31.076Z,1533097111.076 [MassServo](DEBUG): Initializing EZServoServo.
2018-08-01T04:18:31.081Z,1533097111.081 [MassServo](DEBUG): Initializing MassServo.
2018-08-01T04:18:31.103Z,1533097111.103 [RudderServo](DEBUG): Initializing EZServoServo.
2018-08-01T04:18:31.109Z,1533097111.109 [RudderServo](DEBUG): Initializing RudderServo.
2018-08-01T04:18:31.123Z,1533097111.123 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-08-01T04:18:31.129Z,1533097111.129 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-08-01T04:18:31.378Z,1533097111.378 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T04:18:31.664Z,1533097111.664 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T04:18:32.009Z,1533097112.009 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2018-08-01T04:18:32.009Z,1533097112.009 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2018-08-01T04:18:32.009Z,1533097112.009 [BuoyancyServo] Communications Fault, FailCount= 1
2018-08-01T04:18:32.009Z,1533097112.009 [BuoyancyServo](ERROR): Communications Fault
2018-08-01T04:18:32.217Z,1533097112.217 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2018-08-01T04:18:32.271Z,1533097112.271 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T04:18:32.301Z,1533097112.301 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-08-01T04:18:32.302Z,1533097112.302 [BuoyancyServo](INFO): Powering down
2018-08-01T04:18:32.701Z,1533097112.701 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T04:18:33.093Z,1533097113.093 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T04:18:33.569Z,1533097113.569 [Aanderaa_O2](INFO): Powering down
2018-08-01T04:18:33.625Z,1533097113.625 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T04:18:33.870Z,1533097113.870 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T04:18:34.422Z,1533097114.422 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2018-08-01T04:18:34.422Z,1533097114.422 [BuoyancyServo] No Fault, FailCount= 1
2018-08-01T04:18:34.698Z,1533097114.698 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-08-01T04:18:34.818Z,1533097114.818 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-08-01T04:18:35.215Z,1533097115.215 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-08-01T04:18:35.360Z,1533097115.360 [CTD_Seabird](INFO): Started Seabird LCM interface with command:nohup ./lrauv-framework/onboard/bin/gpctd -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyC6 -b 9600 >& /dev/null &
2018-08-01T04:18:35.438Z,1533097115.438 [CTD_Seabird](INFO): LCM subscribed to channel:ctd_t.seabird-gpctd
2018-08-01T04:18:36.097Z,1533097116.097 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-08-01T04:18:36.097Z,1533097116.097 [CTD_Seabird](INFO): Powering down
2018-08-01T04:18:55.907Z,1533097135.907 [NAL9602](INFO): Powering up NAL9602
2018-08-01T04:19:07.106Z,1533097147.106 [NAL9602](INFO): NAL9602 initialized
2018-08-01T04:19:29.161Z,1533097169.161 [SBIT](IMPORTANT): Beginning Startup BIT
2018-08-01T04:19:29.198Z,1533097169.198 [CBIT](IMPORTANT): Beginning ground fault scan
2018-08-01T04:19:40.143Z,1533097180.143 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.008264
CHAN A1 (24V): -0.011389
CHAN A2 (12V): -0.004967
CHAN A3 (5V): -0.002245
CHAN B0 (3.3V): -0.001460
CHAN B1 (3.15aV): -0.001090
CHAN B2 (3.15bV): -0.001475
CHAN B3 (GND): 0.000011
OPEN: 0.004535
Full Scale Calc: 4.765 mA, -1.589 mA
2018-08-01T04:19:56.967Z,1533097196.967 [CommandLine](IMPORTANT): got command maintain sensor NAL9602.latitude_fix 36.799999 degree
2018-08-01T04:19:56.968Z,1533097196.968 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.latitude_fix" handled in the control thread.
2018-08-01T04:19:56.969Z,1533097196.969 [CommandLine](IMPORTANT): got command maintain sensor NAL9602.longitude_fix -121.900002 degree
2018-08-01T04:19:56.971Z,1533097196.971 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.longitude_fix" handled in the control thread.
2018-08-01T04:19:57.168Z,1533097197.168 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,NAL9602,Onboard,PNI_TCM,BPC1,Aanderaa_O2,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,Maintain_NAL9602.latitude_fix,Maintain_NAL9602.longitude_fix,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-08-01T04:20:19.626Z,1533097219.626 [CommandLine](IMPORTANT): got command set NAL9602.time_fix 1533096832.000000 second
2018-08-01T04:20:23.211Z,1533097223.211 [SBIT](IMPORTANT): SBIT PASSED
2018-08-01T04:20:23.268Z,1533097223.268 [CommandLine](IMPORTANT): got command configSet list
2018-08-01T04:20:23.268Z,1533097223.268 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-08-01T04:20:23.270Z,1533097223.270 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.loadAtStartup=0 bool;

2018-08-01T04:20:23.270Z,1533097223.270 [CommandLine](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2018-08-01T04:20:23.270Z,1533097223.270 [CommandLine](IMPORTANT): Express none Rowe_600LCM.height_above_sea_floor;

2018-08-01T04:20:23.270Z,1533097223.270 [CommandLine](IMPORTANT): IBIT.batteryHibernationTimeout=1 hour;

2018-08-01T04:20:23.270Z,1533097223.270 [CommandLine](IMPORTANT): IBIT.batteryMissingStickThreshold=15 count;

2018-08-01T04:20:23.271Z,1533097223.271 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=0 bool;

2018-08-01T04:20:23.271Z,1533097223.271 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=200 cubic_centimeter;

2018-08-01T04:20:23.271Z,1533097223.271 [CommandLine](IMPORTANT): VerticalControl.massDefault=10 millimeter;

2018-08-01T04:20:23.625Z,1533097223.625 [MissionManager](IMPORTANT): Started mission Startup
2018-08-01T04:20:23.626Z,1533097223.626 [Startup] Running Loop=1
2018-08-01T04:20:23.626Z,1533097223.626 [Startup](DEBUG): Aggregate::initialize Startup
2018-08-01T04:20:23.626Z,1533097223.626 [Startup:A.GoToSurface] Running Loop=1
2018-08-01T04:20:23.626Z,1533097223.626 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-08-01T04:20:23.627Z,1533097223.627 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-08-01T04:20:23.627Z,1533097223.627 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-08-01T04:20:23.628Z,1533097223.628 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-08-01T04:20:23.628Z,1533097223.628 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-08-01T04:20:23.629Z,1533097223.629 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-08-01T04:20:23.659Z,1533097223.659 [Startup:StartupSatComms] Running Loop=1
2018-08-01T04:20:23.659Z,1533097223.659 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-08-01T04:20:23.659Z,1533097223.659 [Startup:StartupSatComms:A] Running Loop=1
2018-08-01T04:20:24.021Z,1533097224.021 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-08-01T04:20:24.023Z,1533097224.023 [Startup:StartupSatComms:A] Stopped
2018-08-01T04:20:24.023Z,1533097224.023 [Startup:StartupSatComms:B] Running Loop=1
2018-08-01T04:20:24.391Z,1533097224.391 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-08-01T04:21:24.392Z,1533097284.392 [Startup:StartupSatComms:B](INFO): Timed out from 2018-08-01T04:20:24.0Z
2018-08-01T04:21:24.392Z,1533097284.392 [Startup:StartupSatComms:B] Stopped
2018-08-01T04:21:24.393Z,1533097284.393 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-08-01T04:21:24.393Z,1533097284.393 [Startup:StartupSatComms] Stopped
2018-08-01T04:21:24.393Z,1533097284.393 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-08-01T04:21:24.394Z,1533097284.394 [Startup](INFO): Completed Startup
2018-08-01T04:21:24.394Z,1533097284.394 [MissionManager](INFO): Startup is completed.
2018-08-01T04:21:24.394Z,1533097284.394 [MissionManager](INFO): Uninitializing Mission Startup
2018-08-01T04:21:24.395Z,1533097284.395 [Startup] Stopped
2018-08-01T04:21:24.395Z,1533097284.395 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-08-01T04:21:24.395Z,1533097284.395 [Startup:A.GoToSurface] Stopped
2018-08-01T04:21:24.395Z,1533097284.395 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-08-01T04:21:24.797Z,1533097284.797 [MissionManager](IMPORTANT): Started mission Default
2018-08-01T04:21:24.797Z,1533097284.797 [Default] Running Loop=1
2018-08-01T04:21:24.797Z,1533097284.797 [Default](DEBUG): Aggregate::initialize Default
2018-08-01T04:21:24.798Z,1533097284.798 [Default:B.GoToSurface] Running Loop=1
2018-08-01T04:21:24.798Z,1533097284.798 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-08-01T04:21:24.798Z,1533097284.798 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-08-01T04:21:24.798Z,1533097284.798 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-08-01T04:21:24.799Z,1533097284.799 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-08-01T04:21:24.799Z,1533097284.799 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-08-01T04:21:24.799Z,1533097284.799 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-08-01T04:21:24.800Z,1533097284.800 [Default:A.Wait] Running Loop=1
2018-08-01T04:21:24.800Z,1533097284.800 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-08-01T04:21:36.364Z,1533097296.364 [DataOverHttps](IMPORTANT): SBD MTMSN=20180801T041543
2018-08-01T04:21:36.369Z,1533097296.369 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005357
2018-08-01T04:21:38.014Z,1533097298.014 [Default:A.Wait](INFO): Done Waiting.
2018-08-01T04:21:38.014Z,1533097298.014 [Default:A.Wait] Stopped
2018-08-01T04:21:38.014Z,1533097298.014 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T04:21:41.267Z,1533097301.267 [Default:CheckIn] Running Loop=1
2018-08-01T04:21:41.267Z,1533097301.267 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T04:21:41.267Z,1533097301.267 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T04:21:41.321Z,1533097301.321 [DataOverHttps](INFO): Received command:sched asap "load Maintenance/sample.xml;set sample.MissionTimeout 5 hour;set sample.Depth 2 meter;set sample.NumberOfSamples 3 count;set sample.WaitBeforeSample 3 second;set sample:SampleAtDepth.TargetDepth 2 meter" 29t5a 1 2
2018-08-01T04:21:41.399Z,1533097301.399 [CommandLine](IMPORTANT): got command schedule asap "load Maintenance/sample.xml;set sample.MissionTimeout 5 hour;set sample.Depth 2 meter;set sample.NumberOfSamples 3 count;set sample.WaitBeforeSample 3 second;set sample:SampleAtDepth.TargetDepth 2 meter" 29t5a 1 2.000000
2018-08-01T04:21:41.400Z,1533097301.400 [CommandLine](IMPORTANT): Scheduling command #1 of 2 with id=29t5a
2018-08-01T04:21:41.401Z,1533097301.401 [CommandLine](IMPORTANT): Scheduled #1 (#1 of 2 with id='29t5a'): "load Maintenance/sample.xml;set sample.MissionTimeout 5 hour;set sample.Depth 2 meter;set sample.NumberOfSamples 3 count;set sample.WaitBeforeSample 3 second;set sample:SampleAtDepth.TargetDepth 2 meter" ASAP
2018-08-01T04:21:41.434Z,1533097301.434 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-08-01T04:21:42.087Z,1533097302.087 [DataOverHttps](IMPORTANT): SBD MTMSN=20180801T041549
2018-08-01T04:21:46.890Z,1533097306.890 [DataOverHttps](INFO): Received command:sched asap "set sample:SampleAtDepth.SettleTime 3 second;run " 29t5a 2 2
2018-08-01T04:21:46.917Z,1533097306.917 [CommandLine](IMPORTANT): got command schedule asap "set sample:SampleAtDepth.SettleTime 3 second;run " 29t5a 2 2.000000
2018-08-01T04:21:46.917Z,1533097306.917 [CommandLine](IMPORTANT): Scheduling command #2 of 2 with id=29t5a
2018-08-01T04:21:46.918Z,1533097306.918 [CommandLine](IMPORTANT): Scheduled #2 (#2 of 2 with id='29t5a'): "set sample:SampleAtDepth.SettleTime 3 second;run " ASAP
2018-08-01T04:21:47.066Z,1533097307.066 [CommandLine](IMPORTANT): got command load ./Missions/Maintenance/sample.xml
2018-08-01T04:21:47.066Z,1533097307.066 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/sample.xml
2018-08-01T04:21:47.149Z,1533097307.149 [MissionManager](INFO): DefineArg sample.MissionTimeout = 90.000000 min
2018-08-01T04:21:47.152Z,1533097307.152 [MissionManager](INFO): DefineArg sample.Depth = 7.000000 m
2018-08-01T04:21:47.159Z,1533097307.159 [MissionManager](INFO): DefineArg sample.NumberOfSamples = 1.000000 count
2018-08-01T04:21:47.163Z,1533097307.163 [MissionManager](INFO): DefineArg sample.WaitBeforeSample = 3.000000 min
2018-08-01T04:21:47.164Z,1533097307.164 [sample:A.Pitch](DEBUG): Construct.
2018-08-01T04:21:47.178Z,1533097307.178 [sample:B.SetSpeed](DEBUG): Construct.
2018-08-01T04:21:47.180Z,1533097307.180 [MissionManager](INFO): Inserting Stack: Missions/Insert/SampleAtDepth.xml
2018-08-01T04:21:47.351Z,1533097307.351 [MissionManager](INFO): DefineArg sample:SampleAtDepth.TargetDepth = 5.000000 m
2018-08-01T04:21:47.362Z,1533097307.362 [MissionManager](INFO): DefineArg sample:SampleAtDepth.SettleTime = 30.000000 s
2018-08-01T04:21:47.374Z,1533097307.374 [MissionManager](INFO): DefineArg sample:SampleAtDepth.MaxWaitNotReachingDepth = 3.000000 h
2018-08-01T04:21:47.376Z,1533097307.376 [MissionManager](INFO): DefineArg sample:SampleAtDepth.RotateOnly = 0.000000 bool
2018-08-01T04:21:47.392Z,1533097307.392 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseCANONSampler = 0.000000 bool
2018-08-01T04:21:47.399Z,1533097307.399 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseESP = 1.000000 bool
2018-08-01T04:21:47.415Z,1533097307.415 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTriggerTimeout = 1.000000 min
2018-08-01T04:21:47.424Z,1533097307.424 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTimeout = 6.000000 min
2018-08-01T04:21:47.427Z,1533097307.427 [sample:SampleAtDepth:B.Pitch](DEBUG): Construct.
2018-08-01T04:21:47.451Z,1533097307.451 [sample:SampleAtDepth:B.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute.
2018-08-01T04:21:47.459Z,1533097307.459 [sample:SampleAtDepth:D.Wait](DEBUG): Construct Wait.
2018-08-01T04:21:47.472Z,1533097307.472 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler:A_Timeout:B.Execute](DEBUG): Construct Execute.
2018-08-01T04:21:47.475Z,1533097307.475 [MissionManager](ERROR): Slate does not contain CTD_NeilBrown.bin_mean_sea_water_temperature
2018-08-01T04:21:47.475Z,1533097307.475 [MissionManager](ERROR): Slate does not contain celsius
2018-08-01T04:21:47.492Z,1533097307.492 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:E:A_Timeout:B.Execute](DEBUG): Construct Execute.
2018-08-01T04:21:47.497Z,1533097307.497 [MissionManager](ERROR): Slate does not contain CTD_NeilBrown.bin_mean_sea_water_temperature
2018-08-01T04:21:47.497Z,1533097307.497 [MissionManager](ERROR): Slate does not contain celsius
2018-08-01T04:21:47.534Z,1533097307.534 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<!-- ====================
     Generated by TethysL
     ==================== -->
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Control="Tethys/Control"
         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"
       Id="sample">

    <Description>
        This mission is designed to be run in the test tank only and samples
        whichever sampler is installed once the vehicle reaches the target depth.
    </Description>
    <DefineArg Name="MissionTimeout"><Description>
        How long to let the mission run.
    </Description><Units:minute/><Value>90</Value></DefineArg>

    <DefineArg Name="Depth"><Description>
        Depth to sample at.
    </Description><Units:meter/><Value>7</Value></DefineArg>

    <DefineArg Name="NumberOfSamples"><Description>
        Number of samples to take.
    </Description><Units:count/><Value>1</Value></DefineArg>

    <DefineArg Name="WaitBeforeSample"><Description>
        How long to wait between samples. This starts *before* the first sample
        to exercise the SettleTime setting in the insert aggregate.
    </Description><Units:minute/><Value>3</Value></DefineArg>
    <Timeout Duration="MissionTimeout"/>
    <Guidance:Pitch>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Control:VerticalControl.massDefault/></Setting>
    </Guidance:Pitch>

    <Guidance:SetSpeed>
        <Parallel/>
        <Setting><Guidance:SetSpeed.speed/><Units:meter_per_second/><Value>0</Value></Setting>
    </Guidance:SetSpeed>

    <Insert Filename="Insert/SampleAtDepth.xml"/>

    <Assign><Sequence/><Arg Name="SampleAtDepth:TargetDepth"/><Arg Name="Depth"/></Assign>

    <Assign><Sequence/><Arg Name="SampleAtDepth:SettleTime"/><Arg Name="WaitBeforeSample"/></Assign>

    <Aggregate Id="SampleRepeater">
        <Sequence Repeat="NumberOfSamples"/>

        <Call Id="Sample" RefId="SampleAtDepth"/>
    </Aggregate>
</Mission>

2018-08-01T04:21:47.535Z,1533097307.535 [CommandLine](IMPORTANT): Loaded ./Missions/Maintenance/sample.xml
2018-08-01T04:21:56.477Z,1533097316.477 [CommandLine](IMPORTANT): got command set sample.MissionTimeout 5.000000 hour
2018-08-01T04:21:56.478Z,1533097316.478 [CommandLine](IMPORTANT): got command set sample.Depth 2.000000 meter
2018-08-01T04:21:56.478Z,1533097316.478 [CommandLine](IMPORTANT): got command set sample.NumberOfSamples 3.000000 count
2018-08-01T04:21:56.479Z,1533097316.479 [CommandLine](IMPORTANT): got command set sample.WaitBeforeSample 3.000000 second
2018-08-01T04:21:56.480Z,1533097316.480 [CommandLine](IMPORTANT): got command set sample:SampleAtDepth.TargetDepth 2.000000 meter
2018-08-01T04:21:59.104Z,1533097319.104 [CommandLine](IMPORTANT): got command set sample:SampleAtDepth.SettleTime 3.000000 second
2018-08-01T04:21:59.104Z,1533097319.104 [CommandLine](IMPORTANT): got command run 
2018-08-01T04:21:59.106Z,1533097319.106 [CommandLine](IMPORTANT): Running 
2018-08-01T04:21:59.349Z,1533097319.349 [Default] Stopped
2018-08-01T04:21:59.349Z,1533097319.349 [Default](DEBUG): Aggregate::uninitialize Default
2018-08-01T04:21:59.350Z,1533097319.350 [Default:B.GoToSurface] Stopped
2018-08-01T04:21:59.350Z,1533097319.350 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-08-01T04:21:59.350Z,1533097319.350 [Default:CheckIn] Stopped
2018-08-01T04:21:59.350Z,1533097319.350 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T04:21:59.350Z,1533097319.350 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T04:21:59.350Z,1533097319.350 [MissionManager](IMPORTANT): Started mission sample
2018-08-01T04:21:59.350Z,1533097319.350 [sample] Running Loop=1
2018-08-01T04:21:59.351Z,1533097319.351 [sample](DEBUG): Aggregate::initialize sample
2018-08-01T04:21:59.351Z,1533097319.351 [sample:A.Pitch] Running Loop=1
2018-08-01T04:21:59.351Z,1533097319.351 [sample:A.Pitch](DEBUG): Initialize.
2018-08-01T04:21:59.351Z,1533097319.351 [sample:B.SetSpeed] Running Loop=1
2018-08-01T04:21:59.351Z,1533097319.351 [sample:B.SetSpeed](DEBUG): Initialize.
2018-08-01T04:21:59.351Z,1533097319.351 [sample:D] Running Loop=1
2018-08-01T04:21:59.353Z,1533097319.353 [sample:D] Stopped
2018-08-01T04:21:59.353Z,1533097319.353 [sample:E] Running Loop=1
2018-08-01T04:21:59.354Z,1533097319.354 [sample:B.SetSpeed] Running Loop=1
2018-08-01T04:21:59.371Z,1533097319.371 [sample:A.Pitch] Running Loop=1
2018-08-01T04:21:59.757Z,1533097319.757 [sample:E] Stopped
2018-08-01T04:21:59.757Z,1533097319.757 [sample:SampleRepeater] Running Loop=1
2018-08-01T04:21:59.757Z,1533097319.757 [sample:SampleRepeater](DEBUG): Aggregate::initialize sample:SampleRepeater
2018-08-01T04:21:59.758Z,1533097319.758 [sample:SampleRepeater:Sample] Running Loop=1
2018-08-01T04:21:59.758Z,1533097319.758 [sample:SampleRepeater:Sample](DEBUG): Aggregate::initialize sample:SampleRepeater:Sample
2018-08-01T04:22:00.154Z,1533097320.154 [sample:SampleAtDepth] Running Loop=1
2018-08-01T04:22:00.154Z,1533097320.154 [sample:SampleAtDepth](DEBUG): Aggregate::initialize sample:SampleAtDepth
2018-08-01T04:22:00.154Z,1533097320.154 [sample:SampleAtDepth:B.Pitch] Running Loop=1
2018-08-01T04:22:00.154Z,1533097320.154 [sample:SampleAtDepth:B.Pitch](DEBUG): Initialize.
2018-08-01T04:22:00.154Z,1533097320.154 [sample:SampleAtDepth:A] Running Loop=1
2018-08-01T04:22:00.161Z,1533097320.161 [sample:SampleAtDepth:A](INFO): Moving to 2.000000 m 
2018-08-01T04:22:00.162Z,1533097320.162 [sample:SampleAtDepth:A] Stopped
2018-08-01T04:22:16.279Z,1533097336.279 [CommandLine](IMPORTANT): got command maintain sensor Depth_Keller.depth 2.000000 meter
2018-08-01T04:22:16.280Z,1533097336.280 [ComponentRegistry](DEBUG): SyncComponent "Maintain_Depth_Keller.depth" handled in the control thread.
2018-08-01T04:22:16.629Z,1533097336.629 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,NAL9602,Onboard,PNI_TCM,BPC1,Aanderaa_O2,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,Maintain_NAL9602.latitude_fix,Maintain_NAL9602.longitude_fix,Maintain_Depth_Keller.depth,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-08-01T04:22:16.954Z,1533097336.954 [sample:SampleAtDepth:C] Running Loop=1
2018-08-01T04:22:17.226Z,1533097337.226 [Radio_Surface](INFO): Powering down
2018-08-01T04:22:17.348Z,1533097337.348 [sample:SampleAtDepth:C](INFO): At 2.000000 m , settling for 0.050000 min 
2018-08-01T04:22:17.349Z,1533097337.349 [sample:SampleAtDepth:C] Stopped
2018-08-01T04:22:17.350Z,1533097337.350 [sample:SampleAtDepth:D.Wait] Running Loop=1
2018-08-01T04:22:17.350Z,1533097337.350 [sample:SampleAtDepth:D.Wait](DEBUG): Initialize Wait Component.
2018-08-01T04:22:20.952Z,1533097340.952 [sample:SampleAtDepth:D.Wait](INFO): Done Waiting.
2018-08-01T04:22:20.953Z,1533097340.953 [sample:SampleAtDepth:D.Wait] Stopped
2018-08-01T04:22:20.953Z,1533097340.953 [sample:SampleAtDepth:D.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T04:22:20.953Z,1533097340.953 [sample:SampleAtDepth:SampleWrapper] Running Loop=1
2018-08-01T04:22:20.953Z,1533097340.953 [sample:SampleAtDepth:SampleWrapper](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper
2018-08-01T04:22:20.953Z,1533097340.953 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler] Running Loop=1
2018-08-01T04:22:20.953Z,1533097340.953 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper:SampleCANONSampler
2018-08-01T04:22:20.953Z,1533097340.953 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:A] Running Loop=1
2018-08-01T04:22:20.953Z,1533097340.953 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:B] Running Loop=1
2018-08-01T04:22:20.954Z,1533097340.954 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler] Running Loop=1
2018-08-01T04:22:21.360Z,1533097341.360 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler] Stopped
2018-08-01T04:22:21.360Z,1533097341.360 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper:SampleCANONSampler
2018-08-01T04:22:21.360Z,1533097341.360 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:A] Stopped
2018-08-01T04:22:21.360Z,1533097341.360 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:B] Stopped
2018-08-01T04:22:21.360Z,1533097341.360 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler] Stopped
2018-08-01T04:22:21.360Z,1533097341.360 [sample:SampleAtDepth:SampleWrapper:SampleESP] Running Loop=1
2018-08-01T04:22:21.361Z,1533097341.361 [sample:SampleAtDepth:SampleWrapper:SampleESP](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper:SampleESP
2018-08-01T04:22:21.361Z,1533097341.361 [sample:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP] Running Loop=1
2018-08-01T04:22:21.760Z,1533097341.760 [sample:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP](DEBUG): Initialize ReadDataComponent to sense ESPComponent.sampling
2018-08-01T04:22:22.518Z,1533097342.518 [ESPComponent](IMPORTANT): Setting regex for ESP Log summary: 'Selecting Cartridge|Sampled|Error|Fail|Retry|Cmd::|Sampler::'
2018-08-01T04:22:22.520Z,1533097342.520 [ESPComponent](INFO): compiled regex: "Selecting Cartridge|Sampled|Error|Fail|Retry|Cmd::|Sampler::"
2018-08-01T04:22:22.944Z,1533097342.944 [ESPComponent](INFO): powering up ESP
2018-08-01T04:22:22.953Z,1533097342.953 [ESPComponent](INFO): manually powering up ESP
2018-08-01T04:22:22.955Z,1533097342.955 [ESPComponent](IMPORTANT): Powered ESP with command: ! echo 1 > /dev/loadA6
2018-08-01T04:22:22.956Z,1533097342.956 [ESPComponent](IMPORTANT): Starting PPPD with command:/sbin/pppd xonxoff asyncmap A0000 /dev/ttyTX1 linkname esp noauth local lock 115200 10.89.5.2:10.89.5.3 persist maxfail 0 holdoff 10 lcp-echo-interval 60 lcp-echo-failure 3 proxyarp ktune deflate 12 ms-dns 8.8.8.8
2018-08-01T04:22:22.984Z,1533097342.984 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadA6
2018-08-01T04:22:23.286Z,1533097343.286 [Radio_Surface](INFO): Powering up
2018-08-01T04:22:23.314Z,1533097343.314 [ESPComponent](IMPORTANT): Waiting for ESP to connect (timeout=150.0000)
2018-08-01T04:22:23.585Z,1533097343.585 [ESPComponent](INFO): console:
2018-08-01T04:22:24.696Z,1533097344.696 [ESPComponent](INFO): console:

2018-08-01T04:22:25.100Z,1533097345.100 [ESPComponent](INFO): console:NAND:  256 MiB
2018-08-01T04:22:25.499Z,1533097345.499 [ESPComponent](INFO): console:
BOOTMODE: SPI
2018-08-01T04:22:25.985Z,1533097345.985 [ESPComponent](INFO): console:
reading SPI NOR..
2018-08-01T04:22:27.143Z,1533097347.143 [ESPComponent](INFO): console:Done
2018-08-01T04:22:27.498Z,1533097347.498 [ESPComponent](INFO): console:

2018-08-01T04:22:27.897Z,1533097347.897 [ESPComponent](INFO): console:

2018-08-01T04:22:28.307Z,1533097348.307 [ESPComponent](INFO): console:
U-Boot 2009.11-mbariB (Dec 07 2017 - 19:07:59)
2018-08-01T04:22:28.706Z,1533097348.706 [ESPComponent](INFO): console:

2018-08-01T04:22:28.942Z,1533097348.942 [Radio_Surface](INFO): Powering down
2018-08-01T04:22:29.113Z,1533097349.113 [ESPComponent](INFO): console:
MBARI LPC31xx ESP 3G
2018-08-01T04:22:29.503Z,1533097349.503 [ESPComponent](INFO): console:
flash params are already written into flash
2018-08-01T04:22:29.892Z,1533097349.892 [ESPComponent](INFO): console:
DRAM:  64 MB
2018-08-01T04:22:30.300Z,1533097350.300 [ESPComponent](INFO): console:
In:    serial
2018-08-01T04:22:30.692Z,1533097350.692 [ESPComponent](INFO): console:
Out:   serial
2018-08-01T04:22:31.092Z,1533097351.092 [ESPComponent](INFO): console:
Err:   serial
2018-08-01T04:22:31.498Z,1533097351.498 [ESPComponent](INFO): console:
Net:   ks8851_mll
2018-08-01T04:22:31.904Z,1533097351.904 [ESPComponent](INFO): console:
Hit <ctrl-C> to stop autoboot:  1  0 
2018-08-01T04:22:32.298Z,1533097352.298 [ESPComponent](INFO): console:
mmc1 is available
2018-08-01T04:22:32.698Z,1533097352.698 [ESPComponent](INFO): console:
reading uImage
2018-08-01T04:22:33.087Z,1533097353.087 [ESPComponent](INFO): console:

2018-08-01T04:22:33.515Z,1533097353.515 [ESPComponent](INFO): console:
1681208 bytes read
2018-08-01T04:22:33.919Z,1533097353.919 [ESPComponent](INFO): console:
## Booting kernel from Legacy Image at 31000000 ...
2018-08-01T04:22:34.314Z,1533097354.314 [ESPComponent](INFO): console:
   Image Name:   Linux-2.6.33-ea3131-mbari6
2018-08-01T04:22:34.700Z,1533097354.700 [ESPComponent](INFO): console:
   Image Type:   ARM Linux Kernel Image (uncompressed)
2018-08-01T04:22:35.112Z,1533097355.112 [ESPComponent](INFO): console:
   Data Size:    1681144 Bytes =  1.6 MB
2018-08-01T04:22:35.497Z,1533097355.497 [ESPComponent](INFO): console:
   Load Address: 30008000
2018-08-01T04:22:35.895Z,1533097355.895 [ESPComponent](INFO): console:
   Entry Point:  30008000
2018-08-01T04:22:36.299Z,1533097356.299 [ESPComponent](INFO): console:
   Verifying Checksum ... OK
2018-08-01T04:22:36.709Z,1533097356.709 [ESPComponent](INFO): console:
   Loading Kernel Image ... OK
2018-08-01T04:22:37.093Z,1533097357.093 [ESPComponent](INFO): console:
OK
2018-08-01T04:22:37.498Z,1533097357.498 [ESPComponent](INFO): console:

2018-08-01T04:22:37.898Z,1533097357.898 [ESPComponent](INFO): console:
Starting kernel ...
2018-08-01T04:22:38.294Z,1533097358.294 [ESPComponent](INFO): console:

2018-08-01T04:22:38.711Z,1533097358.711 [ESPComponent](INFO): console:
Uncompressing Linux... done, booting the kernel.
2018-08-01T04:22:39.109Z,1533097359.109 [ESPComponent](INFO): console:
[    0.00] CPU: ARM926EJ-S [41069265] revision 5 (ARMv5TEJ), cr=00053177
2018-08-01T04:22:39.498Z,1533097359.498 [ESPComponent](INFO): console:
[    0.00] CPU: VIVT data cache, VIVT instruction cache
2018-08-01T04:22:39.914Z,1533097359.914 [ESPComponent](INFO): console:
[    0.00] Machine: NXP EA313X
2018-08-01T04:22:40.293Z,1533097360.293 [ESPComponent](INFO): console:
[    0.00] Memory policy: ECC disabled, Data cache writeback
2018-08-01T04:22:40.701Z,1533097360.701 [ESPComponent](INFO): console:
[    0.00] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 16256
2018-08-01T04:22:41.067Z,1533097361.067 [Radio_Surface](INFO): Powering up
2018-08-01T04:22:41.111Z,1533097361.111 [ESPComponent](INFO): console:
[    0.24] Mount-cache hash table entries: 512
2018-08-01T04:22:41.504Z,1533097361.504 [ESPComponent](INFO): console:
[    0.29] MBARI ESP 3G
2018-08-01T04:22:41.885Z,1533097361.885 [ESPComponent](INFO): console:
[    0.39] bio: create slab <bio-0> at 0
2018-08-01T04:22:42.292Z,1533097362.292 [ESPComponent](INFO): console:
[    0.46] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master...
2018-08-01T04:22:42.695Z,1533097362.695 [ESPComponent](INFO): console:
[    0.48] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master...
2018-08-01T04:22:43.105Z,1533097363.105 [ESPComponent](INFO): console:
[    0.50] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master...
2018-08-01T04:22:43.485Z,1533097363.485 [ESPComponent](INFO): console:
[    0.52] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master...
2018-08-01T04:22:43.918Z,1533097363.918 [ESPComponent](INFO): console:
[    0.54] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master...
2018-08-01T04:22:44.300Z,1533097364.300 [ESPComponent](INFO): console:
[    0.56] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master...
2018-08-01T04:22:44.719Z,1533097364.719 [ESPComponent](INFO): console:
[    0.56] NetWinder Floating Point Emulator V0.97 (double precision)
2018-08-01T04:22:45.118Z,1533097365.118 [ESPComponent](INFO): console:
[    0.58] yaffs Jul  6 2018 16:45:28 Installing. 
2018-08-01T04:22:45.491Z,1533097365.491 [ESPComponent](INFO): console:
[    0.72] m25p80 spi0.3: m25p80 found s25sl032a flash
2018-08-01T04:22:45.900Z,1533097365.900 [ESPComponent](INFO): console:
[    2.78] VFS: Mounted root (ext2 filesystem) readonly on device 179:2.
2018-08-01T04:22:46.306Z,1533097366.306 [ESPComponent](INFO): console:

2018-08-01T04:22:46.691Z,1533097366.691 [ESPComponent](INFO): console:INIT: version 2.85 booting
2018-08-01T04:22:46.730Z,1533097366.730 [Radio_Surface](INFO): Powering down
2018-08-01T04:22:47.100Z,1533097367.100 [ESPComponent](INFO): console:

2018-08-01T04:22:47.502Z,1533097367.502 [ESPComponent](INFO): console:MBARI ESP Embedded Linux    http://www.mbari.org   mailto:brent@mbari.org
2018-08-01T04:22:47.894Z,1533097367.894 [ESPComponent](INFO): console:
ESPhonu
2018-08-01T04:22:48.295Z,1533097368.295 [ESPComponent](INFO): console:

2018-08-01T04:22:48.684Z,1533097368.684 [ESPComponent](INFO): console:INIT: Entering runlevel: 3
2018-08-01T04:22:49.104Z,1533097369.104 [ESPComponent](INFO): console:

2018-08-01T04:22:49.507Z,1533097369.507 [ESPComponent](INFO): console:Loading kernel modules
2018-08-01T04:22:49.896Z,1533097369.896 [ESPComponent](INFO): console:
Mounting filesystems and adding swapfiles listed in /etc/fstab
2018-08-01T04:22:50.296Z,1533097370.296 [ESPComponent](INFO): console:
mount: /dev/mmcblk0p2 already mounted or /card busy
2018-08-01T04:22:50.694Z,1533097370.694 [ESPComponent](INFO): console:
Starting hotplug events dispatcher udevd
2018-08-01T04:22:51.088Z,1533097371.088 [ESPComponent](INFO): console:
Set system clock to:  Tue Jul 31 21:16:53 PDT 2018
2018-08-01T04:22:51.490Z,1533097371.490 [ESPComponent](INFO): console:
Starting syslogd klogd...
2018-08-01T04:22:51.890Z,1533097371.890 [ESPComponent](INFO): console:
Bringing up interface lo ...
2018-08-01T04:22:52.291Z,1533097372.291 [ESPComponent](INFO): console:
lo IP=127.0.0.1
2018-08-01T04:22:52.695Z,1533097372.695 [ESPComponent](INFO): console:
Packet forwarding enabled
2018-08-01T04:22:53.095Z,1533097373.095 [ESPComponent](INFO): console:
Bringing up interface eth0 ...
2018-08-01T04:22:53.495Z,1533097373.495 [ESPComponent](INFO): console:
Determining IP configuration for eth0....udhcpc (v1.11.2) started
2018-08-01T04:22:53.884Z,1533097373.884 [ESPComponent](INFO): console:
Sending discover...
2018-08-01T04:22:54.307Z,1533097374.307 [ESPComponent](INFO): console:
No lease, forking to background
2018-08-01T04:22:54.710Z,1533097374.710 [ESPComponent](INFO): console:
Bringing up interface eth0:10 ...
2018-08-01T04:22:55.099Z,1533097375.099 [ESPComponent](INFO): console:
eth0:10 IP=10.10.10.10
2018-08-01T04:22:55.506Z,1533097375.506 [ESPComponent](INFO): console:
Bringing up interface ppp2 ...
2018-08-01T04:22:55.895Z,1533097375.895 [ESPComponent](INFO): console:
Starting portmap...
2018-08-01T04:22:56.292Z,1533097376.292 [ESPComponent](INFO): console:
Network unavailable:  Local time is Tue Jul 31 21:16:59 PDT 2018
2018-08-01T04:22:56.699Z,1533097376.699 [ESPComponent](INFO): console:
Starting thttpd...
2018-08-01T04:22:57.084Z,1533097377.084 [ESPComponent](INFO): console:

2018-08-01T04:22:57.484Z,1533097377.484 [ESPComponent](INFO): console:

2018-08-01T04:22:57.889Z,1533097377.889 [ESPComponent](INFO): console:MBARI ESP Embedded Linux 2.37 -- 7/12/18 brent@mbari.org
2018-08-01T04:22:58.292Z,1533097378.292 [ESPComponent](INFO): console:

2018-08-01T04:22:58.753Z,1533097378.753 [ESPComponent](INFO): console:ESPhonu login: 
2018-08-01T04:23:01.094Z,1533097381.094 [ESPComponent](IMPORTANT): ESP has connected as client
2018-08-01T04:23:01.901Z,1533097381.901 [ESPComponent](IMPORTANT): ESP sampling sequence starting (sample #1)  sampling state: S_WAITING_INITIAL_PROMPT
2018-08-01T04:23:01.902Z,1533097381.902 [ESPComponent](DEBUG): Writing samplingActive=1, sampleNumber=1
2018-08-01T04:23:01.946Z,1533097381.946 [sample:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP] Stopped
2018-08-01T04:23:01.946Z,1533097381.946 [sample:SampleAtDepth:SampleWrapper:SampleESP:B] Running Loop=1
2018-08-01T04:23:02.304Z,1533097382.304 [sample:SampleAtDepth:SampleWrapper:SampleESP:B](IMPORTANT): ESP sampling at 2.000000 m inwater with nan ug/l chlorophyll fluorescence.
2018-08-01T04:23:02.313Z,1533097382.313 [sample:SampleAtDepth:SampleWrapper:SampleESP:B] Stopped
2018-08-01T04:23:02.314Z,1533097382.314 [sample:SampleAtDepth:SampleWrapper:SampleESP:WaitForESP] Running Loop=1
2018-08-01T04:23:02.710Z,1533097382.710 [sample:SampleAtDepth:SampleWrapper:SampleESP:WaitForESP](DEBUG): Initialize ReadDataComponent to sense ESPComponent.sample_number
2018-08-01T04:23:03.095Z,1533097383.095 [ESPComponent](IMPORTANT): ESP sampling state: S_PREPARING_SHOW_LOG
2018-08-01T04:23:03.490Z,1533097383.490 [ESPComponent](IMPORTANT): ESP sampling state: S_PREPARING_SHOW_STATUS
2018-08-01T04:23:05.126Z,1533097385.126 [ESPComponent](IMPORTANT): ESP sampling state: S_LOADING_CARTRIDGE
2018-08-01T04:23:13.054Z,1533097393.054 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:23:19.470Z,1533097399.470 [Radio_Surface](INFO): Powering up
2018-08-01T04:23:25.126Z,1533097405.126 [Radio_Surface](INFO): Powering down
2018-08-01T04:23:43.492Z,1533097423.492 [ESPComponent](IMPORTANT): ESP sampling state: S_FILTERING
2018-08-01T04:23:45.895Z,1533097425.895 [ESPComponent](IMPORTANT): ESP sampling state: S_WAITING_FOR_PAUSED
2018-08-01T04:23:58.265Z,1533097438.265 [Radio_Surface](INFO): Powering up
2018-08-01T04:24:03.930Z,1533097443.930 [Radio_Surface](INFO): Powering down
2018-08-01T04:24:10.658Z,1533097450.658 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-01T04:24:13.454Z,1533097453.454 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:24:35.864Z,1533097475.864 [Radio_Surface](INFO): Powering up
2018-08-01T04:24:41.062Z,1533097481.062 [NAL9602](INFO): Powering down
2018-08-01T04:24:41.518Z,1533097481.518 [Radio_Surface](INFO): Powering down
2018-08-01T04:24:47.854Z,1533097487.854 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.163391
2018-08-01T04:25:13.062Z,1533097513.062 [Radio_Surface](INFO): Powering up
2018-08-01T04:25:18.718Z,1533097518.718 [Radio_Surface](INFO): Powering down
2018-08-01T04:25:53.462Z,1533097553.462 [Radio_Surface](INFO): Powering up
2018-08-01T04:25:59.126Z,1533097559.126 [Radio_Surface](INFO): Powering down
2018-08-01T04:26:14.254Z,1533097574.254 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:26:18.693Z,1533097578.693 [BPC1](ERROR): Failed to receive data from both battery packs
2018-08-01T04:26:18.693Z,1533097578.693 [BPC1] Communications Fault, FailCount= 1
2018-08-01T04:26:18.693Z,1533097578.693 [BPC1](ERROR): Communications Fault
2018-08-01T04:26:18.761Z,1533097578.761 [CBIT](ERROR): Communications Fault in component: BPC1
2018-08-01T04:26:19.937Z,1533097579.937 [CBIT](INFO): Clearing failed state for component BPC1
2018-08-01T04:26:19.938Z,1533097579.938 [BPC1] No Fault, FailCount= 1
2018-08-01T04:26:33.466Z,1533097593.466 [Radio_Surface](INFO): Powering up
2018-08-01T04:26:39.122Z,1533097599.122 [Radio_Surface](INFO): Powering down
2018-08-01T04:27:13.866Z,1533097633.866 [Radio_Surface](INFO): Powering up
2018-08-01T04:27:14.654Z,1533097634.654 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:27:19.523Z,1533097639.523 [Radio_Surface](INFO): Powering down
2018-08-01T04:27:53.466Z,1533097673.466 [Radio_Surface](INFO): Powering up
2018-08-01T04:27:59.126Z,1533097679.126 [Radio_Surface](INFO): Powering down
2018-08-01T04:28:14.654Z,1533097694.654 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:28:31.062Z,1533097711.062 [Radio_Surface](INFO): Powering up
2018-08-01T04:28:36.718Z,1533097716.718 [Radio_Surface](INFO): Powering down
2018-08-01T04:29:07.862Z,1533097747.862 [Radio_Surface](INFO): Powering up
2018-08-01T04:29:13.518Z,1533097753.518 [Radio_Surface](INFO): Powering down
2018-08-01T04:29:14.654Z,1533097754.654 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:29:46.262Z,1533097786.262 [Radio_Surface](INFO): Powering up
2018-08-01T04:29:51.918Z,1533097791.918 [Radio_Surface](INFO): Powering down
2018-08-01T04:30:15.054Z,1533097815.054 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:30:24.660Z,1533097824.660 [Radio_Surface](INFO): Powering up
2018-08-01T04:30:30.314Z,1533097830.314 [Radio_Surface](INFO): Powering down
2018-08-01T04:31:04.266Z,1533097864.266 [Radio_Surface](INFO): Powering up
2018-08-01T04:31:09.922Z,1533097869.922 [Radio_Surface](INFO): Powering down
2018-08-01T04:31:15.454Z,1533097875.454 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:31:43.060Z,1533097903.060 [Radio_Surface](INFO): Powering up
2018-08-01T04:31:48.714Z,1533097908.714 [Radio_Surface](INFO): Powering down
2018-08-01T04:32:15.454Z,1533097935.454 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:32:21.066Z,1533097941.066 [Radio_Surface](INFO): Powering up
2018-08-01T04:32:26.746Z,1533097946.746 [Radio_Surface](INFO): Powering down
2018-08-01T04:32:58.266Z,1533097978.266 [Radio_Surface](INFO): Powering up
2018-08-01T04:33:03.926Z,1533097983.926 [Radio_Surface](INFO): Powering down
2018-08-01T04:33:15.454Z,1533097995.454 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:33:36.666Z,1533098016.666 [Radio_Surface](INFO): Powering up
2018-08-01T04:33:42.326Z,1533098022.326 [Radio_Surface](INFO): Powering down
2018-08-01T04:34:13.462Z,1533098053.462 [Radio_Surface](INFO): Powering up
2018-08-01T04:34:16.254Z,1533098056.254 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:34:19.126Z,1533098059.126 [Radio_Surface](INFO): Powering down
2018-08-01T04:34:51.066Z,1533098091.066 [Radio_Surface](INFO): Powering up
2018-08-01T04:34:56.726Z,1533098096.726 [Radio_Surface](INFO): Powering down
2018-08-01T04:35:15.855Z,1533098115.855 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:35:16.286Z,1533098116.286 [BPC1](ERROR): Failed to receive data from both battery packs
2018-08-01T04:35:16.286Z,1533098116.286 [BPC1] Communications Fault, FailCount= 2
2018-08-01T04:35:16.286Z,1533098116.286 [BPC1](ERROR): Communications Fault
2018-08-01T04:35:16.364Z,1533098116.364 [CBIT](ERROR): Communications Fault in component: BPC1
2018-08-01T04:35:17.548Z,1533098117.548 [CBIT](INFO): Clearing failed state for component BPC1
2018-08-01T04:35:17.549Z,1533098117.549 [BPC1] No Fault, FailCount= 2
2018-08-01T04:35:27.862Z,1533098127.862 [Radio_Surface](INFO): Powering up
2018-08-01T04:35:33.518Z,1533098133.518 [Radio_Surface](INFO): Powering down
2018-08-01T04:36:06.262Z,1533098166.262 [Radio_Surface](INFO): Powering up
2018-08-01T04:36:11.918Z,1533098171.918 [Radio_Surface](INFO): Powering down
2018-08-01T04:36:16.254Z,1533098176.254 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:36:46.662Z,1533098206.662 [Radio_Surface](INFO): Powering up
2018-08-01T04:36:52.326Z,1533098212.326 [Radio_Surface](INFO): Powering down
2018-08-01T04:37:16.654Z,1533098236.654 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:37:25.062Z,1533098245.062 [Radio_Surface](INFO): Powering up
2018-08-01T04:37:31.122Z,1533098251.122 [Radio_Surface](INFO): Powering down
2018-08-01T04:38:05.462Z,1533098285.462 [Radio_Surface](INFO): Powering up
2018-08-01T04:38:11.118Z,1533098291.118 [Radio_Surface](INFO): Powering down
2018-08-01T04:38:17.054Z,1533098297.054 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:38:46.266Z,1533098326.266 [Radio_Surface](INFO): Powering up
2018-08-01T04:38:51.946Z,1533098331.946 [Radio_Surface](INFO): Powering down
2018-08-01T04:39:17.454Z,1533098357.454 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:39:22.660Z,1533098362.660 [Radio_Surface](INFO): Powering up
2018-08-01T04:39:28.314Z,1533098368.314 [Radio_Surface](INFO): Powering down
2018-08-01T04:40:03.466Z,1533098403.466 [Radio_Surface](INFO): Powering up
2018-08-01T04:40:09.122Z,1533098409.122 [Radio_Surface](INFO): Powering down
2018-08-01T04:40:17.854Z,1533098417.854 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:40:39.860Z,1533098439.860 [Radio_Surface](INFO): Powering up
2018-08-01T04:40:45.514Z,1533098445.514 [Radio_Surface](INFO): Powering down
2018-08-01T04:41:17.854Z,1533098477.854 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:41:17.862Z,1533098477.862 [Radio_Surface](INFO): Powering up
2018-08-01T04:41:23.534Z,1533098483.534 [Radio_Surface](INFO): Powering down
2018-08-01T04:41:53.862Z,1533098513.862 [Radio_Surface](INFO): Powering up
2018-08-01T04:41:59.518Z,1533098519.518 [Radio_Surface](INFO): Powering down
2018-08-01T04:42:18.254Z,1533098538.254 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:42:31.062Z,1533098551.062 [Radio_Surface](INFO): Powering up
2018-08-01T04:42:36.719Z,1533098556.719 [Radio_Surface](INFO): Powering down
2018-08-01T04:43:07.866Z,1533098587.866 [Radio_Surface](INFO): Powering up
2018-08-01T04:43:13.522Z,1533098593.522 [Radio_Surface](INFO): Powering down
2018-08-01T04:43:18.655Z,1533098598.655 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:43:46.266Z,1533098626.266 [Radio_Surface](INFO): Powering up
2018-08-01T04:43:51.922Z,1533098631.922 [Radio_Surface](INFO): Powering down
2018-08-01T04:44:19.054Z,1533098659.054 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:44:24.262Z,1533098664.262 [Radio_Surface](INFO): Powering up
2018-08-01T04:44:29.922Z,1533098669.922 [Radio_Surface](INFO): Powering down
2018-08-01T04:45:02.260Z,1533098702.260 [Radio_Surface](INFO): Powering up
2018-08-01T04:45:07.914Z,1533098707.914 [Radio_Surface](INFO): Powering down
2018-08-01T04:45:19.054Z,1533098719.054 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:45:41.462Z,1533098741.462 [Radio_Surface](INFO): Powering up
2018-08-01T04:45:47.118Z,1533098747.118 [Radio_Surface](INFO): Powering down
2018-08-01T04:45:50.697Z,1533098750.697 [BPC1](ERROR): Failed to receive data from both battery packs
2018-08-01T04:45:50.697Z,1533098750.697 [BPC1] Communications Fault, FailCount= 3
2018-08-01T04:45:50.697Z,1533098750.697 [BPC1](ERROR): Communications Fault
2018-08-01T04:45:50.726Z,1533098750.726 [CBIT](ERROR): Communications Fault in component: BPC1
2018-08-01T04:45:51.922Z,1533098751.922 [CBIT](INFO): Clearing failed state for component BPC1
2018-08-01T04:45:51.922Z,1533098751.922 [BPC1] No Fault, FailCount= 3
2018-08-01T04:46:18.662Z,1533098778.662 [Radio_Surface](INFO): Powering up
2018-08-01T04:46:19.054Z,1533098779.054 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:46:24.318Z,1533098784.318 [Radio_Surface](INFO): Powering down
2018-08-01T04:46:51.558Z,1533098811.558 [CommandLine](IMPORTANT): got command show stack
2018-08-01T04:46:51.558Z,1533098811.558 [CommandLine](IMPORTANT): Behavior Stack:

2018-08-01T04:46:51.558Z,1533098811.558 [sample](IMPORTANT): Priority 0: sample:A.Pitch
2018-08-01T04:46:51.558Z,1533098811.558 [sample](IMPORTANT): Priority 1: sample:B.SetSpeed
2018-08-01T04:46:51.559Z,1533098811.559 [sample:SampleAtDepth](IMPORTANT): Priority 2: sample:SampleAtDepth:B.Pitch
2018-08-01T04:46:51.559Z,1533098811.559 [sample:SampleAtDepth:SampleWrapper:SampleESP](IMPORTANT): Priority 3: sample:SampleAtDepth:SampleWrapper:SampleESP:WaitForESP
2018-08-01T04:46:55.062Z,1533098815.062 [Radio_Surface](INFO): Powering up
2018-08-01T04:47:00.718Z,1533098820.718 [Radio_Surface](INFO): Powering down
2018-08-01T04:47:19.454Z,1533098839.454 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:47:31.862Z,1533098851.862 [Radio_Surface](INFO): Powering up
2018-08-01T04:47:37.522Z,1533098857.522 [Radio_Surface](INFO): Powering down
2018-08-01T04:48:07.862Z,1533098887.862 [Radio_Surface](INFO): Powering up
2018-08-01T04:48:13.518Z,1533098893.518 [Radio_Surface](INFO): Powering down
2018-08-01T04:48:19.456Z,1533098899.456 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:48:47.062Z,1533098927.062 [Radio_Surface](INFO): Powering up
2018-08-01T04:48:52.719Z,1533098932.719 [Radio_Surface](INFO): Powering down
2018-08-01T04:49:19.454Z,1533098959.454 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:49:26.662Z,1533098966.662 [Radio_Surface](INFO): Powering up
2018-08-01T04:49:32.318Z,1533098972.318 [Radio_Surface](INFO): Powering down
2018-08-01T04:50:03.066Z,1533099003.066 [Radio_Surface](INFO): Powering up
2018-08-01T04:50:08.726Z,1533099008.726 [Radio_Surface](INFO): Powering down
2018-08-01T04:50:19.855Z,1533099019.855 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:50:42.662Z,1533099042.662 [Radio_Surface](INFO): Powering up
2018-08-01T04:50:48.318Z,1533099048.318 [Radio_Surface](INFO): Powering down
2018-08-01T04:51:20.254Z,1533099080.254 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:51:20.260Z,1533099080.260 [Radio_Surface](INFO): Powering up
2018-08-01T04:51:25.914Z,1533099085.914 [Radio_Surface](INFO): Powering down
2018-08-01T04:51:59.868Z,1533099119.868 [Radio_Surface](INFO): Powering up
2018-08-01T04:52:05.522Z,1533099125.522 [Radio_Surface](INFO): Powering down
2018-08-01T04:52:20.255Z,1533099140.255 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:52:37.064Z,1533099157.064 [Radio_Surface](INFO): Powering up
2018-08-01T04:52:42.722Z,1533099162.722 [Radio_Surface](INFO): Powering down
2018-08-01T04:53:15.462Z,1533099195.462 [Radio_Surface](INFO): Powering up
2018-08-01T04:53:21.054Z,1533099201.054 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:53:21.118Z,1533099201.118 [Radio_Surface](INFO): Powering down
2018-08-01T04:53:56.266Z,1533099236.266 [Radio_Surface](INFO): Powering up
2018-08-01T04:54:01.930Z,1533099241.930 [Radio_Surface](INFO): Powering down
2018-08-01T04:54:21.054Z,1533099261.054 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:54:35.462Z,1533099275.462 [Radio_Surface](INFO): Powering up
2018-08-01T04:54:41.118Z,1533099281.118 [Radio_Surface](INFO): Powering down
2018-08-01T04:55:14.662Z,1533099314.662 [Radio_Surface](INFO): Powering up
2018-08-01T04:55:20.322Z,1533099320.322 [Radio_Surface](INFO): Powering down
2018-08-01T04:55:21.454Z,1533099321.454 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:55:51.862Z,1533099351.862 [Radio_Surface](INFO): Powering up
2018-08-01T04:55:57.518Z,1533099357.518 [Radio_Surface](INFO): Powering down
2018-08-01T04:56:21.854Z,1533099381.854 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:56:30.262Z,1533099390.262 [Radio_Surface](INFO): Powering up
2018-08-01T04:56:35.918Z,1533099395.918 [Radio_Surface](INFO): Powering down
2018-08-01T04:57:08.262Z,1533099428.262 [Radio_Surface](INFO): Powering up
2018-08-01T04:57:13.934Z,1533099433.934 [Radio_Surface](INFO): Powering down
2018-08-01T04:57:22.254Z,1533099442.254 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:57:46.266Z,1533099466.266 [Radio_Surface](INFO): Powering up
2018-08-01T04:57:51.926Z,1533099471.926 [Radio_Surface](INFO): Powering down
2018-08-01T04:58:22.254Z,1533099502.254 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:58:23.862Z,1533099503.862 [Radio_Surface](INFO): Powering up
2018-08-01T04:58:29.526Z,1533099509.526 [Radio_Surface](INFO): Powering down
2018-08-01T04:59:02.262Z,1533099542.262 [Radio_Surface](INFO): Powering up
2018-08-01T04:59:07.922Z,1533099547.922 [Radio_Surface](INFO): Powering down
2018-08-01T04:59:17.490Z,1533099557.490 [BPC1](ERROR): Failed to receive data from both battery packs
2018-08-01T04:59:17.490Z,1533099557.490 [BPC1] Communications Fault, FailCount= 4
2018-08-01T04:59:17.490Z,1533099557.490 [BPC1](ERROR): Communications Fault
2018-08-01T04:59:17.518Z,1533099557.518 [CBIT](ERROR): Communications Fault in component: BPC1
2018-08-01T04:59:18.722Z,1533099558.722 [CBIT](INFO): Clearing failed state for component BPC1
2018-08-01T04:59:18.722Z,1533099558.722 [BPC1] No Fault, FailCount= 4
2018-08-01T04:59:22.654Z,1533099562.654 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T04:59:39.066Z,1533099579.066 [Radio_Surface](INFO): Powering up
2018-08-01T04:59:44.722Z,1533099584.722 [Radio_Surface](INFO): Powering down
2018-08-01T05:00:17.462Z,1533099617.462 [Radio_Surface](INFO): Powering up
2018-08-01T05:00:22.654Z,1533099622.654 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:00:23.118Z,1533099623.118 [Radio_Surface](INFO): Powering down
2018-08-01T05:00:57.062Z,1533099657.062 [Radio_Surface](INFO): Powering up
2018-08-01T05:01:02.726Z,1533099662.726 [Radio_Surface](INFO): Powering down
2018-08-01T05:01:23.454Z,1533099683.454 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:01:36.662Z,1533099696.662 [Radio_Surface](INFO): Powering up
2018-08-01T05:01:42.318Z,1533099702.318 [Radio_Surface](INFO): Powering down
2018-08-01T05:02:13.462Z,1533099733.462 [Radio_Surface](INFO): Powering up
2018-08-01T05:02:19.118Z,1533099739.118 [Radio_Surface](INFO): Powering down
2018-08-01T05:02:23.854Z,1533099743.854 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:02:53.466Z,1533099773.466 [Radio_Surface](INFO): Powering up
2018-08-01T05:02:59.122Z,1533099779.122 [Radio_Surface](INFO): Powering down
2018-08-01T05:03:23.854Z,1533099803.854 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:03:30.666Z,1533099810.666 [Radio_Surface](INFO): Powering up
2018-08-01T05:03:36.322Z,1533099816.322 [Radio_Surface](INFO): Powering down
2018-08-01T05:04:10.266Z,1533099850.266 [Radio_Surface](INFO): Powering up
2018-08-01T05:04:15.922Z,1533099855.922 [Radio_Surface](INFO): Powering down
2018-08-01T05:04:24.254Z,1533099864.254 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:04:46.660Z,1533099886.660 [Radio_Surface](INFO): Powering up
2018-08-01T05:04:52.322Z,1533099892.322 [Radio_Surface](INFO): Powering down
2018-08-01T05:05:23.462Z,1533099923.462 [Radio_Surface](INFO): Powering up
2018-08-01T05:05:24.255Z,1533099924.255 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:05:29.122Z,1533099929.122 [Radio_Surface](INFO): Powering down
2018-08-01T05:06:01.468Z,1533099961.468 [Radio_Surface](INFO): Powering up
2018-08-01T05:06:07.126Z,1533099967.126 [Radio_Surface](INFO): Powering down
2018-08-01T05:06:25.054Z,1533099985.054 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:06:40.666Z,1533100000.666 [Radio_Surface](INFO): Powering up
2018-08-01T05:06:46.330Z,1533100006.330 [Radio_Surface](INFO): Powering down
2018-08-01T05:07:18.262Z,1533100038.262 [Radio_Surface](INFO): Powering up
2018-08-01T05:07:23.922Z,1533100043.922 [Radio_Surface](INFO): Powering down
2018-08-01T05:07:25.054Z,1533100045.054 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:07:58.262Z,1533100078.262 [Radio_Surface](INFO): Powering up
2018-08-01T05:08:03.918Z,1533100083.918 [Radio_Surface](INFO): Powering down
2018-08-01T05:08:25.054Z,1533100105.054 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:08:35.062Z,1533100115.062 [Radio_Surface](INFO): Powering up
2018-08-01T05:08:40.718Z,1533100120.718 [Radio_Surface](INFO): Powering down
2018-08-01T05:09:13.462Z,1533100153.462 [Radio_Surface](INFO): Powering up
2018-08-01T05:09:19.138Z,1533100159.138 [Radio_Surface](INFO): Powering down
2018-08-01T05:09:25.854Z,1533100165.854 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:09:51.466Z,1533100191.466 [Radio_Surface](INFO): Powering up
2018-08-01T05:09:57.142Z,1533100197.142 [Radio_Surface](INFO): Powering down
2018-08-01T05:10:26.254Z,1533100226.254 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:10:28.260Z,1533100228.260 [Radio_Surface](INFO): Powering up
2018-08-01T05:10:33.914Z,1533100233.914 [Radio_Surface](INFO): Powering down
2018-08-01T05:11:06.665Z,1533100266.665 [Radio_Surface](INFO): Powering up
2018-08-01T05:11:12.322Z,1533100272.322 [Radio_Surface](INFO): Powering down
2018-08-01T05:11:26.254Z,1533100286.254 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:11:44.659Z,1533100304.659 [Radio_Surface](INFO): Powering up
2018-08-01T05:11:50.322Z,1533100310.322 [Radio_Surface](INFO): Powering down
2018-08-01T05:12:21.462Z,1533100341.462 [Radio_Surface](INFO): Powering up
2018-08-01T05:12:26.654Z,1533100346.654 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:12:27.118Z,1533100347.118 [Radio_Surface](INFO): Powering down
2018-08-01T05:12:43.893Z,1533100363.893 [BPC1](ERROR): Failed to receive data from both battery packs
2018-08-01T05:12:43.893Z,1533100363.893 [BPC1] Communications Fault, FailCount= 5
2018-08-01T05:12:43.893Z,1533100363.893 [BPC1](ERROR): Communications Fault
2018-08-01T05:12:43.922Z,1533100363.922 [CBIT](ERROR): Communications Fault in component: BPC1
2018-08-01T05:12:45.125Z,1533100365.125 [CBIT](INFO): Clearing failed state for component BPC1
2018-08-01T05:12:45.125Z,1533100365.125 [BPC1] No Fault, FailCount= 5
2018-08-01T05:12:58.662Z,1533100378.662 [Radio_Surface](INFO): Powering up
2018-08-01T05:13:04.318Z,1533100384.318 [Radio_Surface](INFO): Powering down
2018-08-01T05:13:26.654Z,1533100406.654 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:13:37.462Z,1533100417.462 [Radio_Surface](INFO): Powering up
2018-08-01T05:13:43.118Z,1533100423.118 [Radio_Surface](INFO): Powering down
2018-08-01T05:14:16.662Z,1533100456.662 [Radio_Surface](INFO): Powering up
2018-08-01T05:14:22.318Z,1533100462.318 [Radio_Surface](INFO): Powering down
2018-08-01T05:14:26.654Z,1533100466.654 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:14:56.262Z,1533100496.262 [Radio_Surface](INFO): Powering up
2018-08-01T05:15:01.926Z,1533100501.926 [Radio_Surface](INFO): Powering down
2018-08-01T05:15:27.054Z,1533100527.054 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:15:34.660Z,1533100534.660 [Radio_Surface](INFO): Powering up
2018-08-01T05:15:40.318Z,1533100540.318 [Radio_Surface](INFO): Powering down
2018-08-01T05:16:12.662Z,1533100572.662 [Radio_Surface](INFO): Powering up
2018-08-01T05:16:18.318Z,1533100578.318 [Radio_Surface](INFO): Powering down
2018-08-01T05:16:27.454Z,1533100587.454 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:16:49.866Z,1533100609.866 [Radio_Surface](INFO): Powering up
2018-08-01T05:16:55.522Z,1533100615.522 [Radio_Surface](INFO): Powering down
2018-08-01T05:17:27.062Z,1533100647.062 [Radio_Surface](INFO): Powering up
2018-08-01T05:17:27.854Z,1533100647.854 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:17:32.726Z,1533100652.726 [Radio_Surface](INFO): Powering down
2018-08-01T05:18:06.662Z,1533100686.662 [Radio_Surface](INFO): Powering up
2018-08-01T05:18:12.318Z,1533100692.318 [Radio_Surface](INFO): Powering down
2018-08-01T05:18:12.686Z,1533100692.686 [BPC1](ERROR): Bank A: No match for stick 3 serial number:1717 in the onboard configuration file.
2018-08-01T05:18:12.686Z,1533100692.686 [BPC1](ERROR): Failed to parse Bank A battery data
2018-08-01T05:18:27.854Z,1533100707.854 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:18:46.262Z,1533100726.262 [Radio_Surface](INFO): Powering up
2018-08-01T05:18:51.930Z,1533100731.930 [Radio_Surface](INFO): Powering down
2018-08-01T05:19:24.662Z,1533100764.662 [Radio_Surface](INFO): Powering up
2018-08-01T05:19:28.254Z,1533100768.254 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:19:30.722Z,1533100770.722 [Radio_Surface](INFO): Powering down
2018-08-01T05:19:33.883Z,1533100773.883 [ESPComponent](IMPORTANT): ESP sampling state: S_PROCESSING
2018-08-01T05:19:36.291Z,1533100776.291 [ESPComponent](IMPORTANT): ESP sampling state: S_WAITING_FOR_PROCESSED
2018-08-01T05:20:04.266Z,1533100804.266 [Radio_Surface](INFO): Powering up
2018-08-01T05:20:09.922Z,1533100809.922 [Radio_Surface](INFO): Powering down
2018-08-01T05:20:29.054Z,1533100829.054 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:20:43.462Z,1533100843.462 [Radio_Surface](INFO): Powering up
2018-08-01T05:20:49.118Z,1533100849.118 [Radio_Surface](INFO): Powering down
2018-08-01T05:21:21.862Z,1533100881.862 [Radio_Surface](INFO): Powering up
2018-08-01T05:21:27.518Z,1533100887.518 [Radio_Surface](INFO): Powering down
2018-08-01T05:21:29.054Z,1533100889.054 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:22:00.262Z,1533100920.262 [Radio_Surface](INFO): Powering up
2018-08-01T05:22:05.918Z,1533100925.918 [Radio_Surface](INFO): Powering down
2018-08-01T05:22:29.457Z,1533100949.457 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:22:39.866Z,1533100959.866 [Radio_Surface](INFO): Powering up
2018-08-01T05:22:45.526Z,1533100965.526 [Radio_Surface](INFO): Powering down
2018-08-01T05:23:16.266Z,1533100996.266 [Radio_Surface](INFO): Powering up
2018-08-01T05:23:21.922Z,1533101001.922 [Radio_Surface](INFO): Powering down
2018-08-01T05:23:29.854Z,1533101009.854 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:23:52.260Z,1533101032.260 [Radio_Surface](INFO): Powering up
2018-08-01T05:23:57.914Z,1533101037.914 [Radio_Surface](INFO): Powering down
2018-08-01T05:24:30.254Z,1533101070.254 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:24:32.262Z,1533101072.262 [Radio_Surface](INFO): Powering up
2018-08-01T05:24:37.918Z,1533101077.918 [Radio_Surface](INFO): Powering down
2018-08-01T05:25:12.262Z,1533101112.262 [Radio_Surface](INFO): Powering up
2018-08-01T05:25:12.302Z,1533101112.302 [BPC1](ERROR): Failed to receive data from both battery packs
2018-08-01T05:25:12.302Z,1533101112.302 [BPC1] Communications Fault, FailCount= 6
2018-08-01T05:25:12.302Z,1533101112.302 [BPC1](ERROR): Communications Fault
2018-08-01T05:25:12.350Z,1533101112.350 [CBIT](ERROR): Communications Fault in component: BPC1
2018-08-01T05:25:13.526Z,1533101113.526 [CBIT](INFO): Clearing failed state for component BPC1
2018-08-01T05:25:13.526Z,1533101113.526 [BPC1] No Fault, FailCount= 6
2018-08-01T05:25:17.918Z,1533101117.918 [Radio_Surface](INFO): Powering down
2018-08-01T05:25:30.254Z,1533101130.254 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:25:52.662Z,1533101152.662 [Radio_Surface](INFO): Powering up
2018-08-01T05:25:58.318Z,1533101158.318 [Radio_Surface](INFO): Powering down
2018-08-01T05:26:31.055Z,1533101191.055 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:26:32.262Z,1533101192.262 [Radio_Surface](INFO): Powering up
2018-08-01T05:26:37.918Z,1533101197.918 [Radio_Surface](INFO): Powering down
2018-08-01T05:27:12.267Z,1533101232.267 [Radio_Surface](INFO): Powering up
2018-08-01T05:27:17.926Z,1533101237.926 [Radio_Surface](INFO): Powering down
2018-08-01T05:27:31.054Z,1533101251.054 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:27:52.266Z,1533101272.266 [Radio_Surface](INFO): Powering up
2018-08-01T05:27:57.922Z,1533101277.922 [Radio_Surface](INFO): Powering down
2018-08-01T05:28:31.054Z,1533101311.054 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:28:31.469Z,1533101311.469 [Radio_Surface](INFO): Powering up
2018-08-01T05:28:37.138Z,1533101317.138 [Radio_Surface](INFO): Powering down
2018-08-01T05:29:10.266Z,1533101350.266 [Radio_Surface](INFO): Powering up
2018-08-01T05:29:15.930Z,1533101355.930 [Radio_Surface](INFO): Powering down
2018-08-01T05:29:31.054Z,1533101371.054 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:29:47.867Z,1533101387.867 [Radio_Surface](INFO): Powering up
2018-08-01T05:29:53.522Z,1533101393.522 [Radio_Surface](INFO): Powering down
2018-08-01T05:30:26.266Z,1533101426.266 [Radio_Surface](INFO): Powering up
2018-08-01T05:30:31.454Z,1533101431.454 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:30:31.922Z,1533101431.922 [Radio_Surface](INFO): Powering down
2018-08-01T05:31:02.298Z,1533101462.298 [ESPComponent](IMPORTANT): ESP sampling state: S_STOPPING
2018-08-01T05:31:05.870Z,1533101465.870 [Radio_Surface](INFO): Powering up
2018-08-01T05:31:11.526Z,1533101471.526 [Radio_Surface](INFO): Powering down
2018-08-01T05:31:28.698Z,1533101488.698 [ESPComponent](IMPORTANT): ESP sampling sequence completed normally (sample #1)
2018-08-01T05:31:28.698Z,1533101488.698 [ESPComponent](DEBUG): Writing samplingActive=0, sampleNumber=1
2018-08-01T05:31:28.713Z,1533101488.713 [sample:SampleAtDepth:SampleWrapper:SampleESP:WaitForESP] Stopped
2018-08-01T05:31:28.714Z,1533101488.714 [sample:SampleAtDepth:SampleWrapper:SampleESP](INFO): Completed sample:SampleAtDepth:SampleWrapper:SampleESP
2018-08-01T05:31:28.714Z,1533101488.714 [sample:SampleAtDepth:SampleWrapper:SampleESP] Stopped
2018-08-01T05:31:28.714Z,1533101488.714 [sample:SampleAtDepth:SampleWrapper:SampleESP](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper:SampleESP
2018-08-01T05:31:28.714Z,1533101488.714 [sample:SampleAtDepth:SampleWrapper](INFO): Completed sample:SampleAtDepth:SampleWrapper
2018-08-01T05:31:28.714Z,1533101488.714 [sample:SampleAtDepth:SampleWrapper] Stopped
2018-08-01T05:31:28.714Z,1533101488.714 [sample:SampleAtDepth:SampleWrapper](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper
2018-08-01T05:31:28.715Z,1533101488.715 [sample:SampleAtDepth](INFO): Completed sample:SampleAtDepth
2018-08-01T05:31:28.715Z,1533101488.715 [sample:SampleAtDepth] Stopped
2018-08-01T05:31:28.715Z,1533101488.715 [sample:SampleAtDepth](DEBUG): Aggregate::uninitialize sample:SampleAtDepth
2018-08-01T05:31:28.716Z,1533101488.716 [sample:SampleAtDepth:B.Pitch] Stopped
2018-08-01T05:31:29.106Z,1533101489.106 [ESPComponent](IMPORTANT): No ESP summary messages.
2018-08-01T05:31:29.106Z,1533101489.106 [ESPComponent](INFO): powering down ESP
2018-08-01T05:31:29.252Z,1533101489.252 [sample:SampleRepeater:Sample](INFO): Completed sample:SampleRepeater:Sample
2018-08-01T05:31:29.252Z,1533101489.252 [sample:SampleRepeater:Sample] Stopped
2018-08-01T05:31:29.252Z,1533101489.252 [sample:SampleRepeater:Sample](DEBUG): Aggregate::uninitialize sample:SampleRepeater:Sample
2018-08-01T05:31:29.252Z,1533101489.252 [sample:SampleRepeater](INFO): Completed sample:SampleRepeater
2018-08-01T05:31:29.252Z,1533101489.252 [sample:SampleRepeater] Stopped
2018-08-01T05:31:29.253Z,1533101489.253 [sample:SampleRepeater](DEBUG): Aggregate::uninitialize sample:SampleRepeater
2018-08-01T05:31:29.253Z,1533101489.253 [sample:SampleRepeater](INFO): Running loop #2
2018-08-01T05:31:29.253Z,1533101489.253 [sample:SampleRepeater] Running Loop=2
2018-08-01T05:31:29.253Z,1533101489.253 [sample:SampleRepeater](DEBUG): Aggregate::initialize sample:SampleRepeater
2018-08-01T05:31:29.253Z,1533101489.253 [sample:SampleRepeater:Sample] Running Loop=1
2018-08-01T05:31:29.254Z,1533101489.254 [sample:SampleRepeater:Sample](DEBUG): Aggregate::initialize sample:SampleRepeater:Sample
2018-08-01T05:31:29.521Z,1533101489.521 [sample:SampleAtDepth] Running Loop=1
2018-08-01T05:31:29.521Z,1533101489.521 [sample:SampleAtDepth](DEBUG): Aggregate::initialize sample:SampleAtDepth
2018-08-01T05:31:29.522Z,1533101489.522 [sample:SampleAtDepth:B.Pitch] Running Loop=1
2018-08-01T05:31:29.522Z,1533101489.522 [sample:SampleAtDepth:B.Pitch](DEBUG): Initialize.
2018-08-01T05:31:29.522Z,1533101489.522 [sample:SampleAtDepth:A] Running Loop=1
2018-08-01T05:31:29.523Z,1533101489.523 [sample:SampleAtDepth:A](INFO): Moving to 2.000000 m 
2018-08-01T05:31:29.524Z,1533101489.524 [sample:SampleAtDepth:A] Stopped
2018-08-01T05:31:29.917Z,1533101489.917 [sample:SampleAtDepth:C] Running Loop=1
2018-08-01T05:31:30.316Z,1533101490.316 [sample:SampleAtDepth:C](INFO): At 2.000000 m , settling for 0.050000 min 
2018-08-01T05:31:30.316Z,1533101490.316 [sample:SampleAtDepth:C] Stopped
2018-08-01T05:31:30.316Z,1533101490.316 [sample:SampleAtDepth:D.Wait] Running Loop=1
2018-08-01T05:31:30.316Z,1533101490.316 [sample:SampleAtDepth:D.Wait](DEBUG): Initialize Wait Component.
2018-08-01T05:31:31.855Z,1533101491.855 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:31:33.909Z,1533101493.909 [sample:SampleAtDepth:D.Wait](INFO): Done Waiting.
2018-08-01T05:31:33.909Z,1533101493.909 [sample:SampleAtDepth:D.Wait] Stopped
2018-08-01T05:31:33.909Z,1533101493.909 [sample:SampleAtDepth:D.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T05:31:33.909Z,1533101493.909 [sample:SampleAtDepth:SampleWrapper] Running Loop=1
2018-08-01T05:31:33.910Z,1533101493.910 [sample:SampleAtDepth:SampleWrapper](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper
2018-08-01T05:31:33.910Z,1533101493.910 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler] Running Loop=1
2018-08-01T05:31:33.910Z,1533101493.910 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper:SampleCANONSampler
2018-08-01T05:31:33.910Z,1533101493.910 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:A] Running Loop=1
2018-08-01T05:31:33.910Z,1533101493.910 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:B] Running Loop=1
2018-08-01T05:31:33.910Z,1533101493.910 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler] Running Loop=1
2018-08-01T05:31:34.318Z,1533101494.318 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler] Stopped
2018-08-01T05:31:34.318Z,1533101494.318 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper:SampleCANONSampler
2018-08-01T05:31:34.318Z,1533101494.318 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:A] Stopped
2018-08-01T05:31:34.318Z,1533101494.318 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:B] Stopped
2018-08-01T05:31:34.319Z,1533101494.319 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler] Stopped
2018-08-01T05:31:34.319Z,1533101494.319 [sample:SampleAtDepth:SampleWrapper:SampleESP] Running Loop=1
2018-08-01T05:31:34.319Z,1533101494.319 [sample:SampleAtDepth:SampleWrapper:SampleESP](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper:SampleESP
2018-08-01T05:31:34.319Z,1533101494.319 [sample:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP] Running Loop=1
2018-08-01T05:31:35.966Z,1533101495.966 [ESPComponent](INFO): powering up ESP
2018-08-01T05:31:35.966Z,1533101495.966 [ESPComponent](INFO): manually powering up ESP
2018-08-01T05:31:35.968Z,1533101495.968 [ESPComponent](IMPORTANT): Powered ESP with command: ! echo 1 > /dev/loadA6
2018-08-01T05:31:35.969Z,1533101495.969 [ESPComponent](IMPORTANT): Starting PPPD with command:/sbin/pppd xonxoff asyncmap A0000 /dev/ttyTX1 linkname esp noauth local lock 115200 10.89.5.2:10.89.5.3 persist maxfail 0 holdoff 10 lcp-echo-interval 60 lcp-echo-failure 3 proxyarp ktune deflate 12 ms-dns 8.8.8.8
2018-08-01T05:31:36.014Z,1533101496.014 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadA6
2018-08-01T05:31:36.134Z,1533101496.134 [ESPComponent](IMPORTANT): Waiting for ESP to connect (timeout=150.0000)
2018-08-01T05:31:36.377Z,1533101496.377 [ESPComponent](INFO): console:
2018-08-01T05:31:37.499Z,1533101497.499 [ESPComponent](INFO): console:

2018-08-01T05:31:37.898Z,1533101497.898 [ESPComponent](INFO): console:NAND:  256 MiB
2018-08-01T05:31:38.298Z,1533101498.298 [ESPComponent](INFO): console:
BOOTMODE: SPI
2018-08-01T05:31:38.773Z,1533101498.773 [ESPComponent](INFO): console:
reading SPI NOR..
2018-08-01T05:31:39.891Z,1533101499.891 [ESPComponent](INFO): console:Done
2018-08-01T05:31:40.289Z,1533101500.289 [ESPComponent](INFO): console:

2018-08-01T05:31:40.708Z,1533101500.708 [ESPComponent](INFO): console:

2018-08-01T05:31:41.094Z,1533101501.094 [ESPComponent](INFO): console:
U-Boot 2009.11-mbariB (Dec 07 2017 - 19:07:59)
2018-08-01T05:31:41.491Z,1533101501.491 [ESPComponent](INFO): console:

2018-08-01T05:31:41.894Z,1533101501.894 [ESPComponent](INFO): console:
MBARI LPC31xx ESP 3G
2018-08-01T05:31:42.317Z,1533101502.317 [ESPComponent](INFO): console:
flash params are already written into flash
2018-08-01T05:31:42.702Z,1533101502.703 [ESPComponent](INFO): console:
DRAM:  64 MB
2018-08-01T05:31:43.095Z,1533101503.095 [ESPComponent](INFO): console:
In:    serial
2018-08-01T05:31:43.523Z,1533101503.523 [ESPComponent](INFO): console:
Out:   serial
2018-08-01T05:31:43.874Z,1533101503.874 [Radio_Surface](INFO): Powering up
2018-08-01T05:31:43.908Z,1533101503.908 [ESPComponent](INFO): console:
Err:   serial
2018-08-01T05:31:44.296Z,1533101504.296 [ESPComponent](INFO): console:
Net:   ks8851_mll
2018-08-01T05:31:44.698Z,1533101504.698 [ESPComponent](INFO): console:
Hit <ctrl-C> to stop autoboot:  1  0 
2018-08-01T05:31:45.098Z,1533101505.098 [ESPComponent](INFO): console:
mmc1 is available
2018-08-01T05:31:45.508Z,1533101505.508 [ESPComponent](INFO): console:
reading uImage
2018-08-01T05:31:45.894Z,1533101505.894 [ESPComponent](INFO): console:

2018-08-01T05:31:46.300Z,1533101506.300 [ESPComponent](INFO): console:
1681208 bytes read
2018-08-01T05:31:46.692Z,1533101506.692 [ESPComponent](INFO): console:
## Booting kernel from Legacy Image at 31000000 ...
2018-08-01T05:31:47.107Z,1533101507.107 [ESPComponent](INFO): console:
   Image Name:   Linux-2.6.33mbari6
2018-08-01T05:31:47.492Z,1533101507.492 [ESPComponent](INFO): console:
   Imag  ARM Linux Kernel Image (uncompressed)
2018-08-01T05:31:47.888Z,1533101507.888 [ESPComponent](INFO): console:
   Data Size:    1681144 Bytes =  1.6 MB
2018-08-01T05:31:48.291Z,1533101508.291 [ESPComponent](INFO): console:
   Load Address: 3

2018-08-01T05:31:48.690Z,1533101508.690 [ESPComponent](INFO): console:   Entry 30008000
2018-08-01T05:31:49.091Z,1533101509.091 [ESPComponent](INFO): console:
   Verifying Checksum ... OK
2018-08-01T05:31:49.490Z,1533101509.490 [ESPComponent](INFO): console:
   Loading Kernel Image ... OK
2018-08-01T05:31:49.530Z,1533101509.530 [Radio_Surface](INFO): Powering down
2018-08-01T05:31:49.896Z,1533101509.896 [ESPComponent](INFO): console:
OK
2018-08-01T05:31:50.302Z,1533101510.302 [ESPComponent](INFO): console:

2018-08-01T05:31:50.693Z,1533101510.693 [ESPComponent](INFO): console:
Starting kernel ...
2018-08-01T05:31:51.095Z,1533101511.095 [ESPComponent](INFO): console:

2018-08-01T05:31:51.502Z,1533101511.502 [ESPComponent](INFO): console:
Uncompressing Linux... done, booting the kernel.
2018-08-01T05:31:51.899Z,1533101511.899 [ESPComponent](INFO): console:
[    U: ARM926EJ-S [41069265] revision 5 (ARMv5TEJ), cr=00053177
2018-08-01T05:31:52.288Z,1533101512.288 [ESPComponent](INFO): console:
[    0.00] CPU: VIVT data cache, VIVT instruction cache
2018-08-01T05:31:52.688Z,1533101512.688 [ESPComponent](INFO): console:
[    0.00] Machine: NXP EA313X
2018-08-01T05:31:53.089Z,1533101513.089 [ESPComponent](INFO): console:
[    0.00] Memory policy: ECC disabled, Data cache writeback
2018-08-01T05:31:53.488Z,1533101513.488 [ESPComponent](INFO): console:
[    0.00] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 16256
2018-08-01T05:31:53.889Z,1533101513.889 [ESPComponent](INFO): console:
[    0.24] Mount-cache hash table entries: 512
2018-08-01T05:31:54.290Z,1533101514.290 [ESPComponent](INFO): console:
[    0.29] MBARI ESP 3G
2018-08-01T05:31:54.693Z,1533101514.693 [ESPComponent](INFO): console:
[    0.39] bio: create slab <bio-0> at 0
2018-08-01T05:31:55.096Z,1533101515.096 [ESPComponent](INFO): console:
[    0.46] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master...
2018-08-01T05:31:55.491Z,1533101515.491 [ESPComponent](INFO): console:
[    0.48] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master...
2018-08-01T05:31:55.896Z,1533101515.896 [ESPComponent](INFO): console:
[    0.50] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master...
2018-08-01T05:31:56.295Z,1533101516.295 [ESPComponent](INFO): console:
[    0.52] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master...
2018-08-01T05:31:56.694Z,1533101516.694 [ESPComponent](INFO): console:
[    0.54] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master...
2018-08-01T05:31:57.094Z,1533101517.094 [ESPComponent](INFO): console:
[    0.56] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master...
2018-08-01T05:31:57.495Z,1533101517.495 [ESPComponent](INFO): console:
[    0.56] NetWinder Floating Point Emulator V0.97 (double precision)
2018-08-01T05:31:57.902Z,1533101517.902 [ESPComponent](INFO): console:
[    0.58] yaffs Jul  6 2018 16:45:28 Installing. 
2018-08-01T05:31:58.299Z,1533101518.299 [ESPComponent](INFO): console:
[    0.72] m25p80 spi0.3: m25p80 found s25sl032a flash
2018-08-01T05:31:58.697Z,1533101518.697 [ESPComponent](INFO): console:
[    2.44] VFS: Mounted root (ext2 filesystem) readonly on device 179:2.
2018-08-01T05:31:59.098Z,1533101519.098 [ESPComponent](INFO): console:

2018-08-01T05:31:59.500Z,1533101519.500 [ESPComponent](INFO): console:INIT: version 2.85 booting
2018-08-01T05:31:59.895Z,1533101519.895 [ESPComponent](INFO): console:

2018-08-01T05:32:00.288Z,1533101520.288 [ESPComponent](INFO): console:MBARI ESP Embedded Linux    http://www.mbari.org   mailto:brent@mbari.org
2018-08-01T05:32:00.689Z,1533101520.689 [ESPComponent](INFO): console:
ESPhonu
2018-08-01T05:32:01.087Z,1533101521.087 [ESPComponent](INFO): console:

2018-08-01T05:32:01.487Z,1533101521.487 [ESPComponent](INFO): console:INIT: Entering runlevel: 3
2018-08-01T05:32:01.887Z,1533101521.887 [ESPComponent](INFO): console:

2018-08-01T05:32:02.288Z,1533101522.288 [ESPComponent](INFO): console:Loading kernel modules
2018-08-01T05:32:02.688Z,1533101522.688 [ESPComponent](INFO): console:
Mounting filesystems and adding swapfiles listed in /etc/fstab
2018-08-01T05:32:03.091Z,1533101523.091 [ESPComponent](INFO): console:
mount: /dev/mmcblk0p2 already mounted or /card busy
2018-08-01T05:32:03.496Z,1533101523.496 [ESPComponent](INFO): console:
Starting hotplug events dispatcher udevd
2018-08-01T05:32:03.894Z,1533101523.894 [ESPComponent](INFO): console:
Set system clock to:  Tue Jul 31 22:25:59 PDT 2018
2018-08-01T05:32:04.292Z,1533101524.292 [ESPComponent](INFO): console:
Starting syslogd klogd...
2018-08-01T05:32:04.694Z,1533101524.694 [ESPComponent](INFO): console:
Bringing up interface lo ...
2018-08-01T05:32:05.094Z,1533101525.094 [ESPComponent](INFO): console:
lo IP=127.0.0.1
2018-08-01T05:32:05.498Z,1533101525.498 [ESPComponent](INFO): console:
Packet forwarding enabled
2018-08-01T05:32:05.896Z,1533101525.896 [ESPComponent](INFO): console:
Bringing up interface eth0 ...
2018-08-01T05:32:06.299Z,1533101526.299 [ESPComponent](INFO): console:
Determining IP configuration for eth0....udhcpc (v1.11.2) started
2018-08-01T05:32:06.687Z,1533101526.687 [ESPComponent](INFO): console:
Sending discover...
2018-08-01T05:32:07.088Z,1533101527.088 [ESPComponent](INFO): console:
No lease, forking to background
2018-08-01T05:32:07.488Z,1533101527.488 [ESPComponent](INFO): console:
Bringing up interface eth0:10 ...
2018-08-01T05:32:07.887Z,1533101527.887 [ESPComponent](INFO): console:
eth0:10 IP=10.10.10.10
2018-08-01T05:32:08.288Z,1533101528.288 [ESPComponent](INFO): console:
Bringing up interface ppp2 ...
2018-08-01T05:32:08.690Z,1533101528.690 [ESPComponent](INFO): console:
Starting portmap...
2018-08-01T05:32:09.090Z,1533101529.090 [ESPComponent](INFO): console:
Network unavailable:  Local time is Tue Jul 31 22:26:05 PDT 2018
2018-08-01T05:32:09.491Z,1533101529.491 [ESPComponent](INFO): console:
Starting thttpd...
2018-08-01T05:32:09.893Z,1533101529.893 [ESPComponent](INFO): console:

2018-08-01T05:32:10.293Z,1533101530.293 [ESPComponent](INFO): console:

2018-08-01T05:32:10.694Z,1533101530.694 [ESPComponent](INFO): console:MBARI ESP Embedded Linux 2.37 -- 7/12/18 brent@mbari.org
2018-08-01T05:32:11.093Z,1533101531.093 [ESPComponent](INFO): console:

2018-08-01T05:32:11.569Z,1533101531.569 [ESPComponent](INFO): console:ESPhonu login: 
2018-08-01T05:32:13.898Z,1533101533.898 [ESPComponent](IMPORTANT): ESP has connected as client
2018-08-01T05:32:14.702Z,1533101534.702 [ESPComponent](IMPORTANT): ESP sampling sequence starting (sample #2)  sampling state: S_WAITING_INITIAL_PROMPT
2018-08-01T05:32:14.703Z,1533101534.703 [ESPComponent](DEBUG): Writing samplingActive=1, sampleNumber=2
2018-08-01T05:32:14.722Z,1533101534.722 [sample:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP] Stopped
2018-08-01T05:32:14.723Z,1533101534.723 [sample:SampleAtDepth:SampleWrapper:SampleESP:B] Running Loop=1
2018-08-01T05:32:15.119Z,1533101535.119 [sample:SampleAtDepth:SampleWrapper:SampleESP:B](IMPORTANT): ESP sampling at 2.000000 m inwater with nan ug/l chlorophyll fluorescence.
2018-08-01T05:32:15.119Z,1533101535.119 [sample:SampleAtDepth:SampleWrapper:SampleESP:B] Stopped
2018-08-01T05:32:15.119Z,1533101535.119 [sample:SampleAtDepth:SampleWrapper:SampleESP:WaitForESP] Running Loop=1
2018-08-01T05:32:15.488Z,1533101535.488 [ESPComponent](IMPORTANT): ESP sampling state: S_PREPARING_SHOW_LOG
2018-08-01T05:32:15.887Z,1533101535.887 [ESPComponent](IMPORTANT): ESP sampling state: S_PREPARING_SHOW_STATUS
2018-08-01T05:32:17.899Z,1533101537.899 [ESPComponent](IMPORTANT): ESP sampling state: S_LOADING_CARTRIDGE
2018-08-01T05:32:22.669Z,1533101542.669 [Radio_Surface](INFO): Powering up
2018-08-01T05:32:28.326Z,1533101548.326 [Radio_Surface](INFO): Powering down
2018-08-01T05:32:32.258Z,1533101552.258 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:32:56.287Z,1533101576.287 [ESPComponent](IMPORTANT): ESP sampling state: S_FILTERING
2018-08-01T05:32:58.686Z,1533101578.686 [ESPComponent](IMPORTANT): ESP sampling state: S_WAITING_FOR_PAUSED
2018-08-01T05:33:01.866Z,1533101581.866 [Radio_Surface](INFO): Powering up
2018-08-01T05:33:07.550Z,1533101587.550 [Radio_Surface](INFO): Powering down
2018-08-01T05:33:32.658Z,1533101612.658 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:33:38.666Z,1533101618.666 [Radio_Surface](INFO): Powering up
2018-08-01T05:33:44.322Z,1533101624.322 [Radio_Surface](INFO): Powering down
2018-08-01T05:34:17.470Z,1533101657.470 [Radio_Surface](INFO): Powering up
2018-08-01T05:34:23.138Z,1533101663.138 [Radio_Surface](INFO): Powering down
2018-08-01T05:34:33.058Z,1533101673.058 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:34:55.870Z,1533101695.870 [Radio_Surface](INFO): Powering up
2018-08-01T05:35:01.526Z,1533101701.526 [Radio_Surface](INFO): Powering down
2018-08-01T05:35:33.059Z,1533101733.059 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:35:33.464Z,1533101733.464 [Radio_Surface](INFO): Powering up
2018-08-01T05:35:39.118Z,1533101739.118 [Radio_Surface](INFO): Powering down
2018-08-01T05:36:13.466Z,1533101773.466 [Radio_Surface](INFO): Powering up
2018-08-01T05:36:19.122Z,1533101779.122 [Radio_Surface](INFO): Powering down
2018-08-01T05:36:33.458Z,1533101793.458 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:36:52.266Z,1533101812.266 [Radio_Surface](INFO): Powering up
2018-08-01T05:36:57.922Z,1533101817.922 [Radio_Surface](INFO): Powering down
2018-08-01T05:37:28.664Z,1533101848.664 [Radio_Surface](INFO): Powering up
2018-08-01T05:37:33.458Z,1533101853.458 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:37:34.318Z,1533101854.318 [Radio_Surface](INFO): Powering down
2018-08-01T05:38:07.466Z,1533101887.466 [Radio_Surface](INFO): Powering up
2018-08-01T05:38:13.122Z,1533101893.122 [Radio_Surface](INFO): Powering down
2018-08-01T05:38:33.858Z,1533101913.858 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:38:41.478Z,1533101921.478 [Radio_Surface](INFO): Powering up
2018-08-01T05:38:47.146Z,1533101927.146 [Radio_Surface](INFO): Powering down
2018-08-01T05:39:18.264Z,1533101958.264 [Radio_Surface](INFO): Powering up
2018-08-01T05:39:23.918Z,1533101963.918 [Radio_Surface](INFO): Powering down
2018-08-01T05:39:33.858Z,1533101973.858 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:39:55.874Z,1533101995.874 [Radio_Surface](INFO): Powering up
2018-08-01T05:40:01.538Z,1533102001.538 [Radio_Surface](INFO): Powering down
2018-08-01T05:40:33.866Z,1533102033.866 [Radio_Surface](INFO): Powering up
2018-08-01T05:40:34.258Z,1533102034.258 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:40:39.526Z,1533102039.526 [Radio_Surface](INFO): Powering down
2018-08-01T05:41:11.870Z,1533102071.870 [Radio_Surface](INFO): Powering up
2018-08-01T05:41:17.526Z,1533102077.526 [Radio_Surface](INFO): Powering down
2018-08-01T05:41:34.658Z,1533102094.658 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:41:49.466Z,1533102109.466 [Radio_Surface](INFO): Powering up
2018-08-01T05:41:55.122Z,1533102115.122 [Radio_Surface](INFO): Powering down
2018-08-01T05:42:26.266Z,1533102146.266 [Radio_Surface](INFO): Powering up
2018-08-01T05:42:31.926Z,1533102151.926 [Radio_Surface](INFO): Powering down
2018-08-01T05:42:35.058Z,1533102155.058 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:43:04.666Z,1533102184.666 [Radio_Surface](INFO): Powering up
2018-08-01T05:43:10.322Z,1533102190.322 [Radio_Surface](INFO): Powering down
2018-08-01T05:43:35.059Z,1533102215.059 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:43:42.264Z,1533102222.264 [Radio_Surface](INFO): Powering up
2018-08-01T05:43:47.918Z,1533102227.918 [Radio_Surface](INFO): Powering down
2018-08-01T05:44:21.067Z,1533102261.067 [Radio_Surface](INFO): Powering up
2018-08-01T05:44:26.722Z,1533102266.722 [Radio_Surface](INFO): Powering down
2018-08-01T05:44:35.858Z,1533102275.858 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:45:00.264Z,1533102300.264 [Radio_Surface](INFO): Powering up
2018-08-01T05:45:05.918Z,1533102305.918 [Radio_Surface](INFO): Powering down
2018-08-01T05:45:35.858Z,1533102335.858 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:45:38.666Z,1533102338.666 [Radio_Surface](INFO): Powering up
2018-08-01T05:45:44.322Z,1533102344.322 [Radio_Surface](INFO): Powering down
2018-08-01T05:46:17.064Z,1533102377.064 [Radio_Surface](INFO): Powering up
2018-08-01T05:46:22.718Z,1533102382.718 [Radio_Surface](INFO): Powering down
2018-08-01T05:46:36.258Z,1533102396.258 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:46:55.466Z,1533102415.466 [Radio_Surface](INFO): Powering up
2018-08-01T05:47:01.122Z,1533102421.122 [Radio_Surface](INFO): Powering down
2018-08-01T05:47:35.066Z,1533102455.066 [Radio_Surface](INFO): Powering up
2018-08-01T05:47:37.058Z,1533102457.058 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:47:40.722Z,1533102460.722 [Radio_Surface](INFO): Powering down
2018-08-01T05:48:13.066Z,1533102493.066 [Radio_Surface](INFO): Powering up
2018-08-01T05:48:18.722Z,1533102498.722 [Radio_Surface](INFO): Powering down
2018-08-01T05:48:37.059Z,1533102517.059 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:48:50.669Z,1533102530.669 [Radio_Surface](INFO): Powering up
2018-08-01T05:48:56.330Z,1533102536.330 [Radio_Surface](INFO): Powering down
2018-08-01T05:49:28.266Z,1533102568.266 [Radio_Surface](INFO): Powering up
2018-08-01T05:49:33.922Z,1533102573.922 [Radio_Surface](INFO): Powering down
2018-08-01T05:49:37.858Z,1533102577.858 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:50:07.466Z,1533102607.466 [Radio_Surface](INFO): Powering up
2018-08-01T05:50:13.122Z,1533102613.122 [Radio_Surface](INFO): Powering down
2018-08-01T05:50:38.258Z,1533102638.258 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:50:43.866Z,1533102643.866 [Radio_Surface](INFO): Powering up
2018-08-01T05:50:49.522Z,1533102649.522 [Radio_Surface](INFO): Powering down
2018-08-01T05:51:22.264Z,1533102682.264 [Radio_Surface](INFO): Powering up
2018-08-01T05:51:27.918Z,1533102687.918 [Radio_Surface](INFO): Powering down
2018-08-01T05:51:38.258Z,1533102698.258 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:51:59.066Z,1533102719.066 [Radio_Surface](INFO): Powering up
2018-08-01T05:52:04.726Z,1533102724.726 [Radio_Surface](INFO): Powering down
2018-08-01T05:52:37.466Z,1533102757.466 [Radio_Surface](INFO): Powering up
2018-08-01T05:52:38.658Z,1533102758.658 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:52:43.126Z,1533102763.126 [Radio_Surface](INFO): Powering down
2018-08-01T05:53:14.266Z,1533102794.266 [Radio_Surface](INFO): Powering up
2018-08-01T05:53:19.922Z,1533102799.922 [Radio_Surface](INFO): Powering down
2018-08-01T05:53:39.058Z,1533102819.058 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:53:53.066Z,1533102833.066 [Radio_Surface](INFO): Powering up
2018-08-01T05:53:58.722Z,1533102838.722 [Radio_Surface](INFO): Powering down
2018-08-01T05:54:32.666Z,1533102872.666 [Radio_Surface](INFO): Powering up
2018-08-01T05:54:38.322Z,1533102878.322 [Radio_Surface](INFO): Powering down
2018-08-01T05:54:39.458Z,1533102879.458 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:55:12.266Z,1533102912.266 [Radio_Surface](INFO): Powering up
2018-08-01T05:55:17.926Z,1533102917.926 [Radio_Surface](INFO): Powering down
2018-08-01T05:55:39.458Z,1533102939.458 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:55:48.266Z,1533102948.266 [Radio_Surface](INFO): Powering up
2018-08-01T05:55:53.942Z,1533102953.942 [Radio_Surface](INFO): Powering down
2018-08-01T05:56:25.471Z,1533102985.471 [Radio_Surface](INFO): Powering up
2018-08-01T05:56:31.130Z,1533102991.130 [Radio_Surface](INFO): Powering down
2018-08-01T05:56:39.858Z,1533102999.858 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:57:01.466Z,1533103021.466 [Radio_Surface](INFO): Powering up
2018-08-01T05:57:07.123Z,1533103027.123 [Radio_Surface](INFO): Powering down
2018-08-01T05:57:40.260Z,1533103060.260 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:57:40.664Z,1533103060.664 [Radio_Surface](INFO): Powering up
2018-08-01T05:57:46.330Z,1533103066.330 [Radio_Surface](INFO): Powering down
2018-08-01T05:58:19.466Z,1533103099.466 [Radio_Surface](INFO): Powering up
2018-08-01T05:58:25.122Z,1533103105.122 [Radio_Surface](INFO): Powering down
2018-08-01T05:58:40.258Z,1533103120.258 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:58:59.066Z,1533103139.066 [Radio_Surface](INFO): Powering up
2018-08-01T05:59:04.722Z,1533103144.722 [Radio_Surface](INFO): Powering down
2018-08-01T05:59:35.066Z,1533103175.066 [Radio_Surface](INFO): Powering up
2018-08-01T05:59:40.658Z,1533103180.658 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T05:59:40.722Z,1533103180.722 [Radio_Surface](INFO): Powering down
2018-08-01T06:00:11.066Z,1533103211.066 [Radio_Surface](INFO): Powering up
2018-08-01T06:00:16.726Z,1533103216.726 [Radio_Surface](INFO): Powering down
2018-08-01T06:00:40.658Z,1533103240.658 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:00:48.664Z,1533103248.664 [Radio_Surface](INFO): Powering up
2018-08-01T06:00:54.318Z,1533103254.318 [Radio_Surface](INFO): Powering down
2018-08-01T06:01:26.666Z,1533103286.666 [Radio_Surface](INFO): Powering up
2018-08-01T06:01:32.322Z,1533103292.322 [Radio_Surface](INFO): Powering down
2018-08-01T06:01:40.658Z,1533103300.658 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:02:05.466Z,1533103325.466 [Radio_Surface](INFO): Powering up
2018-08-01T06:02:11.123Z,1533103331.123 [Radio_Surface](INFO): Powering down
2018-08-01T06:02:41.058Z,1533103361.058 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:02:45.866Z,1533103365.866 [Radio_Surface](INFO): Powering up
2018-08-01T06:02:51.522Z,1533103371.522 [Radio_Surface](INFO): Powering down
2018-08-01T06:03:23.866Z,1533103403.866 [Radio_Surface](INFO): Powering up
2018-08-01T06:03:29.522Z,1533103409.522 [Radio_Surface](INFO): Powering down
2018-08-01T06:03:41.858Z,1533103421.858 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:04:03.068Z,1533103443.068 [Radio_Surface](INFO): Powering up
2018-08-01T06:04:08.726Z,1533103448.726 [Radio_Surface](INFO): Powering down
2018-08-01T06:04:41.458Z,1533103481.458 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:04:41.466Z,1533103481.466 [Radio_Surface](INFO): Powering up
2018-08-01T06:04:47.130Z,1533103487.130 [Radio_Surface](INFO): Powering down
2018-08-01T06:05:19.864Z,1533103519.864 [Radio_Surface](INFO): Powering up
2018-08-01T06:05:25.518Z,1533103525.518 [Radio_Surface](INFO): Powering down
2018-08-01T06:05:41.858Z,1533103541.858 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:05:48.298Z,1533103548.298 [ESPComponent](IMPORTANT): ESP sampling state: S_PROCESSING
2018-08-01T06:05:50.698Z,1533103550.698 [ESPComponent](IMPORTANT): ESP sampling state: S_WAITING_FOR_PROCESSED
2018-08-01T06:05:57.072Z,1533103557.072 [Radio_Surface](INFO): Powering up
2018-08-01T06:06:02.730Z,1533103562.730 [Radio_Surface](INFO): Powering down
2018-08-01T06:06:34.666Z,1533103594.666 [Radio_Surface](INFO): Powering up
2018-08-01T06:06:40.326Z,1533103600.326 [Radio_Surface](INFO): Powering down
2018-08-01T06:06:41.858Z,1533103601.858 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:07:09.866Z,1533103629.866 [Radio_Surface](INFO): Powering up
2018-08-01T06:07:15.526Z,1533103635.526 [Radio_Surface](INFO): Powering down
2018-08-01T06:07:42.658Z,1533103662.658 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:07:48.266Z,1533103668.266 [Radio_Surface](INFO): Powering up
2018-08-01T06:07:53.922Z,1533103673.922 [Radio_Surface](INFO): Powering down
2018-08-01T06:08:26.664Z,1533103706.664 [Radio_Surface](INFO): Powering up
2018-08-01T06:08:32.318Z,1533103712.318 [Radio_Surface](INFO): Powering down
2018-08-01T06:08:42.658Z,1533103722.658 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:09:05.064Z,1533103745.064 [Radio_Surface](INFO): Powering up
2018-08-01T06:09:10.718Z,1533103750.718 [Radio_Surface](INFO): Powering down
2018-08-01T06:09:43.058Z,1533103783.058 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:09:43.464Z,1533103783.464 [Radio_Surface](INFO): Powering up
2018-08-01T06:09:49.118Z,1533103789.118 [Radio_Surface](INFO): Powering down
2018-08-01T06:10:22.670Z,1533103822.670 [Radio_Surface](INFO): Powering up
2018-08-01T06:10:28.326Z,1533103828.326 [Radio_Surface](INFO): Powering down
2018-08-01T06:10:43.458Z,1533103843.458 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:11:01.466Z,1533103861.466 [Radio_Surface](INFO): Powering up
2018-08-01T06:11:07.130Z,1533103867.130 [Radio_Surface](INFO): Powering down
2018-08-01T06:11:40.266Z,1533103900.266 [Radio_Surface](INFO): Powering up
2018-08-01T06:11:43.858Z,1533103903.858 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:11:45.922Z,1533103905.922 [Radio_Surface](INFO): Powering down
2018-08-01T06:12:17.070Z,1533103937.070 [Radio_Surface](INFO): Powering up
2018-08-01T06:12:22.726Z,1533103942.726 [Radio_Surface](INFO): Powering down
2018-08-01T06:12:44.258Z,1533103964.258 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:12:55.864Z,1533103975.864 [Radio_Surface](INFO): Powering up
2018-08-01T06:13:01.518Z,1533103981.518 [Radio_Surface](INFO): Powering down
2018-08-01T06:13:33.866Z,1533104013.866 [Radio_Surface](INFO): Powering up
2018-08-01T06:13:39.522Z,1533104019.522 [Radio_Surface](INFO): Powering down
2018-08-01T06:13:44.658Z,1533104024.658 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:14:12.266Z,1533104052.266 [Radio_Surface](INFO): Powering up
2018-08-01T06:14:17.922Z,1533104057.922 [Radio_Surface](INFO): Powering down
2018-08-01T06:14:44.658Z,1533104084.658 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:14:51.866Z,1533104091.866 [Radio_Surface](INFO): Powering up
2018-08-01T06:14:57.522Z,1533104097.522 [Radio_Surface](INFO): Powering down
2018-08-01T06:15:30.265Z,1533104130.265 [Radio_Surface](INFO): Powering up
2018-08-01T06:15:35.922Z,1533104135.922 [Radio_Surface](INFO): Powering down
2018-08-01T06:15:45.058Z,1533104145.058 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:16:09.066Z,1533104169.066 [Radio_Surface](INFO): Powering up
2018-08-01T06:16:14.722Z,1533104174.722 [Radio_Surface](INFO): Powering down
2018-08-01T06:16:45.858Z,1533104205.858 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:16:47.866Z,1533104207.866 [Radio_Surface](INFO): Powering up
2018-08-01T06:16:53.526Z,1533104213.526 [Radio_Surface](INFO): Powering down
2018-08-01T06:17:16.694Z,1533104236.694 [ESPComponent](IMPORTANT): ESP sampling state: S_STOPPING
2018-08-01T06:17:25.864Z,1533104245.864 [Radio_Surface](INFO): Powering up
2018-08-01T06:17:31.518Z,1533104251.518 [Radio_Surface](INFO): Powering down
2018-08-01T06:17:43.096Z,1533104263.096 [ESPComponent](IMPORTANT): ESP sampling sequence completed normally (sample #2)
2018-08-01T06:17:43.097Z,1533104263.097 [ESPComponent](DEBUG): Writing samplingActive=0, sampleNumber=2
2018-08-01T06:17:43.112Z,1533104263.112 [sample:SampleAtDepth:SampleWrapper:SampleESP:WaitForESP] Stopped
2018-08-01T06:17:43.112Z,1533104263.112 [sample:SampleAtDepth:SampleWrapper:SampleESP](INFO): Completed sample:SampleAtDepth:SampleWrapper:SampleESP
2018-08-01T06:17:43.112Z,1533104263.112 [sample:SampleAtDepth:SampleWrapper:SampleESP] Stopped
2018-08-01T06:17:43.112Z,1533104263.112 [sample:SampleAtDepth:SampleWrapper:SampleESP](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper:SampleESP
2018-08-01T06:17:43.113Z,1533104263.113 [sample:SampleAtDepth:SampleWrapper](INFO): Completed sample:SampleAtDepth:SampleWrapper
2018-08-01T06:17:43.113Z,1533104263.113 [sample:SampleAtDepth:SampleWrapper] Stopped
2018-08-01T06:17:43.113Z,1533104263.113 [sample:SampleAtDepth:SampleWrapper](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper
2018-08-01T06:17:43.114Z,1533104263.114 [sample:SampleAtDepth](INFO): Completed sample:SampleAtDepth
2018-08-01T06:17:43.114Z,1533104263.114 [sample:SampleAtDepth] Stopped
2018-08-01T06:17:43.114Z,1533104263.114 [sample:SampleAtDepth](DEBUG): Aggregate::uninitialize sample:SampleAtDepth
2018-08-01T06:17:43.114Z,1533104263.114 [sample:SampleAtDepth:B.Pitch] Stopped
2018-08-01T06:17:43.498Z,1533104263.498 [ESPComponent](IMPORTANT): No ESP summary messages.
2018-08-01T06:17:43.498Z,1533104263.498 [ESPComponent](INFO): powering down ESP
2018-08-01T06:17:43.625Z,1533104263.625 [sample:SampleRepeater:Sample](INFO): Completed sample:SampleRepeater:Sample
2018-08-01T06:17:43.625Z,1533104263.625 [sample:SampleRepeater:Sample] Stopped
2018-08-01T06:17:43.625Z,1533104263.625 [sample:SampleRepeater:Sample](DEBUG): Aggregate::uninitialize sample:SampleRepeater:Sample
2018-08-01T06:17:43.625Z,1533104263.625 [sample:SampleRepeater](INFO): Completed sample:SampleRepeater
2018-08-01T06:17:43.626Z,1533104263.626 [sample:SampleRepeater] Stopped
2018-08-01T06:17:43.626Z,1533104263.626 [sample:SampleRepeater](DEBUG): Aggregate::uninitialize sample:SampleRepeater
2018-08-01T06:17:43.626Z,1533104263.626 [sample:SampleRepeater](INFO): Running loop #3
2018-08-01T06:17:43.626Z,1533104263.626 [sample:SampleRepeater] Running Loop=3
2018-08-01T06:17:43.626Z,1533104263.626 [sample:SampleRepeater](DEBUG): Aggregate::initialize sample:SampleRepeater
2018-08-01T06:17:43.627Z,1533104263.627 [sample:SampleRepeater:Sample] Running Loop=1
2018-08-01T06:17:43.627Z,1533104263.627 [sample:SampleRepeater:Sample](DEBUG): Aggregate::initialize sample:SampleRepeater:Sample
2018-08-01T06:17:43.920Z,1533104263.920 [sample:SampleAtDepth] Running Loop=1
2018-08-01T06:17:43.920Z,1533104263.920 [sample:SampleAtDepth](DEBUG): Aggregate::initialize sample:SampleAtDepth
2018-08-01T06:17:43.920Z,1533104263.920 [sample:SampleAtDepth:B.Pitch] Running Loop=1
2018-08-01T06:17:43.920Z,1533104263.920 [sample:SampleAtDepth:B.Pitch](DEBUG): Initialize.
2018-08-01T06:17:43.921Z,1533104263.921 [sample:SampleAtDepth:A] Running Loop=1
2018-08-01T06:17:43.922Z,1533104263.922 [sample:SampleAtDepth:A](INFO): Moving to 2.000000 m 
2018-08-01T06:17:43.922Z,1533104263.922 [sample:SampleAtDepth:A] Stopped
2018-08-01T06:17:44.310Z,1533104264.310 [sample:SampleAtDepth:C] Running Loop=1
2018-08-01T06:17:44.725Z,1533104264.725 [sample:SampleAtDepth:C](INFO): At 2.000000 m , settling for 0.050000 min 
2018-08-01T06:17:44.725Z,1533104264.725 [sample:SampleAtDepth:C] Stopped
2018-08-01T06:17:44.725Z,1533104264.725 [sample:SampleAtDepth:D.Wait] Running Loop=1
2018-08-01T06:17:44.725Z,1533104264.725 [sample:SampleAtDepth:D.Wait](DEBUG): Initialize Wait Component.
2018-08-01T06:17:45.858Z,1533104265.858 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:17:48.310Z,1533104268.310 [sample:SampleAtDepth:D.Wait](INFO): Done Waiting.
2018-08-01T06:17:48.310Z,1533104268.310 [sample:SampleAtDepth:D.Wait] Stopped
2018-08-01T06:17:48.310Z,1533104268.310 [sample:SampleAtDepth:D.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T06:17:48.310Z,1533104268.310 [sample:SampleAtDepth:SampleWrapper] Running Loop=1
2018-08-01T06:17:48.310Z,1533104268.310 [sample:SampleAtDepth:SampleWrapper](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper
2018-08-01T06:17:48.310Z,1533104268.310 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler] Running Loop=1
2018-08-01T06:17:48.311Z,1533104268.311 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper:SampleCANONSampler
2018-08-01T06:17:48.311Z,1533104268.311 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:A] Running Loop=1
2018-08-01T06:17:48.311Z,1533104268.311 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:B] Running Loop=1
2018-08-01T06:17:48.311Z,1533104268.311 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler] Running Loop=1
2018-08-01T06:17:48.706Z,1533104268.706 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler] Stopped
2018-08-01T06:17:48.707Z,1533104268.707 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper:SampleCANONSampler
2018-08-01T06:17:48.707Z,1533104268.707 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:A] Stopped
2018-08-01T06:17:48.707Z,1533104268.707 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:B] Stopped
2018-08-01T06:17:48.707Z,1533104268.707 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler] Stopped
2018-08-01T06:17:48.707Z,1533104268.707 [sample:SampleAtDepth:SampleWrapper:SampleESP] Running Loop=1
2018-08-01T06:17:48.707Z,1533104268.707 [sample:SampleAtDepth:SampleWrapper:SampleESP](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper:SampleESP
2018-08-01T06:17:48.707Z,1533104268.707 [sample:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP] Running Loop=1
2018-08-01T06:17:50.366Z,1533104270.366 [ESPComponent](INFO): powering up ESP
2018-08-01T06:17:50.366Z,1533104270.366 [ESPComponent](INFO): manually powering up ESP
2018-08-01T06:17:50.368Z,1533104270.368 [ESPComponent](IMPORTANT): Powered ESP with command: ! echo 1 > /dev/loadA6
2018-08-01T06:17:50.369Z,1533104270.369 [ESPComponent](IMPORTANT): Starting PPPD with command:/sbin/pppd xonxoff asyncmap A0000 /dev/ttyTX1 linkname esp noauth local lock 115200 10.89.5.2:10.89.5.3 persist maxfail 0 holdoff 10 lcp-echo-interval 60 lcp-echo-failure 3 proxyarp ktune deflate 12 ms-dns 8.8.8.8
2018-08-01T06:17:50.446Z,1533104270.446 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadA6
2018-08-01T06:17:50.526Z,1533104270.526 [Radio_Surface](INFO): Powering up
2018-08-01T06:17:50.570Z,1533104270.570 [ESPComponent](IMPORTANT): Waiting for ESP to connect (timeout=150.0000)
2018-08-01T06:17:50.777Z,1533104270.777 [ESPComponent](INFO): console:
2018-08-01T06:17:51.898Z,1533104271.898 [ESPComponent](INFO): console:

2018-08-01T06:17:52.288Z,1533104272.288 [ESPComponent](INFO): console:NAND:  256 MiB
2018-08-01T06:17:52.692Z,1533104272.692 [ESPComponent](INFO): console:
BOOTMODE: SPI
2018-08-01T06:17:53.153Z,1533104273.153 [ESPComponent](INFO): console:
reading SPI NOR..
2018-08-01T06:17:54.298Z,1533104274.298 [ESPComponent](INFO): console:Done
2018-08-01T06:17:54.695Z,1533104274.695 [ESPComponent](INFO): console:

2018-08-01T06:17:55.093Z,1533104275.093 [ESPComponent](INFO): console:

2018-08-01T06:17:55.495Z,1533104275.495 [ESPComponent](INFO): console:
U-Boot 2009.11-mbariB (Dec 07 2017 - 19:07:59)
2018-08-01T06:17:55.898Z,1533104275.898 [ESPComponent](INFO): console:

2018-08-01T06:17:56.184Z,1533104276.184 [Radio_Surface](INFO): Powering down
2018-08-01T06:17:56.302Z,1533104276.302 [ESPComponent](INFO): console:
MBARI LPC31xx ESP 3G
2018-08-01T06:17:56.712Z,1533104276.712 [ESPComponent](INFO): console:
flash params are already written into flash
2018-08-01T06:17:57.088Z,1533104277.088 [ESPComponent](INFO): console:
DRAM:  64 MB
2018-08-01T06:17:57.488Z,1533104277.488 [ESPComponent](INFO): console:
In:    serial
2018-08-01T06:17:57.893Z,1533104277.893 [ESPComponent](INFO): console:
Out:   serial
2018-08-01T06:17:58.288Z,1533104278.288 [ESPComponent](INFO): console:
Err:   serial
2018-08-01T06:17:58.691Z,1533104278.691 [ESPComponent](INFO): console:
Net:   ks8851_mll
2018-08-01T06:17:59.092Z,1533104279.092 [ESPComponent](INFO): console:
Hit <ctrl-C> to stop autoboot:  1  0 
2018-08-01T06:17:59.499Z,1533104279.499 [ESPComponent](INFO): console:
mmc1 is available
2018-08-01T06:17:59.895Z,1533104279.895 [ESPComponent](INFO): console:
reading uImage
2018-08-01T06:18:00.294Z,1533104280.294 [ESPComponent](INFO): console:

2018-08-01T06:18:00.694Z,1533104280.694 [ESPComponent](INFO): console:
1681208 bytes read
2018-08-01T06:18:01.095Z,1533104281.095 [ESPComponent](INFO): console:
## Booting kernel from Legacy Image at 31000000 ...
2018-08-01T06:18:01.499Z,1533104281.499 [ESPComponent](INFO): console:
   Image Name:-2.6.33-ea313
2018-08-01T06:18:01.900Z,1533104281.900 [ESPComponent](INFO): console:
   Image Type:   ARM Linux Kernel Image (uncompressed)
2018-08-01T06:18:02.296Z,1533104282.296 [ESPComponent](INFO): console:
   Data Size:    1681144 Bytes =  1.6 MB
2018-08-01T06:18:02.698Z,1533104282.698 [ESPComponent](INFO): console:
   Load Address: 30008000
2018-08-01T06:18:03.066Z,1533104283.066 [Radio_Surface](INFO): Powering up
2018-08-01T06:18:03.097Z,1533104283.097 [ESPComponent](INFO): console:
   Entry Point:  30008000
2018-08-01T06:18:03.496Z,1533104283.496 [ESPComponent](INFO): console:
   Verifying Checksum ... OK
2018-08-01T06:18:03.888Z,1533104283.888 [ESPComponent](INFO): console:
   Loading Kernel Image ... OK
2018-08-01T06:18:04.301Z,1533104284.301 [ESPComponent](INFO): console:
OK
2018-08-01T06:18:04.686Z,1533104284.686 [ESPComponent](INFO): console:

2018-08-01T06:18:05.088Z,1533104285.088 [ESPComponent](INFO): console:
Starting kernel ...
2018-08-01T06:18:05.487Z,1533104285.487 [ESPComponent](INFO): console:

2018-08-01T06:18:05.891Z,1533104285.891 [ESPComponent](INFO): console:
Uncompressing Linux... done, booting the kernel.
2018-08-01T06:18:06.291Z,1533104286.291 [ESPComponent](INFO): console:
[    0.00] CPU: ARM926EJ-S [41069265] revision 5 (ARMv5TEJ), cr=00053177
2018-08-01T06:18:06.691Z,1533104286.691 [ESPComponent](INFO): console:
[    0.00] CPU: VIVT data cache, VIVT instruction cache
2018-08-01T06:18:07.094Z,1533104287.094 [ESPComponent](INFO): console:
[    0.00] Machine: NXP EA313X
2018-08-01T06:18:07.493Z,1533104287.493 [ESPComponent](INFO): console:
[    0.00] Memory policy: ECC disabled, Data cache writeback
2018-08-01T06:18:07.894Z,1533104287.894 [ESPComponent](INFO): console:
[    0.00] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 16256
2018-08-01T06:18:08.294Z,1533104288.294 [ESPComponent](INFO): console:
[    0.24] Mount-cache hash table entries: 512
2018-08-01T06:18:08.696Z,1533104288.696 [ESPComponent](INFO): console:
[    0.29] MBARI ESP 3G
2018-08-01T06:18:08.722Z,1533104288.722 [Radio_Surface](INFO): Powering down
2018-08-01T06:18:09.097Z,1533104289.097 [ESPComponent](INFO): console:
[    0.39] bio: create slab <bio-0> at 0
2018-08-01T06:18:09.497Z,1533104289.497 [ESPComponent](INFO): console:
[    0.46] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master...
2018-08-01T06:18:09.888Z,1533104289.888 [ESPComponent](INFO): console:
[    0.48] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master...
2018-08-01T06:18:10.321Z,1533104290.321 [ESPComponent](INFO): console:
[    0.50] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master...
2018-08-01T06:18:10.689Z,1533104290.689 [ESPComponent](INFO): console:
[    0.52] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master...
2018-08-01T06:18:11.094Z,1533104291.093 [ESPComponent](INFO): console:
[    0.54] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master...
2018-08-01T06:18:11.489Z,1533104291.489 [ESPComponent](INFO): console:
[    0.56] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master...
2018-08-01T06:18:11.892Z,1533104291.892 [ESPComponent](INFO): console:
[    0.56] NetWinder Floating Point Emulator V0.97 (double precision)
2018-08-01T06:18:12.294Z,1533104292.294 [ESPComponent](INFO): console:
[    0.58] yaffs Jul  6 2018 16:45:28 Installing. 
2018-08-01T06:18:12.694Z,1533104292.694 [ESPComponent](INFO): console:
[    0.72] m25p80 spi0.3: m25p80 found s25sl032a flash
2018-08-01T06:18:13.093Z,1533104293.093 [ESPComponent](INFO): console:
[    2.35] VFS: Mounted root (ext2 filesystem) readonly on device 179:2.
2018-08-01T06:18:13.497Z,1533104293.497 [ESPComponent](INFO): console:

2018-08-01T06:18:13.895Z,1533104293.895 [ESPComponent](INFO): console:INIT: version 2.85 booting
2018-08-01T06:18:14.295Z,1533104294.295 [ESPComponent](INFO): console:

2018-08-01T06:18:14.699Z,1533104294.699 [ESPComponent](INFO): console:MBARI ESP Embedded Linux    http://www.mbari.org   mailto:brent@mbari.org
2018-08-01T06:18:15.098Z,1533104295.098 [ESPComponent](INFO): console:
ESPhonu
2018-08-01T06:18:15.487Z,1533104295.487 [ESPComponent](INFO): console:

2018-08-01T06:18:15.889Z,1533104295.889 [ESPComponent](INFO): console:INIT: Entering runlevel: 3
2018-08-01T06:18:16.287Z,1533104296.287 [ESPComponent](INFO): console:

2018-08-01T06:18:16.691Z,1533104296.691 [ESPComponent](INFO): console:Loading kernel modules
2018-08-01T06:18:17.092Z,1533104297.092 [ESPComponent](INFO): console:
Mounting filesystems and adding swapfiles listed in /etc/fstab
2018-08-01T06:18:17.491Z,1533104297.491 [ESPComponent](INFO): console:
mount: /dev/mmcblk0p2 already mounted or /card busy
2018-08-01T06:18:17.892Z,1533104297.892 [ESPComponent](INFO): console:
Starting hotplug events dispatcher udevd
2018-08-01T06:18:18.295Z,1533104298.295 [ESPComponent](INFO): console:
Set system clock to:  Tue Jul 31 23:12:09 PDT 2018
2018-08-01T06:18:18.694Z,1533104298.694 [ESPComponent](INFO): console:
Starting syslogd klogd...
2018-08-01T06:18:19.093Z,1533104299.093 [ESPComponent](INFO): console:
Bringing up interface lo ...
2018-08-01T06:18:19.493Z,1533104299.493 [ESPComponent](INFO): console:
lo IP=127.0.0.1
2018-08-01T06:18:19.894Z,1533104299.894 [ESPComponent](INFO): console:
Packet forwarding enabled
2018-08-01T06:18:20.294Z,1533104300.294 [ESPComponent](INFO): console:
Bringing up interface eth0 ...
2018-08-01T06:18:20.700Z,1533104300.700 [ESPComponent](INFO): console:
Determining IP configuration for eth0....udhcpc (v1.11.2) started
2018-08-01T06:18:21.099Z,1533104301.099 [ESPComponent](INFO): console:
Sending discover...
2018-08-01T06:18:21.495Z,1533104301.495 [ESPComponent](INFO): console:
No lease, forking to background
2018-08-01T06:18:21.898Z,1533104301.898 [ESPComponent](INFO): console:
Bringing up interface eth0:10 ...
2018-08-01T06:18:22.299Z,1533104302.299 [ESPComponent](INFO): console:
eth0:10 IP=10.10.10.10
2018-08-01T06:18:22.688Z,1533104302.688 [ESPComponent](INFO): console:
Bringing up interface ppp2 ...
2018-08-01T06:18:23.091Z,1533104303.092 [ESPComponent](INFO): console:
Starting portmap...
2018-08-01T06:18:23.493Z,1533104303.493 [ESPComponent](INFO): console:
Network unavailable:  Local time is Tue Jul 31 23:12:15 PDT 2018
2018-08-01T06:18:23.893Z,1533104303.893 [ESPComponent](INFO): console:
Starting thttpd...
2018-08-01T06:18:24.293Z,1533104304.293 [ESPComponent](INFO): console:

2018-08-01T06:18:24.693Z,1533104304.693 [ESPComponent](INFO): console:

2018-08-01T06:18:25.094Z,1533104305.094 [ESPComponent](INFO): console:MBARI ESP Embedded Linux 2.37 -- 7/12/18 brent@mbari.org
2018-08-01T06:18:25.502Z,1533104305.502 [ESPComponent](INFO): console:

2018-08-01T06:18:25.961Z,1533104305.961 [ESPComponent](INFO): console:ESPhonu login: 
2018-08-01T06:18:28.295Z,1533104308.295 [ESPComponent](IMPORTANT): ESP has connected as client
2018-08-01T06:18:29.101Z,1533104309.101 [ESPComponent](IMPORTANT): ESP sampling sequence starting (sample #3)  sampling state: S_WAITING_INITIAL_PROMPT
2018-08-01T06:18:29.102Z,1533104309.102 [ESPComponent](DEBUG): Writing samplingActive=1, sampleNumber=3
2018-08-01T06:18:29.122Z,1533104309.122 [sample:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP] Stopped
2018-08-01T06:18:29.122Z,1533104309.122 [sample:SampleAtDepth:SampleWrapper:SampleESP:B] Running Loop=1
2018-08-01T06:18:29.519Z,1533104309.519 [sample:SampleAtDepth:SampleWrapper:SampleESP:B](IMPORTANT): ESP sampling at 2.000000 m inwater with nan ug/l chlorophyll fluorescence.
2018-08-01T06:18:29.519Z,1533104309.519 [sample:SampleAtDepth:SampleWrapper:SampleESP:B] Stopped
2018-08-01T06:18:29.519Z,1533104309.519 [sample:SampleAtDepth:SampleWrapper:SampleESP:WaitForESP] Running Loop=1
2018-08-01T06:18:29.895Z,1533104309.895 [ESPComponent](IMPORTANT): ESP sampling state: S_PREPARING_SHOW_LOG
2018-08-01T06:18:30.295Z,1533104310.295 [ESPComponent](IMPORTANT): ESP sampling state: S_PREPARING_SHOW_STATUS
2018-08-01T06:18:32.295Z,1533104312.295 [ESPComponent](IMPORTANT): ESP sampling state: S_LOADING_CARTRIDGE
2018-08-01T06:18:42.670Z,1533104322.670 [Radio_Surface](INFO): Powering up
2018-08-01T06:18:46.260Z,1533104326.260 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:18:48.326Z,1533104328.326 [Radio_Surface](INFO): Powering down
2018-08-01T06:19:10.699Z,1533104350.699 [ESPComponent](IMPORTANT): ESP sampling state: S_FILTERING
2018-08-01T06:19:13.898Z,1533104353.898 [ESPComponent](IMPORTANT): ESP sampling state: S_WAITING_FOR_PAUSED
2018-08-01T06:19:21.866Z,1533104361.866 [Radio_Surface](INFO): Powering up
2018-08-01T06:19:27.522Z,1533104367.522 [Radio_Surface](INFO): Powering down
2018-08-01T06:19:46.258Z,1533104386.258 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:20:01.064Z,1533104401.064 [Radio_Surface](INFO): Powering up
2018-08-01T06:20:06.718Z,1533104406.718 [Radio_Surface](INFO): Powering down
2018-08-01T06:20:41.066Z,1533104441.066 [Radio_Surface](INFO): Powering up
2018-08-01T06:20:46.258Z,1533104446.258 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:20:46.722Z,1533104446.722 [Radio_Surface](INFO): Powering down
2018-08-01T06:21:21.070Z,1533104481.070 [Radio_Surface](INFO): Powering up
2018-08-01T06:21:26.726Z,1533104486.726 [Radio_Surface](INFO): Powering down
2018-08-01T06:21:47.058Z,1533104507.058 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:21:59.470Z,1533104519.470 [Radio_Surface](INFO): Powering up
2018-08-01T06:22:05.130Z,1533104525.130 [Radio_Surface](INFO): Powering down
2018-08-01T06:22:36.264Z,1533104556.264 [Radio_Surface](INFO): Powering up
2018-08-01T06:22:41.918Z,1533104561.918 [Radio_Surface](INFO): Powering down
2018-08-01T06:22:47.058Z,1533104567.058 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:23:14.670Z,1533104594.670 [Radio_Surface](INFO): Powering up
2018-08-01T06:23:20.326Z,1533104600.326 [Radio_Surface](INFO): Powering down
2018-08-01T06:23:47.858Z,1533104627.858 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:23:53.471Z,1533104633.471 [Radio_Surface](INFO): Powering up
2018-08-01T06:23:59.126Z,1533104639.126 [Radio_Surface](INFO): Powering down
2018-08-01T06:24:29.866Z,1533104669.866 [Radio_Surface](INFO): Powering up
2018-08-01T06:24:35.526Z,1533104675.526 [Radio_Surface](INFO): Powering down
2018-08-01T06:24:47.858Z,1533104687.858 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:25:06.670Z,1533104706.670 [Radio_Surface](INFO): Powering up
2018-08-01T06:25:12.334Z,1533104712.334 [Radio_Surface](INFO): Powering down
2018-08-01T06:25:45.066Z,1533104745.066 [Radio_Surface](INFO): Powering up
2018-08-01T06:25:48.658Z,1533104748.658 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:25:50.726Z,1533104750.726 [Radio_Surface](INFO): Powering down
2018-08-01T06:26:23.864Z,1533104783.864 [Radio_Surface](INFO): Powering up
2018-08-01T06:26:29.518Z,1533104789.518 [Radio_Surface](INFO): Powering down
2018-08-01T06:26:49.058Z,1533104809.058 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:27:04.270Z,1533104824.270 [Radio_Surface](INFO): Powering up
2018-08-01T06:27:09.935Z,1533104829.935 [Radio_Surface](INFO): Powering down
2018-08-01T06:27:42.666Z,1533104862.666 [Radio_Surface](INFO): Powering up
2018-08-01T06:27:48.322Z,1533104868.322 [Radio_Surface](INFO): Powering down
2018-08-01T06:27:49.058Z,1533104869.058 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:28:21.866Z,1533104901.866 [Radio_Surface](INFO): Powering up
2018-08-01T06:28:27.522Z,1533104907.522 [Radio_Surface](INFO): Powering down
2018-08-01T06:28:49.058Z,1533104929.058 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:29:01.870Z,1533104941.870 [Radio_Surface](INFO): Powering up
2018-08-01T06:29:07.526Z,1533104947.526 [Radio_Surface](INFO): Powering down
2018-08-01T06:29:39.468Z,1533104979.468 [Radio_Surface](INFO): Powering up
2018-08-01T06:29:45.130Z,1533104985.130 [Radio_Surface](INFO): Powering down
2018-08-01T06:29:49.458Z,1533104989.458 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:30:18.670Z,1533105018.670 [Radio_Surface](INFO): Powering up
2018-08-01T06:30:24.326Z,1533105024.326 [Radio_Surface](INFO): Powering down
2018-08-01T06:30:49.858Z,1533105049.858 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:30:57.066Z,1533105057.066 [Radio_Surface](INFO): Powering up
2018-08-01T06:31:02.722Z,1533105062.722 [Radio_Surface](INFO): Powering down
2018-08-01T06:31:35.466Z,1533105095.466 [Radio_Surface](INFO): Powering up
2018-08-01T06:31:41.122Z,1533105101.122 [Radio_Surface](INFO): Powering down
2018-08-01T06:31:50.260Z,1533105110.260 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:32:13.064Z,1533105133.064 [Radio_Surface](INFO): Powering up
2018-08-01T06:32:18.726Z,1533105138.726 [Radio_Surface](INFO): Powering down
2018-08-01T06:32:50.258Z,1533105170.258 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:32:52.269Z,1533105172.269 [Radio_Surface](INFO): Powering up
2018-08-01T06:32:57.926Z,1533105177.926 [Radio_Surface](INFO): Powering down
2018-08-01T06:33:30.666Z,1533105210.666 [Radio_Surface](INFO): Powering up
2018-08-01T06:33:36.322Z,1533105216.322 [Radio_Surface](INFO): Powering down
2018-08-01T06:33:51.058Z,1533105231.058 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:34:08.266Z,1533105248.266 [Radio_Surface](INFO): Powering up
2018-08-01T06:34:13.922Z,1533105253.922 [Radio_Surface](INFO): Powering down
2018-08-01T06:34:44.666Z,1533105284.666 [Radio_Surface](INFO): Powering up
2018-08-01T06:34:50.323Z,1533105290.323 [Radio_Surface](INFO): Powering down
2018-08-01T06:34:51.058Z,1533105291.058 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:35:23.470Z,1533105323.470 [Radio_Surface](INFO): Powering up
2018-08-01T06:35:29.126Z,1533105329.126 [Radio_Surface](INFO): Powering down
2018-08-01T06:35:51.459Z,1533105351.459 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:36:01.866Z,1533105361.866 [Radio_Surface](INFO): Powering up
2018-08-01T06:36:07.522Z,1533105367.522 [Radio_Surface](INFO): Powering down
2018-08-01T06:36:41.466Z,1533105401.466 [Radio_Surface](INFO): Powering up
2018-08-01T06:36:47.122Z,1533105407.122 [Radio_Surface](INFO): Powering down
2018-08-01T06:36:51.858Z,1533105411.858 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:37:21.070Z,1533105441.070 [Radio_Surface](INFO): Powering up
2018-08-01T06:37:26.726Z,1533105446.726 [Radio_Surface](INFO): Powering down
2018-08-01T06:37:51.858Z,1533105471.858 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:38:00.270Z,1533105480.270 [Radio_Surface](INFO): Powering up
2018-08-01T06:38:05.926Z,1533105485.926 [Radio_Surface](INFO): Powering down
2018-08-01T06:38:37.866Z,1533105517.866 [Radio_Surface](INFO): Powering up
2018-08-01T06:38:43.522Z,1533105523.522 [Radio_Surface](INFO): Powering down
2018-08-01T06:38:52.258Z,1533105532.258 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:39:17.466Z,1533105557.466 [Radio_Surface](INFO): Powering up
2018-08-01T06:39:23.122Z,1533105563.122 [Radio_Surface](INFO): Powering down
2018-08-01T06:39:52.258Z,1533105592.258 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:39:55.466Z,1533105595.466 [Radio_Surface](INFO): Powering up
2018-08-01T06:40:01.122Z,1533105601.122 [Radio_Surface](INFO): Powering down
2018-08-01T06:40:34.267Z,1533105634.267 [Radio_Surface](INFO): Powering up
2018-08-01T06:40:39.930Z,1533105639.930 [Radio_Surface](INFO): Powering down
2018-08-01T06:40:53.058Z,1533105653.058 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:41:13.066Z,1533105673.066 [Radio_Surface](INFO): Powering up
2018-08-01T06:41:18.722Z,1533105678.722 [Radio_Surface](INFO): Powering down
2018-08-01T06:41:52.266Z,1533105712.266 [Radio_Surface](INFO): Powering up
2018-08-01T06:41:53.058Z,1533105713.058 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:41:57.930Z,1533105717.930 [Radio_Surface](INFO): Powering down
2018-08-01T06:42:29.866Z,1533105749.866 [Radio_Surface](INFO): Powering up
2018-08-01T06:42:35.522Z,1533105755.522 [Radio_Surface](INFO): Powering down
2018-08-01T06:42:53.458Z,1533105773.458 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:43:08.266Z,1533105788.266 [Radio_Surface](INFO): Powering up
2018-08-01T06:43:13.930Z,1533105793.930 [Radio_Surface](INFO): Powering down
2018-08-01T06:43:46.664Z,1533105826.664 [Radio_Surface](INFO): Powering up
2018-08-01T06:43:52.318Z,1533105832.318 [Radio_Surface](INFO): Powering down
2018-08-01T06:43:53.858Z,1533105833.858 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:44:24.663Z,1533105864.663 [Radio_Surface](INFO): Powering up
2018-08-01T06:44:30.318Z,1533105870.318 [Radio_Surface](INFO): Powering down
2018-08-01T06:44:54.260Z,1533105894.260 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:45:01.866Z,1533105901.866 [Radio_Surface](INFO): Powering up
2018-08-01T06:45:07.522Z,1533105907.522 [Radio_Surface](INFO): Powering down
2018-08-01T06:45:41.466Z,1533105941.466 [Radio_Surface](INFO): Powering up
2018-08-01T06:45:47.122Z,1533105947.122 [Radio_Surface](INFO): Powering down
2018-08-01T06:45:54.258Z,1533105954.258 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:46:21.070Z,1533105981.070 [Radio_Surface](INFO): Powering up
2018-08-01T06:46:26.726Z,1533105986.726 [Radio_Surface](INFO): Powering down
2018-08-01T06:46:55.058Z,1533106015.058 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:46:59.866Z,1533106019.866 [Radio_Surface](INFO): Powering up
2018-08-01T06:47:05.522Z,1533106025.522 [Radio_Surface](INFO): Powering down
2018-08-01T06:47:37.870Z,1533106057.870 [Radio_Surface](INFO): Powering up
2018-08-01T06:47:43.526Z,1533106063.526 [Radio_Surface](INFO): Powering down
2018-08-01T06:47:55.058Z,1533106075.058 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:48:15.466Z,1533106095.466 [Radio_Surface](INFO): Powering up
2018-08-01T06:48:21.122Z,1533106101.122 [Radio_Surface](INFO): Powering down
2018-08-01T06:48:52.266Z,1533106132.266 [Radio_Surface](INFO): Powering up
2018-08-01T06:48:55.060Z,1533106135.060 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:48:57.922Z,1533106137.922 [Radio_Surface](INFO): Powering down
2018-08-01T06:49:29.866Z,1533106169.866 [Radio_Surface](INFO): Powering up
2018-08-01T06:49:35.530Z,1533106175.530 [Radio_Surface](INFO): Powering down
2018-08-01T06:49:55.858Z,1533106195.858 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:50:09.070Z,1533106209.070 [Radio_Surface](INFO): Powering up
2018-08-01T06:50:14.762Z,1533106214.762 [Radio_Surface](INFO): Powering down
2018-08-01T06:50:44.666Z,1533106244.666 [Radio_Surface](INFO): Powering up
2018-08-01T06:50:50.322Z,1533106250.322 [Radio_Surface](INFO): Powering down
2018-08-01T06:50:55.858Z,1533106255.858 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:51:24.266Z,1533106284.266 [Radio_Surface](INFO): Powering up
2018-08-01T06:51:29.930Z,1533106289.930 [Radio_Surface](INFO): Powering down
2018-08-01T06:51:55.858Z,1533106315.858 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:52:01.866Z,1533106321.866 [Radio_Surface](INFO): Powering up
2018-08-01T06:52:07.522Z,1533106327.522 [Radio_Surface](INFO): Powering down
2018-08-01T06:52:40.264Z,1533106360.264 [Radio_Surface](INFO): Powering up
2018-08-01T06:52:45.918Z,1533106365.918 [Radio_Surface](INFO): Powering down
2018-08-01T06:52:56.258Z,1533106376.258 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:53:20.270Z,1533106400.270 [Radio_Surface](INFO): Powering up
2018-08-01T06:53:25.926Z,1533106405.926 [Radio_Surface](INFO): Powering down
2018-08-01T06:53:57.060Z,1533106437.060 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:53:57.070Z,1533106437.070 [Radio_Surface](INFO): Powering up
2018-08-01T06:54:02.726Z,1533106442.726 [Radio_Surface](INFO): Powering down
2018-08-01T06:54:35.864Z,1533106475.864 [Radio_Surface](INFO): Powering up
2018-08-01T06:54:41.518Z,1533106481.518 [Radio_Surface](INFO): Powering down
2018-08-01T06:54:57.058Z,1533106497.058 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:55:15.466Z,1533106515.466 [Radio_Surface](INFO): Powering up
2018-08-01T06:55:21.126Z,1533106521.126 [Radio_Surface](INFO): Powering down
2018-08-01T06:55:54.670Z,1533106554.670 [Radio_Surface](INFO): Powering up
2018-08-01T06:55:57.858Z,1533106557.858 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:56:00.346Z,1533106560.346 [Radio_Surface](INFO): Powering down
2018-08-01T06:56:31.866Z,1533106591.866 [Radio_Surface](INFO): Powering up
2018-08-01T06:56:37.542Z,1533106597.542 [Radio_Surface](INFO): Powering down
2018-08-01T06:56:58.258Z,1533106618.258 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:57:09.064Z,1533106629.064 [Radio_Surface](INFO): Powering up
2018-08-01T06:57:14.718Z,1533106634.718 [Radio_Surface](INFO): Powering down
2018-08-01T06:57:48.270Z,1533106668.270 [Radio_Surface](INFO): Powering up
2018-08-01T06:57:53.938Z,1533106673.938 [Radio_Surface](INFO): Powering down
2018-08-01T06:57:58.258Z,1533106678.258 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:58:25.864Z,1533106705.864 [Radio_Surface](INFO): Powering up
2018-08-01T06:58:31.519Z,1533106711.519 [Radio_Surface](INFO): Powering down
2018-08-01T06:58:59.058Z,1533106739.058 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T06:59:05.066Z,1533106745.066 [Radio_Surface](INFO): Powering up
2018-08-01T06:59:10.722Z,1533106750.722 [Radio_Surface](INFO): Powering down
2018-08-01T06:59:44.666Z,1533106784.666 [Radio_Surface](INFO): Powering up
2018-08-01T06:59:50.322Z,1533106790.322 [Radio_Surface](INFO): Powering down
2018-08-01T06:59:59.058Z,1533106799.058 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:00:23.466Z,1533106823.466 [Radio_Surface](INFO): Powering up
2018-08-01T07:00:29.122Z,1533106829.122 [Radio_Surface](INFO): Powering down
2018-08-01T07:00:59.458Z,1533106859.458 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:01:00.266Z,1533106860.266 [Radio_Surface](INFO): Powering up
2018-08-01T07:01:05.922Z,1533106865.922 [Radio_Surface](INFO): Powering down
2018-08-01T07:01:37.866Z,1533106897.866 [Radio_Surface](INFO): Powering up
2018-08-01T07:01:43.522Z,1533106903.522 [Radio_Surface](INFO): Powering down
2018-08-01T07:01:59.858Z,1533106919.858 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:02:15.070Z,1533106935.070 [Radio_Surface](INFO): Powering up
2018-08-01T07:02:20.734Z,1533106940.734 [Radio_Surface](INFO): Powering down
2018-08-01T07:02:49.866Z,1533106969.866 [Radio_Surface](INFO): Powering up
2018-08-01T07:02:55.522Z,1533106975.522 [Radio_Surface](INFO): Powering down
2018-08-01T07:03:00.658Z,1533106980.658 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:03:27.066Z,1533107007.066 [Radio_Surface](INFO): Powering up
2018-08-01T07:03:32.722Z,1533107012.722 [Radio_Surface](INFO): Powering down
2018-08-01T07:04:00.658Z,1533107040.658 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:04:06.666Z,1533107046.666 [Radio_Surface](INFO): Powering up
2018-08-01T07:04:12.322Z,1533107052.322 [Radio_Surface](INFO): Powering down
2018-08-01T07:04:45.066Z,1533107085.066 [Radio_Surface](INFO): Powering up
2018-08-01T07:04:50.726Z,1533107090.726 [Radio_Surface](INFO): Powering down
2018-08-01T07:05:01.458Z,1533107101.458 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:05:24.270Z,1533107124.270 [Radio_Surface](INFO): Powering up
2018-08-01T07:05:29.934Z,1533107129.934 [Radio_Surface](INFO): Powering down
2018-08-01T07:06:01.458Z,1533107161.458 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:06:02.666Z,1533107162.666 [Radio_Surface](INFO): Powering up
2018-08-01T07:06:08.322Z,1533107168.322 [Radio_Surface](INFO): Powering down
2018-08-01T07:06:38.667Z,1533107198.667 [Radio_Surface](INFO): Powering up
2018-08-01T07:06:44.326Z,1533107204.326 [Radio_Surface](INFO): Powering down
2018-08-01T07:07:01.458Z,1533107221.458 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:07:15.066Z,1533107235.066 [Radio_Surface](INFO): Powering up
2018-08-01T07:07:20.738Z,1533107240.738 [Radio_Surface](INFO): Powering down
2018-08-01T07:07:53.066Z,1533107273.066 [Radio_Surface](INFO): Powering up
2018-08-01T07:07:58.726Z,1533107278.726 [Radio_Surface](INFO): Powering down
2018-08-01T07:08:02.258Z,1533107282.258 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:08:29.866Z,1533107309.866 [Radio_Surface](INFO): Powering up
2018-08-01T07:08:35.522Z,1533107315.522 [Radio_Surface](INFO): Powering down
2018-08-01T07:09:02.658Z,1533107342.658 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:09:09.466Z,1533107349.466 [Radio_Surface](INFO): Powering up
2018-08-01T07:09:15.122Z,1533107355.122 [Radio_Surface](INFO): Powering down
2018-08-01T07:09:47.466Z,1533107387.466 [Radio_Surface](INFO): Powering up
2018-08-01T07:09:53.122Z,1533107393.122 [Radio_Surface](INFO): Powering down
2018-08-01T07:10:03.058Z,1533107403.058 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:10:26.266Z,1533107426.266 [Radio_Surface](INFO): Powering up
2018-08-01T07:10:31.922Z,1533107431.922 [Radio_Surface](INFO): Powering down
2018-08-01T07:11:03.058Z,1533107463.058 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:11:04.666Z,1533107464.666 [Radio_Surface](INFO): Powering up
2018-08-01T07:11:10.323Z,1533107470.323 [Radio_Surface](INFO): Powering down
2018-08-01T07:11:43.066Z,1533107503.066 [Radio_Surface](INFO): Powering up
2018-08-01T07:11:48.722Z,1533107508.722 [Radio_Surface](INFO): Powering down
2018-08-01T07:12:03.058Z,1533107523.058 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:12:23.066Z,1533107543.066 [Radio_Surface](INFO): Powering up
2018-08-01T07:12:28.722Z,1533107548.722 [Radio_Surface](INFO): Powering down
2018-08-01T07:13:01.870Z,1533107581.870 [Radio_Surface](INFO): Powering up
2018-08-01T07:13:03.458Z,1533107583.458 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:13:07.526Z,1533107587.526 [Radio_Surface](INFO): Powering down
2018-08-01T07:13:40.664Z,1533107620.664 [Radio_Surface](INFO): Powering up
2018-08-01T07:13:46.318Z,1533107626.318 [Radio_Surface](INFO): Powering down
2018-08-01T07:14:03.458Z,1533107643.458 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:14:19.064Z,1533107659.064 [Radio_Surface](INFO): Powering up
2018-08-01T07:14:24.718Z,1533107664.718 [Radio_Surface](INFO): Powering down
2018-08-01T07:14:31.495Z,1533107671.495 [ESPComponent](IMPORTANT): ESP sampling state: S_PROCESSING
2018-08-01T07:14:33.894Z,1533107673.894 [ESPComponent](IMPORTANT): ESP sampling state: S_WAITING_FOR_PROCESSED
2018-08-01T07:14:58.666Z,1533107698.666 [Radio_Surface](INFO): Powering up
2018-08-01T07:15:03.459Z,1533107703.459 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:15:04.326Z,1533107704.326 [Radio_Surface](INFO): Powering down
2018-08-01T07:15:35.466Z,1533107735.466 [Radio_Surface](INFO): Powering up
2018-08-01T07:15:41.123Z,1533107741.123 [Radio_Surface](INFO): Powering down
2018-08-01T07:16:03.858Z,1533107763.858 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:16:11.466Z,1533107771.466 [Radio_Surface](INFO): Powering up
2018-08-01T07:16:17.122Z,1533107777.122 [Radio_Surface](INFO): Powering down
2018-08-01T07:16:48.266Z,1533107808.266 [Radio_Surface](INFO): Powering up
2018-08-01T07:16:53.922Z,1533107813.922 [Radio_Surface](INFO): Powering down
2018-08-01T07:17:04.258Z,1533107824.258 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:17:27.466Z,1533107847.466 [Radio_Surface](INFO): Powering up
2018-08-01T07:17:33.122Z,1533107853.122 [Radio_Surface](INFO): Powering down
2018-08-01T07:18:04.658Z,1533107884.658 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:18:04.666Z,1533107884.666 [Radio_Surface](INFO): Powering up
2018-08-01T07:18:10.322Z,1533107890.322 [Radio_Surface](INFO): Powering down
2018-08-01T07:18:44.266Z,1533107924.266 [Radio_Surface](INFO): Powering up
2018-08-01T07:18:49.922Z,1533107929.922 [Radio_Surface](INFO): Powering down
2018-08-01T07:19:05.458Z,1533107945.458 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:19:20.266Z,1533107960.266 [Radio_Surface](INFO): Powering up
2018-08-01T07:19:25.922Z,1533107965.922 [Radio_Surface](INFO): Powering down
2018-08-01T07:19:59.866Z,1533107999.866 [Radio_Surface](INFO): Powering up
2018-08-01T07:20:05.522Z,1533108005.522 [Radio_Surface](INFO): Powering down
2018-08-01T07:20:05.858Z,1533108005.858 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:20:38.266Z,1533108038.266 [Radio_Surface](INFO): Powering up
2018-08-01T07:20:43.922Z,1533108043.922 [Radio_Surface](INFO): Powering down
2018-08-01T07:21:05.858Z,1533108065.858 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:21:17.066Z,1533108077.066 [Radio_Surface](INFO): Powering up
2018-08-01T07:21:22.722Z,1533108082.722 [Radio_Surface](INFO): Powering down
2018-08-01T07:21:55.066Z,1533108115.066 [Radio_Surface](INFO): Powering up
2018-08-01T07:22:00.722Z,1533108120.722 [Radio_Surface](INFO): Powering down
2018-08-01T07:22:06.258Z,1533108126.258 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:22:34.666Z,1533108154.666 [Radio_Surface](INFO): Powering up
2018-08-01T07:22:40.322Z,1533108160.322 [Radio_Surface](INFO): Powering down
2018-08-01T07:23:06.658Z,1533108186.658 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:23:11.866Z,1533108191.866 [Radio_Surface](INFO): Powering up
2018-08-01T07:23:17.522Z,1533108197.522 [Radio_Surface](INFO): Powering down
2018-08-01T07:23:49.473Z,1533108229.473 [Radio_Surface](INFO): Powering up
2018-08-01T07:23:55.130Z,1533108235.130 [Radio_Surface](INFO): Powering down
2018-08-01T07:24:07.458Z,1533108247.458 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:24:28.666Z,1533108268.666 [Radio_Surface](INFO): Powering up
2018-08-01T07:24:34.322Z,1533108274.322 [Radio_Surface](INFO): Powering down
2018-08-01T07:25:05.466Z,1533108305.466 [Radio_Surface](INFO): Powering up
2018-08-01T07:25:07.458Z,1533108307.458 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:25:11.122Z,1533108311.122 [Radio_Surface](INFO): Powering down
2018-08-01T07:25:43.866Z,1533108343.866 [Radio_Surface](INFO): Powering up
2018-08-01T07:25:49.522Z,1533108349.522 [Radio_Surface](INFO): Powering down
2018-08-01T07:25:59.891Z,1533108359.891 [ESPComponent](IMPORTANT): ESP sampling state: S_STOPPING
2018-08-01T07:26:07.858Z,1533108367.858 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:26:21.466Z,1533108381.466 [Radio_Surface](INFO): Powering up
2018-08-01T07:26:26.288Z,1533108386.288 [ESPComponent](IMPORTANT): ESP sampling sequence completed normally (sample #3)
2018-08-01T07:26:26.289Z,1533108386.289 [ESPComponent](DEBUG): Writing samplingActive=0, sampleNumber=3
2018-08-01T07:26:26.326Z,1533108386.326 [sample:SampleAtDepth:SampleWrapper:SampleESP:WaitForESP] Stopped
2018-08-01T07:26:26.326Z,1533108386.326 [sample:SampleAtDepth:SampleWrapper:SampleESP](INFO): Completed sample:SampleAtDepth:SampleWrapper:SampleESP
2018-08-01T07:26:26.326Z,1533108386.326 [sample:SampleAtDepth:SampleWrapper:SampleESP] Stopped
2018-08-01T07:26:26.327Z,1533108386.327 [sample:SampleAtDepth:SampleWrapper:SampleESP](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper:SampleESP
2018-08-01T07:26:26.327Z,1533108386.327 [sample:SampleAtDepth:SampleWrapper](INFO): Completed sample:SampleAtDepth:SampleWrapper
2018-08-01T07:26:26.327Z,1533108386.327 [sample:SampleAtDepth:SampleWrapper] Stopped
2018-08-01T07:26:26.327Z,1533108386.327 [sample:SampleAtDepth:SampleWrapper](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper
2018-08-01T07:26:26.328Z,1533108386.328 [sample:SampleAtDepth](INFO): Completed sample:SampleAtDepth
2018-08-01T07:26:26.328Z,1533108386.328 [sample:SampleAtDepth] Stopped
2018-08-01T07:26:26.328Z,1533108386.328 [sample:SampleAtDepth](DEBUG): Aggregate::uninitialize sample:SampleAtDepth
2018-08-01T07:26:26.328Z,1533108386.328 [sample:SampleAtDepth:B.Pitch] Stopped
2018-08-01T07:26:26.695Z,1533108386.695 [ESPComponent](IMPORTANT): No ESP summary messages.
2018-08-01T07:26:26.695Z,1533108386.695 [ESPComponent](INFO): powering down ESP
2018-08-01T07:26:26.837Z,1533108386.837 [sample:SampleRepeater:Sample](INFO): Completed sample:SampleRepeater:Sample
2018-08-01T07:26:26.837Z,1533108386.837 [sample:SampleRepeater:Sample] Stopped
2018-08-01T07:26:26.837Z,1533108386.837 [sample:SampleRepeater:Sample](DEBUG): Aggregate::uninitialize sample:SampleRepeater:Sample
2018-08-01T07:26:26.837Z,1533108386.837 [sample:SampleRepeater](INFO): Completed sample:SampleRepeater
2018-08-01T07:26:26.838Z,1533108386.838 [sample:SampleRepeater] Stopped
2018-08-01T07:26:26.838Z,1533108386.838 [sample:SampleRepeater](DEBUG): Aggregate::uninitialize sample:SampleRepeater
2018-08-01T07:26:26.839Z,1533108386.839 [sample](INFO): Completed sample
2018-08-01T07:26:26.839Z,1533108386.839 [MissionManager](INFO): sample is completed.
2018-08-01T07:26:26.839Z,1533108386.839 [MissionManager](INFO): Uninitializing Mission sample
2018-08-01T07:26:26.840Z,1533108386.840 [sample] Stopped
2018-08-01T07:26:26.840Z,1533108386.840 [sample](DEBUG): Aggregate::uninitialize sample
2018-08-01T07:26:26.840Z,1533108386.840 [sample:A.Pitch] Stopped
2018-08-01T07:26:26.840Z,1533108386.840 [sample:B.SetSpeed] Stopped
2018-08-01T07:26:26.840Z,1533108386.840 [sample:B.SetSpeed](DEBUG): Uninitialize.
2018-08-01T07:26:27.114Z,1533108387.114 [MissionManager](IMPORTANT): Started mission Default
2018-08-01T07:26:27.114Z,1533108387.114 [Default] Running Loop=1
2018-08-01T07:26:27.114Z,1533108387.114 [Default](DEBUG): Aggregate::initialize Default
2018-08-01T07:26:27.114Z,1533108387.114 [Default:B.GoToSurface] Running Loop=1
2018-08-01T07:26:27.114Z,1533108387.114 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-08-01T07:26:27.115Z,1533108387.115 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-08-01T07:26:27.115Z,1533108387.115 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-08-01T07:26:27.115Z,1533108387.115 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-08-01T07:26:27.116Z,1533108387.116 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-08-01T07:26:27.116Z,1533108387.116 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-08-01T07:26:27.122Z,1533108387.122 [Radio_Surface](INFO): Powering down
2018-08-01T07:26:27.137Z,1533108387.137 [Default:A.Wait] Running Loop=1
2018-08-01T07:26:27.137Z,1533108387.137 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-08-01T07:26:27.511Z,1533108387.511 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 30.00 deg, mass-position -13.00 mm (1 active estimators).
2018-08-01T07:26:35.218Z,1533108395.218 [Radio_Surface](INFO): Powering up
2018-08-01T07:26:40.459Z,1533108400.459 [Default:A.Wait](INFO): Done Waiting.
2018-08-01T07:26:40.459Z,1533108400.459 [Default:A.Wait] Stopped
2018-08-01T07:26:40.459Z,1533108400.459 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T07:26:40.874Z,1533108400.874 [Radio_Surface](INFO): Powering down
2018-08-01T07:27:08.406Z,1533108428.406 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:27:14.814Z,1533108434.814 [Radio_Surface](INFO): Powering up
2018-08-01T07:27:20.470Z,1533108440.470 [Radio_Surface](INFO): Powering down
2018-08-01T07:27:54.014Z,1533108474.014 [Radio_Surface](INFO): Powering up
2018-08-01T07:27:59.678Z,1533108479.678 [Radio_Surface](INFO): Powering down
2018-08-01T07:28:08.806Z,1533108488.806 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:28:32.810Z,1533108512.810 [Radio_Surface](INFO): Powering up
2018-08-01T07:28:38.466Z,1533108518.466 [Radio_Surface](INFO): Powering down
2018-08-01T07:29:08.806Z,1533108548.806 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:29:11.614Z,1533108551.614 [Radio_Surface](INFO): Powering up
2018-08-01T07:29:17.270Z,1533108557.270 [Radio_Surface](INFO): Powering down
2018-08-01T07:29:50.412Z,1533108590.412 [Radio_Surface](INFO): Powering up
2018-08-01T07:29:56.066Z,1533108596.066 [Radio_Surface](INFO): Powering down
2018-08-01T07:30:08.807Z,1533108608.807 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:30:28.814Z,1533108628.814 [Radio_Surface](INFO): Powering up
2018-08-01T07:30:34.470Z,1533108634.470 [Radio_Surface](INFO): Powering down
2018-08-01T07:31:08.414Z,1533108668.414 [Radio_Surface](INFO): Powering up
2018-08-01T07:31:09.206Z,1533108669.206 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:31:14.070Z,1533108674.070 [Radio_Surface](INFO): Powering down
2018-08-01T07:31:27.263Z,1533108687.263 [VerticalControl](CRITICAL): Failure to ascend, stopping mission after 300.119263 seconds, depthRate=0.069022 m/s, pitch=86.127640 deg.
2018-08-01T07:31:27.295Z,1533108687.295 [CommandLine](FAULT): Scheduling is paused
2018-08-01T07:31:27.296Z,1533108687.296 [CBIT](INFO): Critical error at 20180801T073127
2018-08-01T07:31:27.296Z,1533108687.296 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2018-08-01T07:31:48.414Z,1533108708.414 [Radio_Surface](INFO): Powering up
2018-08-01T07:31:54.070Z,1533108714.070 [Radio_Surface](INFO): Powering down
2018-08-01T07:32:09.206Z,1533108729.206 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:32:27.616Z,1533108747.616 [Radio_Surface](INFO): Powering up
2018-08-01T07:32:33.271Z,1533108753.271 [Radio_Surface](INFO): Powering down
2018-08-01T07:33:05.214Z,1533108785.214 [Radio_Surface](INFO): Powering up
2018-08-01T07:33:09.606Z,1533108789.606 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:33:10.871Z,1533108790.871 [Radio_Surface](INFO): Powering down
2018-08-01T07:33:44.418Z,1533108824.418 [Radio_Surface](INFO): Powering up
2018-08-01T07:33:50.074Z,1533108830.074 [Radio_Surface](INFO): Powering down
2018-08-01T07:34:10.006Z,1533108850.006 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:34:23.214Z,1533108863.214 [Radio_Surface](INFO): Powering up
2018-08-01T07:34:28.883Z,1533108868.883 [Radio_Surface](INFO): Powering down
2018-08-01T07:35:01.214Z,1533108901.214 [Radio_Surface](INFO): Powering up
2018-08-01T07:35:06.870Z,1533108906.870 [Radio_Surface](INFO): Powering down
2018-08-01T07:35:10.006Z,1533108910.006 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:35:40.414Z,1533108940.414 [Radio_Surface](INFO): Powering up
2018-08-01T07:35:46.074Z,1533108946.074 [Radio_Surface](INFO): Powering down
2018-08-01T07:36:10.006Z,1533108970.006 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:36:19.618Z,1533108979.618 [Radio_Surface](INFO): Powering up
2018-08-01T07:36:25.275Z,1533108985.275 [Radio_Surface](INFO): Powering down
2018-08-01T07:36:27.662Z,1533108987.662 [VerticalControl](CRITICAL): Failure to ascend, dropping drop weight after 300.397980 seconds, depthRate=0.069022 m/s, pitch=86.089233 deg.
2018-08-01T07:36:27.719Z,1533108987.719 [CBIT](INFO): Critical error at 20180801T073627
2018-08-01T07:36:58.414Z,1533109018.414 [Radio_Surface](INFO): Powering up
2018-08-01T07:37:04.070Z,1533109024.070 [Radio_Surface](INFO): Powering down
2018-08-01T07:37:10.406Z,1533109030.406 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:37:37.612Z,1533109057.612 [Radio_Surface](INFO): Powering up
2018-08-01T07:37:43.266Z,1533109063.266 [Radio_Surface](INFO): Powering down
2018-08-01T07:37:59.119Z,1533109079.119 [CommandLine](IMPORTANT): got command show stack
2018-08-01T07:37:59.119Z,1533109079.119 [CommandLine](IMPORTANT): Behavior Stack:

2018-08-01T07:37:59.119Z,1533109079.119 [Default](IMPORTANT): Priority 0: Default:B.GoToSurface
2018-08-01T07:38:02.002Z,1533109082.002 [CommandLine](IMPORTANT): got command maintain clear
2018-08-01T07:38:02.150Z,1533109082.150 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,NAL9602,Onboard,PNI_TCM,BPC1,Aanderaa_O2,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-08-01T07:38:02.480Z,1533109082.480 [Default:CheckIn] Running Loop=1
2018-08-01T07:38:02.480Z,1533109082.480 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T07:38:02.480Z,1533109082.480 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T07:38:02.658Z,1533109082.658 [Radio_Surface](INFO): Powering up
2018-08-01T07:38:03.218Z,1533109083.218 [NAL9602](INFO): Powering up
2018-08-01T07:38:08.495Z,1533109088.495 [CommandLine](IMPORTANT): got command get depth
2018-08-01T07:38:08.495Z,1533109088.495 [CommandLine](IMPORTANT): depth -0.081610 m
2018-08-01T07:38:10.934Z,1533109090.934 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:38:14.138Z,1533109094.138 [NAL9602](INFO): NAL9602 initialized
2018-08-01T07:38:14.938Z,1533109094.938 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-08-01T07:38:14.938Z,1533109094.938 [NAL9602] Data Fault, FailCount= 1
2018-08-01T07:38:14.938Z,1533109094.938 [NAL9602](ERROR): Data Fault
2018-08-01T07:38:15.058Z,1533109095.058 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T07:38:15.338Z,1533109095.338 [NAL9602](INFO): Powering down
2018-08-01T07:38:16.278Z,1533109096.278 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T07:38:16.278Z,1533109096.278 [NAL9602] No Fault, FailCount= 1
2018-08-01T07:38:45.738Z,1533109125.738 [NAL9602](INFO): Powering up NAL9602
2018-08-01T07:38:56.942Z,1533109136.942 [NAL9602](INFO): NAL9602 initialized
2018-08-01T07:39:10.934Z,1533109150.934 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:40:11.334Z,1533109211.334 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-08-01T07:40:45.809Z,1533109245.809 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002728
2018-08-01T07:42:45.975Z,1533109365.975 [DataOverHttps](IMPORTANT): SBD MTMSN=20180801T073634
2018-08-01T07:42:47.622Z,1533109367.622 [CommandLine](IMPORTANT): got command show stack
2018-08-01T07:42:47.622Z,1533109367.622 [CommandLine](IMPORTANT): Behavior Stack:

2018-08-01T07:42:47.622Z,1533109367.622 [Default](IMPORTANT): Priority 0: Default:B.GoToSurface
2018-08-01T07:42:47.622Z,1533109367.622 [Default:CheckIn](IMPORTANT): Priority 1: Default:CheckIn:Read_GPS