2018-09-12T01:13:04.846Z,1536714784.846 [Supervisor](DEBUG): Initializing supervisor.
2018-09-12T01:13:04.849Z,1536714784.849 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-09-12T01:13:04.850Z,1536714784.850 [SyncHandler](INFO): Protected caller Thread ID is 800
2018-09-12T01:13:04.850Z,1536714784.850 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-09-12T01:13:04.851Z,1536714784.851 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-09-12T01:13:04.851Z,1536714784.851 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 801
2018-09-12T01:13:04.854Z,1536714784.854 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-09-12T01:13:04.866Z,1536714784.866 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-09-12T01:13:04.867Z,1536714784.867 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-09-12T01:13:04.867Z,1536714784.867 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 802
2018-09-12T01:13:04.868Z,1536714784.868 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-09-12T01:13:04.869Z,1536714784.869 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-09-12T01:13:04.869Z,1536714784.869 [logger ThreadHandler](INFO): Protected caller Thread ID is 803
2018-09-12T01:13:04.871Z,1536714784.871 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-09-12T01:13:04.872Z,1536714784.872 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-09-12T01:13:04.878Z,1536714784.878 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-09-12T01:13:05.224Z,1536714785.224 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-09-12T01:13:05.226Z,1536714785.226 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-09-12T01:13:05.427Z,1536714785.427 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-09-12T01:13:05.428Z,1536714785.428 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-09-12T01:13:05.896Z,1536714785.896 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-09-12T01:13:05.897Z,1536714785.897 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-09-12T01:13:05.998Z,1536714785.998 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-09-12T01:13:05.998Z,1536714785.998 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-09-12T01:13:06.206Z,1536714786.206 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-09-12T01:13:06.206Z,1536714786.206 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-09-12T01:13:06.344Z,1536714786.344 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-09-12T01:13:06.345Z,1536714786.345 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-09-12T01:13:06.690Z,1536714786.690 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-09-12T01:13:06.691Z,1536714786.691 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-09-12T01:13:06.772Z,1536714786.772 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-09-12T01:13:06.871Z,1536714786.871 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-09-12T01:13:06.872Z,1536714786.872 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-09-12T01:13:06.980Z,1536714786.980 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-09-12T01:13:06.981Z,1536714786.981 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-09-12T01:13:07.303Z,1536714787.303 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-09-12T01:13:07.304Z,1536714787.304 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-09-12T01:13:07.516Z,1536714787.516 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-09-12T01:13:07.517Z,1536714787.517 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-09-12T01:13:07.971Z,1536714787.971 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-09-12T01:13:07.972Z,1536714787.972 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-09-12T01:13:08.119Z,1536714788.119 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-09-12T01:13:08.120Z,1536714788.120 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-09-12T01:13:08.656Z,1536714788.656 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-09-12T01:13:08.658Z,1536714788.658 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-tethys/
2018-09-12T01:13:08.663Z,1536714788.663 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys/Control.cfg
2018-09-12T01:13:08.761Z,1536714788.761 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys/Navigation.cfg
2018-09-12T01:13:08.854Z,1536714788.854 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys/Simulator.cfg
2018-09-12T01:13:08.941Z,1536714788.941 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys/logger.cfg
2018-09-12T01:13:09.022Z,1536714789.022 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys/Battery.cfg
2018-09-12T01:13:09.256Z,1536714789.256 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-09-12T01:13:09.257Z,1536714789.257 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys/Science.cfg
2018-09-12T01:13:09.398Z,1536714789.398 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys/secure.cfg
2018-09-12T01:13:09.483Z,1536714789.483 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys/workSite.cfg
2018-09-12T01:13:09.575Z,1536714789.575 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys/Servo.cfg
2018-09-12T01:13:09.674Z,1536714789.674 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys/BIT.cfg
2018-09-12T01:13:09.772Z,1536714789.772 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys/Sensor.cfg
2018-09-12T01:13:09.917Z,1536714789.917 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys/vehicle.cfg
2018-09-12T01:13:10.116Z,1536714790.116 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-09-12T01:13:10.127Z,1536714790.127 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-09-12T01:13:10.282Z,1536714790.282 [SBIT](DEBUG): Construct Startup Built In Test.
2018-09-12T01:13:10.312Z,1536714790.312 [SBIT] Loaded
2018-09-12T01:13:10.313Z,1536714790.313 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-09-12T01:13:10.313Z,1536714790.313 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-09-12T01:13:10.341Z,1536714790.341 [IBIT] Loaded
2018-09-12T01:13:10.342Z,1536714790.342 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-09-12T01:13:10.345Z,1536714790.345 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-09-12T01:13:10.502Z,1536714790.502 [CBIT] Loaded
2018-09-12T01:13:10.503Z,1536714790.503 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-09-12T01:13:10.503Z,1536714790.503 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-09-12T01:13:10.505Z,1536714790.505 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-09-12T01:13:10.543Z,1536714790.543 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-09-12T01:13:10.543Z,1536714790.543 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-09-12T01:13:10.785Z,1536714790.785 [CTD_Seabird] Loaded
2018-09-12T01:13:10.785Z,1536714790.785 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2018-09-12T01:13:10.786Z,1536714790.786 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 405B74E0
2018-09-12T01:13:10.787Z,1536714790.787 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 885
2018-09-12T01:13:10.805Z,1536714790.805 [ESPComponent] Loaded
2018-09-12T01:13:10.806Z,1536714790.806 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2018-09-12T01:13:10.820Z,1536714790.820 [PAR_Licor] Loaded
2018-09-12T01:13:10.820Z,1536714790.820 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-09-12T01:13:10.870Z,1536714790.870 [WetLabsBB2FL] Loaded
2018-09-12T01:13:10.870Z,1536714790.870 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-09-12T01:13:10.871Z,1536714790.871 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 405E74E0
2018-09-12T01:13:10.871Z,1536714790.871 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 886
2018-09-12T01:13:10.872Z,1536714790.872 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-09-12T01:13:10.873Z,1536714790.873 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-09-12T01:13:10.998Z,1536714790.998 [BuoyancyServo] Loaded
2018-09-12T01:13:10.998Z,1536714790.998 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-09-12T01:13:11.013Z,1536714791.013 [ElevatorServo] Loaded
2018-09-12T01:13:11.013Z,1536714791.013 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-09-12T01:13:11.028Z,1536714791.028 [MassServo] Loaded
2018-09-12T01:13:11.028Z,1536714791.028 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-09-12T01:13:11.043Z,1536714791.043 [RudderServo] Loaded
2018-09-12T01:13:11.043Z,1536714791.043 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-09-12T01:13:11.058Z,1536714791.058 [ThrusterServo] Loaded
2018-09-12T01:13:11.058Z,1536714791.058 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-09-12T01:13:11.059Z,1536714791.059 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-09-12T01:13:11.059Z,1536714791.059 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-09-12T01:13:11.341Z,1536714791.341 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-09-12T01:13:11.342Z,1536714791.342 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-09-12T01:13:11.956Z,1536714791.956 [AHRS_M2] Loaded
2018-09-12T01:13:11.957Z,1536714791.957 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2018-09-12T01:13:12.092Z,1536714792.092 [DataOverHttps] Loaded
2018-09-12T01:13:12.092Z,1536714792.092 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-09-12T01:13:12.105Z,1536714792.105 [Depth_Keller] Loaded
2018-09-12T01:13:12.106Z,1536714792.106 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-09-12T01:13:12.111Z,1536714792.111 [DropWeight] Loaded
2018-09-12T01:13:12.111Z,1536714792.111 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-09-12T01:13:12.202Z,1536714792.202 [NAL9602] Loaded
2018-09-12T01:13:12.203Z,1536714792.203 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-09-12T01:13:12.208Z,1536714792.208 [Onboard] Loaded
2018-09-12T01:13:12.208Z,1536714792.208 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-09-12T01:13:12.215Z,1536714792.215 [Radio_Surface] Loaded
2018-09-12T01:13:12.215Z,1536714792.215 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-09-12T01:13:12.216Z,1536714792.216 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408CE4E0
2018-09-12T01:13:12.217Z,1536714792.217 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 887
2018-09-12T01:13:12.246Z,1536714792.246 [RDI_Pathfinder] Loaded
2018-09-12T01:13:12.247Z,1536714792.247 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2018-09-12T01:13:12.377Z,1536714792.377 [DAT] Loaded
2018-09-12T01:13:12.377Z,1536714792.377 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2018-09-12T01:13:14.188Z,1536714794.188 [BPC1] Loaded
2018-09-12T01:13:14.188Z,1536714794.188 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-09-12T01:13:14.189Z,1536714794.189 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-09-12T01:13:14.189Z,1536714794.189 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-09-12T01:13:14.217Z,1536714794.217 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-09-12T01:13:14.658Z,1536714794.658 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-09-12T01:13:14.774Z,1536714794.774 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-09-12T01:13:14.775Z,1536714794.775 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-09-12T01:13:14.893Z,1536714794.893 [DeadReckonUsingMultipleVelocitySources] Loaded
2018-09-12T01:13:14.893Z,1536714794.893 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2018-09-12T01:13:14.949Z,1536714794.949 [DeadReckonUsingSpeedCalculator] Loaded
2018-09-12T01:13:14.949Z,1536714794.949 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-09-12T01:13:14.965Z,1536714794.965 [NavChart] Loaded
2018-09-12T01:13:14.966Z,1536714794.966 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-09-12T01:13:14.970Z,1536714794.970 [UniversalFixResidualReporter] Loaded
2018-09-12T01:13:14.970Z,1536714794.970 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-09-12T01:13:14.970Z,1536714794.970 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-09-12T01:13:14.971Z,1536714794.971 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-09-12T01:13:15.100Z,1536714795.100 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-09-12T01:13:15.101Z,1536714795.101 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-09-12T01:13:15.190Z,1536714795.190 [VerticalControl](DEBUG): Construct VerticalControl.
2018-09-12T01:13:15.279Z,1536714795.279 [VerticalControl] Loaded
2018-09-12T01:13:15.280Z,1536714795.280 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-09-12T01:13:15.280Z,1536714795.280 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-09-12T01:13:15.338Z,1536714795.338 [HorizontalControl] Loaded
2018-09-12T01:13:15.339Z,1536714795.339 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-09-12T01:13:15.339Z,1536714795.339 [SpeedControl](DEBUG): Construct SpeedControl.
2018-09-12T01:13:15.342Z,1536714795.342 [SpeedControl] Loaded
2018-09-12T01:13:15.342Z,1536714795.342 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-09-12T01:13:15.343Z,1536714795.343 [LoopControl](DEBUG): Construct LoopControl.
2018-09-12T01:13:15.343Z,1536714795.343 [LoopControl] Loaded
2018-09-12T01:13:15.343Z,1536714795.343 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-09-12T01:13:15.344Z,1536714795.344 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-09-12T01:13:15.344Z,1536714795.344 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-09-12T01:13:15.400Z,1536714795.400 [DepthRateCalculator] Loaded
2018-09-12T01:13:15.400Z,1536714795.400 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-09-12T01:13:15.406Z,1536714795.406 [PitchRateCalculator] Loaded
2018-09-12T01:13:15.406Z,1536714795.406 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-09-12T01:13:15.419Z,1536714795.419 [SpeedCalculator] Loaded
2018-09-12T01:13:15.419Z,1536714795.419 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-09-12T01:13:15.440Z,1536714795.440 [TempGradientCalculator] Loaded
2018-09-12T01:13:15.441Z,1536714795.441 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-09-12T01:13:15.456Z,1536714795.456 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2018-09-12T01:13:15.457Z,1536714795.457 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2018-09-12T01:13:15.462Z,1536714795.462 [YawRateCalculator] Loaded
2018-09-12T01:13:15.462Z,1536714795.462 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-09-12T01:13:15.492Z,1536714795.492 [ElevatorOffsetCalculator] Loaded
2018-09-12T01:13:15.493Z,1536714795.493 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-09-12T01:13:15.493Z,1536714795.493 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-09-12T01:13:15.497Z,1536714795.497 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-09-12T01:13:15.498Z,1536714795.498 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-09-12T01:13:15.504Z,1536714795.504 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-09-12T01:13:15.506Z,1536714795.506 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A064E0
2018-09-12T01:13:15.506Z,1536714795.506 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 888
2018-09-12T01:13:15.511Z,1536714795.511 [Supervisor](INFO): Main Thread ID is 796
2018-09-12T01:13:15.511Z,1536714795.511 [Supervisor](DEBUG): Running supervisor.
2018-09-12T01:13:15.511Z,1536714795.511 [CommandLine ThreadHandler](INFO): Handler Thread ID is 889
2018-09-12T01:13:15.514Z,1536714795.514 [controlThread ThreadHandler](INFO): Handler Thread ID is 890
2018-09-12T01:13:15.514Z,1536714795.514 [controlThread](DEBUG): Initializing ControlThread
2018-09-12T01:13:15.515Z,1536714795.515 [SBIT](INFO): Initialize SBIT Component.
2018-09-12T01:13:15.516Z,1536714795.516 [SBIT](IMPORTANT): git: 2018-09-06
2018-09-12T01:13:15.516Z,1536714795.516 [SBIT](INFO): git hash: 66a1d3cbc6e0267838eeaa8d8b2ab3dc44228fef
2018-09-12T01:13:15.516Z,1536714795.516 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-09-12T01:13:15.518Z,1536714795.518 [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-09-12T01:13:15.519Z,1536714795.519 [SBIT](INFO): Beginning SBIT in 28.000000 seconds.
2018-09-12T01:13:15.519Z,1536714795.519 [IBIT](INFO): Initialize IBIT Component.
2018-09-12T01:13:15.520Z,1536714795.520 [CBIT](DEBUG): Initialize CBIT Component.
2018-09-12T01:13:15.520Z,1536714795.520 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-09-12T01:13:15.521Z,1536714795.521 [logger ThreadHandler](INFO): Handler Thread ID is 891
2018-09-12T01:13:15.538Z,1536714795.538 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 892
2018-09-12T01:13:15.539Z,1536714795.539 [CTD_Seabird](INFO): Initializing
2018-09-12T01:13:15.539Z,1536714795.539 [CTD_Seabird](INFO): Checking LCM
2018-09-12T01:13:15.637Z,1536714795.637 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2018-09-12T01:13:15.638Z,1536714795.638 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2018-09-12T01:13:15.638Z,1536714795.638 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2018-09-12T01:13:15.642Z,1536714795.642 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-09-12T01:13:15.643Z,1536714795.643 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-09-12T01:13:15.643Z,1536714795.643 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-09-12T01:13:15.643Z,1536714795.643 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-09-12T01:13:15.644Z,1536714795.644 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-09-12T01:13:15.644Z,1536714795.644 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-09-12T01:13:15.648Z,1536714795.648 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-09-12T01:13:15.675Z,1536714795.675 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-09-12T01:13:15.675Z,1536714795.675 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-09-12T01:13:15.675Z,1536714795.675 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-09-12T01:13:15.676Z,1536714795.676 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-09-12T01:13:15.676Z,1536714795.676 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-09-12T01:13:15.677Z,1536714795.677 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-09-12T01:13:15.677Z,1536714795.677 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2018-09-12T01:13:15.678Z,1536714795.678 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 893
2018-09-12T01:13:15.680Z,1536714795.680 [WetLabsBB2FL](INFO): Powering down
2018-09-12T01:13:15.706Z,1536714795.706 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-09-12T01:13:15.706Z,1536714795.706 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-09-12T01:13:15.708Z,1536714795.708 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-09-12T01:13:15.809Z,1536714795.809 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 894
2018-09-12T01:13:15.826Z,1536714795.826 [Radio_Surface](INFO): Powering up
2018-09-12T01:13:15.828Z,1536714795.828 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-09-12T01:13:15.891Z,1536714795.891 [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-09-12T01:13:15.892Z,1536714795.892 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 895
2018-09-12T01:13:15.895Z,1536714795.895 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-09-12T01:13:15.945Z,1536714795.945 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-09-12T01:13:15.945Z,1536714795.945 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-09-12T01:13:15.945Z,1536714795.945 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-09-12T01:13:15.945Z,1536714795.945 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-09-12T01:13:15.946Z,1536714795.946 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-09-12T01:13:15.946Z,1536714795.946 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-09-12T01:13:15.946Z,1536714795.946 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-09-12T01:13:15.946Z,1536714795.946 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-09-12T01:13:15.946Z,1536714795.946 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-09-12T01:13:15.946Z,1536714795.946 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-09-12T01:13:15.947Z,1536714795.947 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-09-12T01:13:15.947Z,1536714795.947 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-09-12T01:13:15.947Z,1536714795.947 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-09-12T01:13:15.947Z,1536714795.947 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-09-12T01:13:15.948Z,1536714795.948 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-09-12T01:13:15.948Z,1536714795.948 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-09-12T01:13:15.963Z,1536714795.963 [CTD_Seabird](INFO): LCM OK
2018-09-12T01:13:15.963Z,1536714795.963 [CTD_Seabird](INFO): Powering up
2018-09-12T01:13:16.039Z,1536714796.039 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-09-12T01:13:16.040Z,1536714796.040 [Default:A.Wait](DEBUG): Construct Wait.
2018-09-12T01:13:16.058Z,1536714796.058 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-09-12T01:13:16.096Z,1536714796.096 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-09-12T01:13:16.098Z,1536714796.098 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-09-12T01:13:16.120Z,1536714796.120 [Default:E.Execute](DEBUG): Construct Execute.
2018-09-12T01:13:16.124Z,1536714796.124 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2018-09-12T01:13:16.143Z,1536714796.143 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,RDI_Pathfinder,DAT,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-09-12T01:13:16.167Z,1536714796.167 [ESPComponent](INFO): powering down ESP
2018-09-12T01:13:16.610Z,1536714796.610 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2018-09-12T01:13:16.728Z,1536714796.728 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-09-12T01:13:16.753Z,1536714796.753 [Depth_Keller](ERROR): Pressure reading out of range: 2102.507080 decibar
2018-09-12T01:13:16.863Z,1536714796.863 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2018-09-12T01:13:16.863Z,1536714796.863 [DAT](INFO): Powering up
2018-09-12T01:13:16.863Z,1536714796.863 [DAT](DEBUG): Initializing DAT.
2018-09-12T01:13:16.910Z,1536714796.910 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2018-09-12T01:13:17.058Z,1536714797.058 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-09-12T01:13:17.158Z,1536714797.158 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-12T01:13:17.217Z,1536714797.217 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-12T01:13:17.334Z,1536714797.334 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-09-12T01:13:17.342Z,1536714797.342 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-09-12T01:13:17.365Z,1536714797.365 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-09-12T01:13:17.366Z,1536714797.366 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-09-12T01:13:17.389Z,1536714797.389 [MassServo](DEBUG): Initializing EZServoServo.
2018-09-12T01:13:17.394Z,1536714797.394 [MassServo](DEBUG): Initializing MassServo.
2018-09-12T01:13:17.416Z,1536714797.416 [RudderServo](DEBUG): Initializing EZServoServo.
2018-09-12T01:13:17.422Z,1536714797.422 [RudderServo](DEBUG): Initializing RudderServo.
2018-09-12T01:13:17.445Z,1536714797.445 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-09-12T01:13:17.454Z,1536714797.454 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-09-12T01:13:17.777Z,1536714797.777 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-12T01:13:17.786Z,1536714797.786 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-12T01:13:18.022Z,1536714798.022 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-12T01:13:18.023Z,1536714798.023 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-12T01:13:18.522Z,1536714798.522 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-12T01:13:18.523Z,1536714798.523 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-12T01:13:18.893Z,1536714798.893 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-12T01:13:18.914Z,1536714798.914 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-12T01:13:19.293Z,1536714799.293 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-12T01:13:19.310Z,1536714799.310 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-12T01:13:19.693Z,1536714799.693 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-12T01:13:19.710Z,1536714799.710 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-12T01:13:20.130Z,1536714800.130 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-12T01:13:20.146Z,1536714800.146 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-12T01:13:21.386Z,1536714801.386 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-09-12T01:13:21.495Z,1536714801.495 [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-09-12T01:13:21.650Z,1536714801.650 [CTD_Seabird](INFO): LCM subscribed to channel:seabird_gpctd_t.seabird-gpctd
2018-09-12T01:13:22.019Z,1536714802.019 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-09-12T01:13:22.019Z,1536714802.019 [CTD_Seabird](INFO): Powering down
2018-09-12T01:13:30.489Z,1536714810.489 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2018-09-12T01:13:33.289Z,1536714813.289 [DAT](INFO): setting local address to 6
2018-09-12T01:13:33.740Z,1536714813.740 [DAT](INFO): set local address to 6
2018-09-12T01:13:42.472Z,1536714822.472 [NAL9602](INFO): Powering up NAL9602
2018-09-12T01:13:44.136Z,1536714824.136 [SBIT](IMPORTANT): Beginning Startup BIT
2018-09-12T01:13:44.141Z,1536714824.141 [CBIT](IMPORTANT): Beginning ground fault scan
2018-09-12T01:13:53.412Z,1536714833.412 [NAL9602](INFO): NAL9602 initialized
2018-09-12T01:13:55.128Z,1536714835.128 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.017425
CHAN A1 (24V): 0.181186
CHAN A2 (12V): -0.004779
CHAN A3 (5V): -0.002698
CHAN B0 (3.3V): -0.001093
CHAN B1 (3.15aV): -0.001682
CHAN B2 (3.15bV): -0.001326
CHAN B3 (GND): -0.000554
OPEN: 0.005388
Full Scale Calc: 4.765 mA, -1.589 mA
2018-09-12T01:14:08.013Z,1536714848.013 [NAL9602](INFO): SBD MO Status=0, MOMSN=49100, MT Status=0, MTMSN=0
2018-09-12T01:14:08.013Z,1536714848.013 [NAL9602](INFO): No messages in MT queue
2018-09-12T01:14:38.212Z,1536714878.212 [SBIT](IMPORTANT): SBIT PASSED
2018-09-12T01:14:38.255Z,1536714878.255 [CommandLine](IMPORTANT): got command configSet list
2018-09-12T01:14:38.255Z,1536714878.255 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-09-12T01:14:38.256Z,1536714878.256 [CommandLine](IMPORTANT): DataOverHttps.connectionTimeout=60 second;

2018-09-12T01:14:38.256Z,1536714878.256 [CommandLine](IMPORTANT): DataOverHttps.period=30 second;

2018-09-12T01:14:38.256Z,1536714878.256 [CommandLine](IMPORTANT): DataOverHttps.timeout=1 minute;

2018-09-12T01:14:38.606Z,1536714878.606 [MissionManager](IMPORTANT): Started mission Startup
2018-09-12T01:14:38.607Z,1536714878.607 [Startup] Running Loop=1
2018-09-12T01:14:38.607Z,1536714878.607 [Startup](DEBUG): Aggregate::initialize Startup
2018-09-12T01:14:38.607Z,1536714878.607 [Startup:A.GoToSurface] Running Loop=1
2018-09-12T01:14:38.607Z,1536714878.607 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-09-12T01:14:38.608Z,1536714878.608 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-09-12T01:14:38.608Z,1536714878.608 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-09-12T01:14:38.608Z,1536714878.608 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-09-12T01:14:38.609Z,1536714878.609 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-09-12T01:14:38.609Z,1536714878.609 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-09-12T01:14:38.647Z,1536714878.647 [Startup:StartupSatComms] Running Loop=1
2018-09-12T01:14:38.648Z,1536714878.648 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-09-12T01:14:38.648Z,1536714878.648 [Startup:StartupSatComms:A] Running Loop=1
2018-09-12T01:14:39.016Z,1536714879.016 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-09-12T01:15:38.648Z,1536714938.648 [Startup:StartupSatComms:A](INFO): Timed out from 2018-09-12T01:14:38.6Z
2018-09-12T01:15:38.649Z,1536714938.649 [Startup:StartupSatComms:A] Stopped
2018-09-12T01:15:38.649Z,1536714938.649 [Startup:StartupSatComms:B] Running Loop=1
2018-09-12T01:15:39.016Z,1536714939.016 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-09-12T01:16:03.914Z,1536714963.914 [NAL9602](INFO): SBD MO Status=1, MOMSN=49101, MT Status=0, MTMSN=0
2018-09-12T01:16:03.966Z,1536714963.966 [NAL9602](INFO): Sent 25 bytes from file Logs/20180911T234333/Courier0022.lzma
2018-09-12T01:16:03.966Z,1536714963.966 [NAL9602](INFO): Packets left to send: 0
2018-09-12T01:16:03.968Z,1536714963.968 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180911T234333/Courier0022.lzma.parts/0000.sbd
2018-09-12T01:16:03.968Z,1536714963.968 [NAL9602](DEBUG): Completed sending Logs/20180911T234333/Courier0022.lzma
2018-09-12T01:16:15.729Z,1536714975.729 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-09-12T01:16:15.729Z,1536714975.729 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2018-09-12T01:16:15.729Z,1536714975.729 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2018-09-12T01:16:15.731Z,1536714975.731 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-09-12T01:16:15.731Z,1536714975.731 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2018-09-12T01:16:15.731Z,1536714975.731 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-09-12T01:16:15.769Z,1536714975.769 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2018-09-12T01:16:15.769Z,1536714975.769 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-09-12T01:16:16.136Z,1536714976.136 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2018-09-12T01:16:16.136Z,1536714976.136 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2018-09-12T01:16:16.136Z,1536714976.136 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-09-12T01:16:16.136Z,1536714976.136 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2018-09-12T01:16:16.527Z,1536714976.527 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2018-09-12T01:16:16.527Z,1536714976.527 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2018-09-12T01:16:16.528Z,1536714976.528 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2018-09-12T01:16:16.528Z,1536714976.528 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-09-12T01:16:16.529Z,1536714976.529 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-09-12T01:16:16.529Z,1536714976.529 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-09-12T01:16:16.924Z,1536714976.924 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.2 s old, using for 20.0 s.
2018-09-12T01:16:17.331Z,1536714977.331 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.6 s old, using for 20.0 s.
2018-09-12T01:16:17.765Z,1536714977.765 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.0 s old, using for 20.0 s.
2018-09-12T01:16:18.115Z,1536714978.115 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.4 s old, using for 20.0 s.
2018-09-12T01:16:18.516Z,1536714978.516 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.8 s old, using for 20.0 s.
2018-09-12T01:16:18.931Z,1536714978.931 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.2 s old, using for 20.0 s.
2018-09-12T01:16:19.314Z,1536714979.314 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.6 s old, using for 20.0 s.
2018-09-12T01:16:19.759Z,1536714979.759 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.0 s old, using for 20.0 s.
2018-09-12T01:16:20.121Z,1536714980.121 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.4 s old, using for 20.0 s.
2018-09-12T01:16:20.534Z,1536714980.534 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.8 s old, using for 20.0 s.
2018-09-12T01:16:20.877Z,1536714980.877 [NAL9602](INFO): SBD MO Status=1, MOMSN=49102, MT Status=0, MTMSN=0
2018-09-12T01:16:20.928Z,1536714980.928 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:16:20.928Z,1536714980.928 [NAL9602](INFO): Packets left to send: 107
2018-09-12T01:16:20.929Z,1536714980.929 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0107.sbd
2018-09-12T01:16:20.970Z,1536714980.970 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.2 s old, using for 20.0 s.
2018-09-12T01:16:21.739Z,1536714981.739 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.0 s old, using for 20.0 s.
2018-09-12T01:16:21.843Z,1536714981.843 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.1 s old, using for 20.0 s.
2018-09-12T01:16:24.276Z,1536714984.276 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.5 s old, using for 20.0 s.
2018-09-12T01:16:24.437Z,1536714984.437 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.7 s old, using for 20.0 s.
2018-09-12T01:16:24.753Z,1536714984.753 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.0 s old, using for 20.0 s.
2018-09-12T01:16:25.146Z,1536714985.146 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.4 s old, using for 20.0 s.
2018-09-12T01:16:25.578Z,1536714985.578 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.9 s old, using for 20.0 s.
2018-09-12T01:16:25.956Z,1536714985.956 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.2 s old, using for 20.0 s.
2018-09-12T01:16:26.349Z,1536714986.349 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.6 s old, using for 20.0 s.
2018-09-12T01:16:26.776Z,1536714986.776 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.0 s old, using for 20.0 s.
2018-09-12T01:16:27.154Z,1536714987.154 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.4 s old, using for 20.0 s.
2018-09-12T01:16:27.584Z,1536714987.584 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.9 s old, using for 20.0 s.
2018-09-12T01:16:27.956Z,1536714987.956 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.2 s old, using for 20.0 s.
2018-09-12T01:16:28.357Z,1536714988.357 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.6 s old, using for 20.0 s.
2018-09-12T01:16:28.770Z,1536714988.770 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.0 s old, using for 20.0 s.
2018-09-12T01:16:29.160Z,1536714989.160 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.4 s old, using for 20.0 s.
2018-09-12T01:16:29.553Z,1536714989.553 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.8 s old, using for 20.0 s.
2018-09-12T01:16:29.000Z,1536714990.000 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.3 s old, using for 20.0 s.
2018-09-12T01:16:30.392Z,1536714990.392 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.7 s old, using for 20.0 s.
2018-09-12T01:16:30.765Z,1536714990.765 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.0 s old, using for 20.0 s.
2018-09-12T01:16:31.121Z,1536714991.121 [NAL9602](INFO): SBD MO Status=1, MOMSN=49103, MT Status=0, MTMSN=0
2018-09-12T01:16:31.187Z,1536714991.187 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:16:31.188Z,1536714991.188 [NAL9602](INFO): Packets left to send: 106
2018-09-12T01:16:31.190Z,1536714991.190 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0106.sbd
2018-09-12T01:16:31.225Z,1536714991.225 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.5 s old, using for 20.0 s.
2018-09-12T01:16:31.905Z,1536714991.905 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.2 s old, using for 20.0 s.
2018-09-12T01:16:32.014Z,1536714992.014 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.3 s old, using for 20.0 s.
2018-09-12T01:16:34.434Z,1536714994.434 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.7 s old, using for 20.0 s.
2018-09-12T01:16:34.576Z,1536714994.576 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.8 s old, using for 20.0 s.
2018-09-12T01:16:34.957Z,1536714994.957 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.2 s old, using for 20.0 s.
2018-09-12T01:16:35.360Z,1536714995.360 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.6 s old, using for 20.0 s.
2018-09-12T01:16:38.954Z,1536714998.954 [Startup:StartupSatComms:B](INFO): Timed out from 2018-09-12T01:15:38.6Z
2018-09-12T01:16:38.954Z,1536714998.954 [Startup:StartupSatComms:B] Stopped
2018-09-12T01:16:38.955Z,1536714998.955 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-09-12T01:16:38.955Z,1536714998.955 [Startup:StartupSatComms] Stopped
2018-09-12T01:16:38.955Z,1536714998.955 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-09-12T01:16:38.956Z,1536714998.956 [Startup](INFO): Completed Startup
2018-09-12T01:16:38.956Z,1536714998.956 [MissionManager](INFO): Startup is completed.
2018-09-12T01:16:38.956Z,1536714998.956 [MissionManager](INFO): Uninitializing Mission Startup
2018-09-12T01:16:38.956Z,1536714998.956 [Startup] Stopped
2018-09-12T01:16:38.956Z,1536714998.956 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-09-12T01:16:38.957Z,1536714998.957 [Startup:A.GoToSurface] Stopped
2018-09-12T01:16:38.957Z,1536714998.957 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-09-12T01:16:39.350Z,1536714999.350 [MissionManager](IMPORTANT): Started mission Default
2018-09-12T01:16:39.350Z,1536714999.350 [Default] Running Loop=1
2018-09-12T01:16:39.350Z,1536714999.350 [Default](DEBUG): Aggregate::initialize Default
2018-09-12T01:16:39.350Z,1536714999.350 [Default:B.GoToSurface] Running Loop=1
2018-09-12T01:16:39.350Z,1536714999.350 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-09-12T01:16:39.351Z,1536714999.351 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-09-12T01:16:39.351Z,1536714999.351 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-09-12T01:16:39.351Z,1536714999.351 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-09-12T01:16:39.352Z,1536714999.352 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-09-12T01:16:39.352Z,1536714999.352 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-09-12T01:16:39.352Z,1536714999.352 [Default:A.Wait] Running Loop=1
2018-09-12T01:16:39.352Z,1536714999.352 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-09-12T01:16:40.513Z,1536715000.513 [NAL9602](INFO): SBD MO Status=1, MOMSN=49104, MT Status=0, MTMSN=0
2018-09-12T01:16:40.575Z,1536715000.575 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:16:40.575Z,1536715000.575 [NAL9602](INFO): Packets left to send: 105
2018-09-12T01:16:40.577Z,1536715000.577 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0105.sbd
2018-09-12T01:16:52.560Z,1536715012.560 [Default:A.Wait](INFO): Done Waiting.
2018-09-12T01:16:52.560Z,1536715012.560 [Default:A.Wait] Stopped
2018-09-12T01:16:52.560Z,1536715012.560 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-09-12T01:16:52.967Z,1536715012.967 [Default:CheckIn] Running Loop=1
2018-09-12T01:16:52.967Z,1536715012.967 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-09-12T01:16:52.968Z,1536715012.968 [Default:CheckIn:Read_GPS] Running Loop=1
2018-09-12T01:16:53.395Z,1536715013.395 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-09-12T01:19:16.578Z,1536715156.578 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-09-12T01:19:16.578Z,1536715156.578 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2018-09-12T01:19:16.578Z,1536715156.578 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2018-09-12T01:19:16.580Z,1536715156.580 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-09-12T01:19:16.580Z,1536715156.580 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2018-09-12T01:19:16.581Z,1536715156.581 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-09-12T01:19:16.620Z,1536715156.620 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2018-09-12T01:19:16.621Z,1536715156.621 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-09-12T01:19:16.987Z,1536715156.987 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2018-09-12T01:19:16.987Z,1536715156.987 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2018-09-12T01:19:16.988Z,1536715156.988 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-09-12T01:19:16.988Z,1536715156.988 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2018-09-12T01:19:17.359Z,1536715157.359 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2018-09-12T01:19:17.360Z,1536715157.360 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2018-09-12T01:19:17.360Z,1536715157.360 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2018-09-12T01:19:17.360Z,1536715157.360 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-09-12T01:19:17.361Z,1536715157.361 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-09-12T01:19:17.361Z,1536715157.361 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-09-12T01:19:17.783Z,1536715157.783 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.2 s old, using for 20.0 s.
2018-09-12T01:19:18.148Z,1536715158.148 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.6 s old, using for 20.0 s.
2018-09-12T01:19:18.548Z,1536715158.548 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.0 s old, using for 20.0 s.
2018-09-12T01:19:18.961Z,1536715158.961 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.4 s old, using for 20.0 s.
2018-09-12T01:19:19.343Z,1536715159.343 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.8 s old, using for 20.0 s.
2018-09-12T01:19:19.787Z,1536715159.787 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.2 s old, using for 20.0 s.
2018-09-12T01:19:20.147Z,1536715160.147 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.6 s old, using for 20.0 s.
2018-09-12T01:19:20.571Z,1536715160.571 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.0 s old, using for 20.0 s.
2018-09-12T01:19:20.952Z,1536715160.952 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.4 s old, using for 20.0 s.
2018-09-12T01:19:21.404Z,1536715161.404 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.8 s old, using for 20.0 s.
2018-09-12T01:19:21.751Z,1536715161.751 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.2 s old, using for 20.0 s.
2018-09-12T01:19:22.136Z,1536715162.136 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.6 s old, using for 20.0 s.
2018-09-12T01:19:22.561Z,1536715162.561 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.0 s old, using for 20.0 s.
2018-09-12T01:19:22.969Z,1536715162.969 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.4 s old, using for 20.0 s.
2018-09-12T01:19:23.404Z,1536715163.404 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.8 s old, using for 20.0 s.
2018-09-12T01:19:23.769Z,1536715163.769 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.2 s old, using for 20.0 s.
2018-09-12T01:19:24.141Z,1536715164.141 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.6 s old, using for 20.0 s.
2018-09-12T01:19:24.580Z,1536715164.580 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.0 s old, using for 20.0 s.
2018-09-12T01:19:24.973Z,1536715164.973 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.4 s old, using for 20.0 s.
2018-09-12T01:19:25.382Z,1536715165.382 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.8 s old, using for 20.0 s.
2018-09-12T01:19:25.756Z,1536715165.756 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.2 s old, using for 20.0 s.
2018-09-12T01:19:26.145Z,1536715166.145 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.6 s old, using for 20.0 s.
2018-09-12T01:19:26.558Z,1536715166.558 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.0 s old, using for 20.0 s.
2018-09-12T01:19:26.956Z,1536715166.956 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.4 s old, using for 20.0 s.
2018-09-12T01:19:27.349Z,1536715167.349 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.8 s old, using for 20.0 s.
2018-09-12T01:19:27.755Z,1536715167.755 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.2 s old, using for 20.0 s.
2018-09-12T01:19:28.147Z,1536715168.147 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.6 s old, using for 20.0 s.
2018-09-12T01:19:28.545Z,1536715168.545 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.0 s old, using for 20.0 s.
2018-09-12T01:19:28.960Z,1536715168.960 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.4 s old, using for 20.0 s.
2018-09-12T01:19:29.356Z,1536715169.356 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.8 s old, using for 20.0 s.
2018-09-12T01:19:29.799Z,1536715169.799 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.2 s old, using for 20.0 s.
2018-09-12T01:19:30.153Z,1536715170.153 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.6 s old, using for 20.0 s.
2018-09-12T01:19:30.601Z,1536715170.601 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.0 s old, using for 20.0 s.
2018-09-12T01:19:30.937Z,1536715170.937 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.4 s old, using for 20.0 s.
2018-09-12T01:19:31.374Z,1536715171.374 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.8 s old, using for 20.0 s.
2018-09-12T01:19:31.760Z,1536715171.760 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.2 s old, using for 20.0 s.
2018-09-12T01:19:32.129Z,1536715172.129 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.6 s old, using for 20.0 s.
2018-09-12T01:19:32.568Z,1536715172.568 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.0 s old, using for 20.0 s.
2018-09-12T01:19:32.964Z,1536715172.964 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.4 s old, using for 20.0 s.
2018-09-12T01:19:33.412Z,1536715173.412 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.9 s old, using for 20.0 s.
2018-09-12T01:19:33.753Z,1536715173.753 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.2 s old, using for 20.0 s.
2018-09-12T01:19:34.136Z,1536715174.136 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.6 s old, using for 20.0 s.
2018-09-12T01:19:34.560Z,1536715174.560 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.0 s old, using for 20.0 s.
2018-09-12T01:19:34.968Z,1536715174.968 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.4 s old, using for 20.0 s.
2018-09-12T01:19:35.388Z,1536715175.388 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.8 s old, using for 20.0 s.
2018-09-12T01:19:35.772Z,1536715175.772 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.2 s old, using for 20.0 s.
2018-09-12T01:19:36.137Z,1536715176.137 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.6 s old, using for 20.0 s.
2018-09-12T01:19:36.544Z,1536715176.544 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 20.0 s old, using for 20.0 s.
2018-09-12T01:19:41.313Z,1536715181.313 [NAL9602](INFO): GPS fix at 20180912T011903: (36.865568, -122.241094)
2018-09-12T01:19:41.406Z,1536715181.406 [Default:CheckIn:Read_GPS] Stopped
2018-09-12T01:19:41.407Z,1536715181.407 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-09-12T01:19:41.826Z,1536715181.826 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-09-12T01:20:10.788Z,1536715210.788 [NAL9602](INFO): SBD MO Status=1, MOMSN=49105, MT Status=0, MTMSN=0
2018-09-12T01:20:10.851Z,1536715210.851 [NAL9602](INFO): Sent 212 bytes from file Logs/20180912T011304/Courier0004.lzma
2018-09-12T01:20:10.851Z,1536715210.851 [NAL9602](INFO): Packets left to send: 0
2018-09-12T01:20:10.853Z,1536715210.853 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180912T011304/Courier0004.lzma.parts/0000.sbd
2018-09-12T01:20:10.853Z,1536715210.853 [NAL9602](DEBUG): Completed sending Logs/20180912T011304/Courier0004.lzma
2018-09-12T01:20:25.347Z,1536715225.347 [NAL9602](INFO): SBD MO Status=1, MOMSN=49106, MT Status=0, MTMSN=0
2018-09-12T01:20:25.394Z,1536715225.394 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:20:25.394Z,1536715225.394 [NAL9602](INFO): Packets left to send: 104
2018-09-12T01:20:25.395Z,1536715225.395 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0104.sbd
2018-09-12T01:20:49.076Z,1536715249.076 [NAL9602](INFO): SBD MO Status=2, MOMSN=49107, MT Status=2, MTMSN=0
2018-09-12T01:20:49.077Z,1536715249.077 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-12T01:21:12.176Z,1536715272.176 [NAL9602](INFO): SBD MO Status=1, MOMSN=49107, MT Status=0, MTMSN=0
2018-09-12T01:21:12.234Z,1536715272.234 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:21:12.234Z,1536715272.234 [NAL9602](INFO): Packets left to send: 103
2018-09-12T01:21:12.235Z,1536715272.235 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0103.sbd
2018-09-12T01:21:25.560Z,1536715285.560 [NAL9602](INFO): SBD MO Status=1, MOMSN=49108, MT Status=0, MTMSN=0
2018-09-12T01:21:25.610Z,1536715285.610 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:21:25.610Z,1536715285.610 [NAL9602](INFO): Packets left to send: 102
2018-09-12T01:21:25.612Z,1536715285.612 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0102.sbd
2018-09-12T01:21:39.739Z,1536715299.739 [NAL9602](INFO): SBD MO Status=1, MOMSN=49109, MT Status=0, MTMSN=0
2018-09-12T01:21:39.788Z,1536715299.788 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:21:39.788Z,1536715299.788 [NAL9602](INFO): Packets left to send: 101
2018-09-12T01:21:39.790Z,1536715299.790 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0101.sbd
2018-09-12T01:21:52.749Z,1536715312.749 [NAL9602](INFO): SBD MO Status=1, MOMSN=49110, MT Status=0, MTMSN=0
2018-09-12T01:21:52.798Z,1536715312.798 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:21:52.798Z,1536715312.798 [NAL9602](INFO): Packets left to send: 100
2018-09-12T01:21:52.799Z,1536715312.799 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0100.sbd
2018-09-12T01:22:02.131Z,1536715322.131 [NAL9602](INFO): SBD MO Status=1, MOMSN=49111, MT Status=0, MTMSN=0
2018-09-12T01:22:02.187Z,1536715322.187 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:22:02.187Z,1536715322.187 [NAL9602](INFO): Packets left to send: 99
2018-09-12T01:22:02.188Z,1536715322.188 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0099.sbd
2018-09-12T01:22:14.412Z,1536715334.412 [NAL9602](INFO): SBD MO Status=1, MOMSN=49112, MT Status=0, MTMSN=0
2018-09-12T01:22:14.466Z,1536715334.466 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:22:14.466Z,1536715334.466 [NAL9602](INFO): Packets left to send: 98
2018-09-12T01:22:14.468Z,1536715334.468 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0098.sbd
2018-09-12T01:22:26.150Z,1536715346.150 [NAL9602](INFO): SBD MO Status=1, MOMSN=49113, MT Status=0, MTMSN=0
2018-09-12T01:22:26.208Z,1536715346.208 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:22:26.208Z,1536715346.208 [NAL9602](INFO): Packets left to send: 97
2018-09-12T01:22:26.210Z,1536715346.210 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0097.sbd
2018-09-12T01:22:38.396Z,1536715358.396 [NAL9602](INFO): SBD MO Status=1, MOMSN=49114, MT Status=0, MTMSN=0
2018-09-12T01:22:38.459Z,1536715358.459 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:22:38.459Z,1536715358.459 [NAL9602](INFO): Packets left to send: 96
2018-09-12T01:22:38.460Z,1536715358.460 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0096.sbd
2018-09-12T01:22:48.729Z,1536715368.729 [NAL9602](INFO): SBD MO Status=1, MOMSN=49115, MT Status=0, MTMSN=0
2018-09-12T01:22:48.782Z,1536715368.782 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:22:48.782Z,1536715368.782 [NAL9602](INFO): Packets left to send: 95
2018-09-12T01:22:48.783Z,1536715368.783 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0095.sbd
2018-09-12T01:23:03.248Z,1536715383.248 [NAL9602](INFO): SBD MO Status=1, MOMSN=49116, MT Status=0, MTMSN=0
2018-09-12T01:23:03.298Z,1536715383.298 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:23:03.298Z,1536715383.298 [NAL9602](INFO): Packets left to send: 94
2018-09-12T01:23:03.300Z,1536715383.300 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0094.sbd
2018-09-12T01:23:14.372Z,1536715394.372 [NAL9602](INFO): SBD MO Status=1, MOMSN=49117, MT Status=0, MTMSN=0
2018-09-12T01:23:14.430Z,1536715394.430 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:23:14.430Z,1536715394.430 [NAL9602](INFO): Packets left to send: 93
2018-09-12T01:23:14.432Z,1536715394.432 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0093.sbd
2018-09-12T01:23:29.773Z,1536715409.773 [NAL9602](INFO): SBD MO Status=1, MOMSN=49118, MT Status=0, MTMSN=0
2018-09-12T01:23:29.834Z,1536715409.834 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:23:29.834Z,1536715409.834 [NAL9602](INFO): Packets left to send: 92
2018-09-12T01:23:29.836Z,1536715409.836 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0092.sbd
2018-09-12T01:23:42.712Z,1536715422.712 [NAL9602](INFO): SBD MO Status=1, MOMSN=49119, MT Status=0, MTMSN=0
2018-09-12T01:23:42.774Z,1536715422.774 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:23:42.774Z,1536715422.774 [NAL9602](INFO): Packets left to send: 91
2018-09-12T01:23:42.775Z,1536715422.775 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0091.sbd
2018-09-12T01:24:00.487Z,1536715440.487 [NAL9602](INFO): SBD MO Status=1, MOMSN=49120, MT Status=0, MTMSN=0
2018-09-12T01:24:00.542Z,1536715440.542 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:24:00.542Z,1536715440.542 [NAL9602](INFO): Packets left to send: 90
2018-09-12T01:24:00.544Z,1536715440.544 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0090.sbd
2018-09-12T01:24:09.196Z,1536715449.196 [NAL9602](INFO): SBD MO Status=1, MOMSN=49121, MT Status=0, MTMSN=0
2018-09-12T01:24:09.258Z,1536715449.258 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:24:09.258Z,1536715449.258 [NAL9602](INFO): Packets left to send: 89
2018-09-12T01:24:09.260Z,1536715449.260 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0089.sbd
2018-09-12T01:24:18.224Z,1536715458.224 [NAL9602](INFO): SBD MO Status=1, MOMSN=49122, MT Status=0, MTMSN=0
2018-09-12T01:24:18.274Z,1536715458.274 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:24:18.274Z,1536715458.274 [NAL9602](INFO): Packets left to send: 88
2018-09-12T01:24:18.276Z,1536715458.276 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0088.sbd
2018-09-12T01:24:26.892Z,1536715466.892 [NAL9602](INFO): SBD MO Status=1, MOMSN=49123, MT Status=0, MTMSN=0
2018-09-12T01:24:26.950Z,1536715466.950 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:24:26.950Z,1536715466.950 [NAL9602](INFO): Packets left to send: 87
2018-09-12T01:24:26.951Z,1536715466.951 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0087.sbd
2018-09-12T01:24:35.500Z,1536715475.500 [NAL9602](INFO): SBD MO Status=1, MOMSN=49124, MT Status=0, MTMSN=0
2018-09-12T01:24:35.554Z,1536715475.554 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:24:35.554Z,1536715475.554 [NAL9602](INFO): Packets left to send: 86
2018-09-12T01:24:35.555Z,1536715475.555 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0086.sbd
2018-09-12T01:24:43.845Z,1536715483.845 [NAL9602](INFO): SBD MO Status=1, MOMSN=49125, MT Status=0, MTMSN=0
2018-09-12T01:24:43.898Z,1536715483.898 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:24:43.898Z,1536715483.898 [NAL9602](INFO): Packets left to send: 85
2018-09-12T01:24:43.899Z,1536715483.899 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0085.sbd
2018-09-12T01:24:52.789Z,1536715492.789 [NAL9602](INFO): SBD MO Status=1, MOMSN=49126, MT Status=0, MTMSN=0
2018-09-12T01:24:52.842Z,1536715492.842 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:24:52.842Z,1536715492.842 [NAL9602](INFO): Packets left to send: 84
2018-09-12T01:24:52.844Z,1536715492.844 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0084.sbd
2018-09-12T01:25:03.477Z,1536715503.477 [NAL9602](INFO): SBD MO Status=1, MOMSN=49127, MT Status=0, MTMSN=0
2018-09-12T01:25:03.522Z,1536715503.522 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:25:03.522Z,1536715503.522 [NAL9602](INFO): Packets left to send: 83
2018-09-12T01:25:03.524Z,1536715503.524 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0083.sbd
2018-09-12T01:25:16.839Z,1536715516.839 [NAL9602](INFO): SBD MO Status=1, MOMSN=49128, MT Status=0, MTMSN=0
2018-09-12T01:25:16.886Z,1536715516.886 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:25:16.886Z,1536715516.886 [NAL9602](INFO): Packets left to send: 82
2018-09-12T01:25:16.888Z,1536715516.888 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0082.sbd
2018-09-12T01:25:25.802Z,1536715525.802 [NAL9602](INFO): SBD MO Status=1, MOMSN=49129, MT Status=0, MTMSN=0
2018-09-12T01:25:25.854Z,1536715525.854 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:25:25.854Z,1536715525.854 [NAL9602](INFO): Packets left to send: 81
2018-09-12T01:25:25.856Z,1536715525.856 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0081.sbd
2018-09-12T01:25:35.121Z,1536715535.121 [NAL9602](INFO): SBD MO Status=1, MOMSN=49130, MT Status=0, MTMSN=0
2018-09-12T01:25:35.179Z,1536715535.179 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:25:35.179Z,1536715535.179 [NAL9602](INFO): Packets left to send: 80
2018-09-12T01:25:35.181Z,1536715535.181 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0080.sbd
2018-09-12T01:25:50.167Z,1536715550.167 [NAL9602](INFO): SBD MO Status=2, MOMSN=49131, MT Status=2, MTMSN=0
2018-09-12T01:25:50.168Z,1536715550.168 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-12T01:26:10.048Z,1536715570.048 [NAL9602](INFO): SBD MO Status=1, MOMSN=49131, MT Status=0, MTMSN=0
2018-09-12T01:26:10.105Z,1536715570.105 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:26:10.105Z,1536715570.105 [NAL9602](INFO): Packets left to send: 79
2018-09-12T01:26:10.107Z,1536715570.107 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0079.sbd
2018-09-12T01:26:14.673Z,1536715574.673 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,-32768,-32768,-32768,-32768,V
2018-09-12T01:26:22.247Z,1536715582.247 [NAL9602](INFO): SBD MO Status=1, MOMSN=49132, MT Status=0, MTMSN=0
2018-09-12T01:26:22.307Z,1536715582.307 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:26:22.308Z,1536715582.308 [NAL9602](INFO): Packets left to send: 78
2018-09-12T01:26:22.310Z,1536715582.310 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0078.sbd
2018-09-12T01:26:35.385Z,1536715595.385 [NAL9602](INFO): SBD MO Status=1, MOMSN=49133, MT Status=0, MTMSN=0
2018-09-12T01:26:35.439Z,1536715595.439 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:26:35.439Z,1536715595.439 [NAL9602](INFO): Packets left to send: 77
2018-09-12T01:26:35.440Z,1536715595.440 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0077.sbd
2018-09-12T01:26:45.855Z,1536715605.855 [NAL9602](INFO): SBD MO Status=1, MOMSN=49134, MT Status=0, MTMSN=0
2018-09-12T01:26:45.910Z,1536715605.910 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:26:45.910Z,1536715605.910 [NAL9602](INFO): Packets left to send: 76
2018-09-12T01:26:45.912Z,1536715605.912 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0076.sbd
2018-09-12T01:26:56.025Z,1536715616.025 [NAL9602](INFO): SBD MO Status=1, MOMSN=49135, MT Status=0, MTMSN=0
2018-09-12T01:26:56.078Z,1536715616.078 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:26:56.078Z,1536715616.078 [NAL9602](INFO): Packets left to send: 75
2018-09-12T01:26:56.080Z,1536715616.080 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0075.sbd
2018-09-12T01:27:07.001Z,1536715627.001 [NAL9602](INFO): SBD MO Status=1, MOMSN=49136, MT Status=0, MTMSN=0
2018-09-12T01:27:07.054Z,1536715627.054 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:27:07.054Z,1536715627.054 [NAL9602](INFO): Packets left to send: 74
2018-09-12T01:27:07.056Z,1536715627.056 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0074.sbd
2018-09-12T01:27:11.714Z,1536715631.714 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,-32768,-32768,-32768,-32768,V
2018-09-12T01:27:18.072Z,1536715638.072 [NAL9602](INFO): SBD MO Status=1, MOMSN=49137, MT Status=0, MTMSN=0
2018-09-12T01:27:18.130Z,1536715638.130 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:27:18.130Z,1536715638.130 [NAL9602](INFO): Packets left to send: 73
2018-09-12T01:27:18.132Z,1536715638.132 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0073.sbd
2018-09-12T01:27:22.643Z,1536715642.643 [RDI_Pathfinder](ERROR): Failed to parse:
:HM,G,G,0e88,0e88, 14.181, -0.140, 0.000
2018-09-12T01:27:27.821Z,1536715647.821 [NAL9602](INFO): SBD MO Status=1, MOMSN=49138, MT Status=0, MTMSN=0
2018-09-12T01:27:27.874Z,1536715647.874 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:27:27.874Z,1536715647.874 [NAL9602](INFO): Packets left to send: 72
2018-09-12T01:27:27.876Z,1536715647.876 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0072.sbd
2018-09-12T01:27:38.369Z,1536715658.369 [NAL9602](INFO): SBD MO Status=1, MOMSN=49139, MT Status=0, MTMSN=0
2018-09-12T01:27:38.414Z,1536715658.414 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:27:38.414Z,1536715658.414 [NAL9602](INFO): Packets left to send: 71
2018-09-12T01:27:38.416Z,1536715658.416 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0071.sbd
2018-09-12T01:28:00.112Z,1536715680.112 [NAL9602](INFO): SBD MO Status=1, MOMSN=49140, MT Status=0, MTMSN=0
2018-09-12T01:28:00.170Z,1536715680.170 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:28:00.170Z,1536715680.170 [NAL9602](INFO): Packets left to send: 70
2018-09-12T01:28:00.172Z,1536715680.172 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0070.sbd
2018-09-12T01:28:17.948Z,1536715697.948 [NAL9602](INFO): SBD MO Status=2, MOMSN=49141, MT Status=2, MTMSN=0
2018-09-12T01:28:17.948Z,1536715697.948 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-12T01:28:50.993Z,1536715730.993 [NAL9602](INFO): SBD MO Status=1, MOMSN=49141, MT Status=0, MTMSN=0
2018-09-12T01:28:51.046Z,1536715731.046 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:28:51.046Z,1536715731.046 [NAL9602](INFO): Packets left to send: 69
2018-09-12T01:28:51.048Z,1536715731.048 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0069.sbd
2018-09-12T01:29:06.731Z,1536715746.731 [NAL9602](INFO): SBD MO Status=1, MOMSN=49142, MT Status=0, MTMSN=0
2018-09-12T01:29:06.776Z,1536715746.776 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:29:06.777Z,1536715746.777 [NAL9602](INFO): Packets left to send: 68
2018-09-12T01:29:06.778Z,1536715746.778 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0068.sbd
2018-09-12T01:29:21.702Z,1536715761.702 [NAL9602](INFO): SBD MO Status=2, MOMSN=49143, MT Status=2, MTMSN=0
2018-09-12T01:29:21.702Z,1536715761.702 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-12T01:29:49.944Z,1536715789.944 [NAL9602](INFO): SBD MO Status=1, MOMSN=49143, MT Status=0, MTMSN=0
2018-09-12T01:29:49.994Z,1536715789.994 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:29:49.994Z,1536715789.994 [NAL9602](INFO): Packets left to send: 67
2018-09-12T01:29:49.996Z,1536715789.996 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0067.sbd
2018-09-12T01:30:01.682Z,1536715801.682 [NAL9602](INFO): SBD MO Status=1, MOMSN=49144, MT Status=0, MTMSN=0
2018-09-12T01:30:01.734Z,1536715801.734 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:30:01.734Z,1536715801.734 [NAL9602](INFO): Packets left to send: 66
2018-09-12T01:30:01.736Z,1536715801.736 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0066.sbd
2018-09-12T01:30:17.163Z,1536715817.163 [NAL9602](INFO): SBD MO Status=1, MOMSN=49145, MT Status=0, MTMSN=0
2018-09-12T01:30:17.210Z,1536715817.210 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:30:17.210Z,1536715817.210 [NAL9602](INFO): Packets left to send: 65
2018-09-12T01:30:17.212Z,1536715817.212 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0065.sbd
2018-09-12T01:30:32.476Z,1536715832.476 [NAL9602](INFO): SBD MO Status=1, MOMSN=49146, MT Status=0, MTMSN=0
2018-09-12T01:30:32.530Z,1536715832.530 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:30:32.530Z,1536715832.530 [NAL9602](INFO): Packets left to send: 64
2018-09-12T01:30:32.532Z,1536715832.532 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0064.sbd
2018-09-12T01:30:50.241Z,1536715850.241 [NAL9602](INFO): SBD MO Status=2, MOMSN=49147, MT Status=2, MTMSN=0
2018-09-12T01:30:50.241Z,1536715850.241 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-12T01:31:19.613Z,1536715879.613 [NAL9602](INFO): SBD MO Status=2, MOMSN=49147, MT Status=2, MTMSN=0
2018-09-12T01:31:19.613Z,1536715879.613 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-12T01:31:48.591Z,1536715908.591 [NAL9602](INFO): SBD MO Status=1, MOMSN=49147, MT Status=0, MTMSN=0
2018-09-12T01:31:48.636Z,1536715908.636 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:31:48.636Z,1536715908.636 [NAL9602](INFO): Packets left to send: 63
2018-09-12T01:31:48.638Z,1536715908.638 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0063.sbd
2018-09-12T01:31:59.737Z,1536715919.737 [NAL9602](INFO): SBD MO Status=1, MOMSN=49148, MT Status=0, MTMSN=0
2018-09-12T01:31:59.783Z,1536715919.783 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:31:59.783Z,1536715919.783 [NAL9602](INFO): Packets left to send: 62
2018-09-12T01:31:59.784Z,1536715919.784 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0062.sbd
2018-09-12T01:32:10.655Z,1536715930.655 [NAL9602](INFO): SBD MO Status=1, MOMSN=49149, MT Status=0, MTMSN=0
2018-09-12T01:32:10.702Z,1536715930.702 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:32:10.702Z,1536715930.702 [NAL9602](INFO): Packets left to send: 61
2018-09-12T01:32:10.704Z,1536715930.704 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0061.sbd
2018-09-12T01:32:21.256Z,1536715941.256 [NAL9602](INFO): SBD MO Status=1, MOMSN=49150, MT Status=0, MTMSN=0
2018-09-12T01:32:21.323Z,1536715941.323 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:32:21.324Z,1536715941.324 [NAL9602](INFO): Packets left to send: 60
2018-09-12T01:32:21.325Z,1536715941.325 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0060.sbd
2018-09-12T01:32:29.497Z,1536715949.497 [NAL9602](INFO): SBD MO Status=1, MOMSN=49151, MT Status=0, MTMSN=0
2018-09-12T01:32:29.558Z,1536715949.558 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:32:29.558Z,1536715949.558 [NAL9602](INFO): Packets left to send: 59
2018-09-12T01:32:29.560Z,1536715949.560 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0059.sbd
2018-09-12T01:32:38.530Z,1536715958.530 [NAL9602](INFO): SBD MO Status=1, MOMSN=49152, MT Status=0, MTMSN=0
2018-09-12T01:32:38.578Z,1536715958.578 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:32:38.578Z,1536715958.578 [NAL9602](INFO): Packets left to send: 58
2018-09-12T01:32:38.580Z,1536715958.580 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0058.sbd
2018-09-12T01:32:47.560Z,1536715967.560 [NAL9602](INFO): SBD MO Status=1, MOMSN=49153, MT Status=0, MTMSN=0
2018-09-12T01:32:47.634Z,1536715967.634 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:32:47.635Z,1536715967.635 [NAL9602](INFO): Packets left to send: 57
2018-09-12T01:32:47.636Z,1536715967.636 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0057.sbd
2018-09-12T01:32:55.849Z,1536715975.849 [NAL9602](INFO): SBD MO Status=1, MOMSN=49154, MT Status=0, MTMSN=0
2018-09-12T01:32:55.895Z,1536715975.895 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:32:55.895Z,1536715975.895 [NAL9602](INFO): Packets left to send: 56
2018-09-12T01:32:55.897Z,1536715975.897 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0056.sbd
2018-09-12T01:33:12.452Z,1536715992.452 [NAL9602](INFO): SBD MO Status=1, MOMSN=49155, MT Status=0, MTMSN=0
2018-09-12T01:33:12.510Z,1536715992.510 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:33:12.510Z,1536715992.510 [NAL9602](INFO): Packets left to send: 55
2018-09-12T01:33:12.512Z,1536715992.512 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0055.sbd
2018-09-12T01:33:20.296Z,1536716000.296 [NAL9602](INFO): SBD MO Status=1, MOMSN=49156, MT Status=0, MTMSN=0
2018-09-12T01:33:20.347Z,1536716000.347 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:33:20.348Z,1536716000.348 [NAL9602](INFO): Packets left to send: 54
2018-09-12T01:33:20.351Z,1536716000.351 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0054.sbd
2018-09-12T01:33:33.245Z,1536716013.245 [NAL9602](INFO): SBD MO Status=1, MOMSN=49157, MT Status=0, MTMSN=0
2018-09-12T01:33:33.294Z,1536716013.294 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:33:33.294Z,1536716013.294 [NAL9602](INFO): Packets left to send: 53
2018-09-12T01:33:33.590Z,1536716013.590 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0053.sbd
2018-09-12T01:33:44.008Z,1536716024.008 [NAL9602](INFO): SBD MO Status=1, MOMSN=49158, MT Status=0, MTMSN=0
2018-09-12T01:33:44.062Z,1536716024.062 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:33:44.062Z,1536716024.062 [NAL9602](INFO): Packets left to send: 52
2018-09-12T01:33:44.064Z,1536716024.064 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0052.sbd
2018-09-12T01:33:49.848Z,1536716029.848 [DAT](FAULT): unknown deviceResponse_:  SPD:+00.0 AGC:69

2018-09-12T01:33:49.848Z,1536716029.848 [DAT] Communications Fault, FailCount= 1
2018-09-12T01:33:49.848Z,1536716029.848 [DAT](ERROR): Communications Fault
2018-09-12T01:33:49.912Z,1536716029.912 [CBIT](ERROR): Communications Fault in component: DAT
2018-09-12T01:33:50.235Z,1536716030.235 [DAT](INFO): Powering down
2018-09-12T01:33:51.065Z,1536716031.065 [CBIT](INFO): Clearing failed state for component DAT
2018-09-12T01:33:51.065Z,1536716031.065 [DAT] No Fault, FailCount= 1
2018-09-12T01:33:53.446Z,1536716033.446 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2018-09-12T01:33:53.446Z,1536716033.446 [DAT](INFO): Powering up
2018-09-12T01:33:53.446Z,1536716033.446 [DAT](DEBUG): Initializing DAT.
2018-09-12T01:33:53.518Z,1536716033.518 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2018-09-12T01:33:57.805Z,1536716037.805 [NAL9602](INFO): SBD MO Status=1, MOMSN=49159, MT Status=0, MTMSN=0
2018-09-12T01:33:57.850Z,1536716037.850 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:33:57.850Z,1536716037.850 [NAL9602](INFO): Packets left to send: 51
2018-09-12T01:33:57.852Z,1536716037.852 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0051.sbd
2018-09-12T01:34:08.437Z,1536716048.437 [DAT](INFO): setting local address to 6
2018-09-12T01:34:08.843Z,1536716048.843 [DAT](INFO): set local address to 6
2018-09-12T01:34:16.817Z,1536716056.817 [NAL9602](INFO): SBD MO Status=1, MOMSN=49160, MT Status=0, MTMSN=0
2018-09-12T01:34:16.870Z,1536716056.870 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:34:16.870Z,1536716056.870 [NAL9602](INFO): Packets left to send: 50
2018-09-12T01:34:16.872Z,1536716056.872 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0050.sbd
2018-09-12T01:34:17.630Z,1536716057.630 [BPC1](FAULT): Failed to receive data from all sticks prior to timeout. Missing data from 7 sticks.
2018-09-12T01:34:17.630Z,1536716057.630 [BPC1] Data Fault, FailCount= 1
2018-09-12T01:34:17.630Z,1536716057.630 [BPC1](ERROR): Data Fault
2018-09-12T01:34:17.656Z,1536716057.656 [CBIT](ERROR): Data Fault in component: BPC1
2018-09-12T01:34:20.307Z,1536716060.307 [CBIT](INFO): Clearing failed state for component BPC1
2018-09-12T01:34:20.307Z,1536716060.307 [BPC1] No Fault, FailCount= 1
2018-09-12T01:34:29.821Z,1536716069.821 [NAL9602](INFO): SBD MO Status=1, MOMSN=49161, MT Status=0, MTMSN=0
2018-09-12T01:34:29.879Z,1536716069.879 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:34:29.879Z,1536716069.879 [NAL9602](INFO): Packets left to send: 49
2018-09-12T01:34:29.881Z,1536716069.881 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0049.sbd
2018-09-12T01:34:41.155Z,1536716081.155 [NAL9602](INFO): SBD MO Status=1, MOMSN=49162, MT Status=0, MTMSN=0
2018-09-12T01:34:41.202Z,1536716081.202 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:34:41.202Z,1536716081.202 [NAL9602](INFO): Packets left to send: 48
2018-09-12T01:34:41.204Z,1536716081.204 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0048.sbd
2018-09-12T01:34:55.804Z,1536716095.804 [NAL9602](INFO): SBD MO Status=1, MOMSN=49163, MT Status=0, MTMSN=0
2018-09-12T01:34:55.862Z,1536716095.862 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:34:55.862Z,1536716095.862 [NAL9602](INFO): Packets left to send: 47
2018-09-12T01:34:55.864Z,1536716095.864 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0047.sbd
2018-09-12T01:35:20.349Z,1536716120.349 [NAL9602](INFO): SBD MO Status=2, MOMSN=49164, MT Status=2, MTMSN=0
2018-09-12T01:35:20.366Z,1536716120.366 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-12T01:35:40.476Z,1536716140.476 [NAL9602](INFO): SBD MO Status=1, MOMSN=49164, MT Status=0, MTMSN=0
2018-09-12T01:35:40.530Z,1536716140.530 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:35:40.530Z,1536716140.530 [NAL9602](INFO): Packets left to send: 46
2018-09-12T01:35:40.532Z,1536716140.532 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0046.sbd
2018-09-12T01:35:51.416Z,1536716151.416 [NAL9602](INFO): SBD MO Status=1, MOMSN=49165, MT Status=0, MTMSN=0
2018-09-12T01:35:51.466Z,1536716151.466 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:35:51.466Z,1536716151.466 [NAL9602](INFO): Packets left to send: 45
2018-09-12T01:35:51.468Z,1536716151.468 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0045.sbd
2018-09-12T01:36:06.440Z,1536716166.440 [NAL9602](INFO): SBD MO Status=1, MOMSN=49166, MT Status=0, MTMSN=0
2018-09-12T01:36:06.494Z,1536716166.494 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:36:06.494Z,1536716166.494 [NAL9602](INFO): Packets left to send: 44
2018-09-12T01:36:06.496Z,1536716166.496 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0044.sbd
2018-09-12T01:36:10.622Z,1536716170.622 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,-32768,-32768,-32768,-32768,V
2018-09-12T01:36:23.784Z,1536716183.784 [NAL9602](INFO): SBD MO Status=1, MOMSN=49167, MT Status=0, MTMSN=0
2018-09-12T01:36:23.838Z,1536716183.838 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:36:23.838Z,1536716183.838 [NAL9602](INFO): Packets left to send: 43
2018-09-12T01:36:23.840Z,1536716183.840 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0043.sbd
2018-09-12T01:36:44.066Z,1536716204.066 [NAL9602](INFO): SBD MO Status=1, MOMSN=49168, MT Status=0, MTMSN=0
2018-09-12T01:36:44.123Z,1536716204.123 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:36:44.124Z,1536716204.124 [NAL9602](INFO): Packets left to send: 42
2018-09-12T01:36:44.125Z,1536716204.125 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0042.sbd
2018-09-12T01:37:09.122Z,1536716229.122 [NAL9602](INFO): SBD MO Status=1, MOMSN=49169, MT Status=0, MTMSN=0
2018-09-12T01:37:09.174Z,1536716229.174 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:37:09.174Z,1536716229.174 [NAL9602](INFO): Packets left to send: 41
2018-09-12T01:37:09.176Z,1536716229.176 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0041.sbd
2018-09-12T01:37:24.621Z,1536716244.621 [NAL9602](INFO): SBD MO Status=1, MOMSN=49170, MT Status=0, MTMSN=0
2018-09-12T01:37:24.682Z,1536716244.682 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:37:24.682Z,1536716244.682 [NAL9602](INFO): Packets left to send: 40
2018-09-12T01:37:24.684Z,1536716244.684 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0040.sbd
2018-09-12T01:37:45.168Z,1536716265.168 [NAL9602](INFO): SBD MO Status=1, MOMSN=49171, MT Status=0, MTMSN=0
2018-09-12T01:37:45.222Z,1536716265.222 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:37:45.222Z,1536716265.222 [NAL9602](INFO): Packets left to send: 39
2018-09-12T01:37:45.226Z,1536716265.226 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0039.sbd
2018-09-12T01:38:04.511Z,1536716284.511 [NAL9602](INFO): SBD MO Status=2, MOMSN=49172, MT Status=2, MTMSN=0
2018-09-12T01:38:04.511Z,1536716284.511 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-12T01:38:39.100Z,1536716319.100 [NAL9602](INFO): SBD MO Status=1, MOMSN=49172, MT Status=0, MTMSN=0
2018-09-12T01:38:39.158Z,1536716319.158 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:38:39.158Z,1536716319.158 [NAL9602](INFO): Packets left to send: 38
2018-09-12T01:38:39.160Z,1536716319.160 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0038.sbd
2018-09-12T01:39:10.489Z,1536716350.489 [NAL9602](INFO): SBD MO Status=1, MOMSN=49173, MT Status=0, MTMSN=0
2018-09-12T01:39:10.538Z,1536716350.538 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:39:10.538Z,1536716350.538 [NAL9602](INFO): Packets left to send: 37
2018-09-12T01:39:10.540Z,1536716350.540 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0037.sbd
2018-09-12T01:39:27.185Z,1536716367.185 [NAL9602](INFO): SBD MO Status=2, MOMSN=49174, MT Status=2, MTMSN=0
2018-09-12T01:39:27.185Z,1536716367.185 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-12T01:40:06.116Z,1536716406.116 [NAL9602](INFO): SBD MO Status=2, MOMSN=49174, MT Status=2, MTMSN=0
2018-09-12T01:40:06.116Z,1536716406.116 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-12T01:40:25.173Z,1536716425.173 [NAL9602](INFO): SBD MO Status=1, MOMSN=49174, MT Status=0, MTMSN=0
2018-09-12T01:40:25.230Z,1536716425.230 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:40:25.230Z,1536716425.230 [NAL9602](INFO): Packets left to send: 36
2018-09-12T01:40:25.232Z,1536716425.232 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0036.sbd
2018-09-12T01:40:34.917Z,1536716434.917 [NAL9602](INFO): SBD MO Status=1, MOMSN=49175, MT Status=0, MTMSN=0
2018-09-12T01:40:34.983Z,1536716434.983 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:40:34.984Z,1536716434.984 [NAL9602](INFO): Packets left to send: 35
2018-09-12T01:40:34.985Z,1536716434.985 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0035.sbd
2018-09-12T01:40:49.861Z,1536716449.861 [NAL9602](INFO): SBD MO Status=1, MOMSN=49176, MT Status=0, MTMSN=0
2018-09-12T01:40:49.910Z,1536716449.910 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:40:49.910Z,1536716449.910 [NAL9602](INFO): Packets left to send: 34
2018-09-12T01:40:49.912Z,1536716449.912 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0034.sbd
2018-09-12T01:40:59.449Z,1536716459.449 [NAL9602](INFO): SBD MO Status=1, MOMSN=49177, MT Status=0, MTMSN=0
2018-09-12T01:40:59.494Z,1536716459.494 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:40:59.494Z,1536716459.494 [NAL9602](INFO): Packets left to send: 33
2018-09-12T01:40:59.497Z,1536716459.497 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0033.sbd
2018-09-12T01:41:42.048Z,1536716502.048 [NAL9602](INFO): SBD MO Status=2, MOMSN=49178, MT Status=2, MTMSN=0
2018-09-12T01:41:42.049Z,1536716502.049 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-12T01:42:01.123Z,1536716521.123 [NAL9602](INFO): SBD MO Status=1, MOMSN=49178, MT Status=0, MTMSN=0
2018-09-12T01:42:01.178Z,1536716521.178 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:42:01.178Z,1536716521.178 [NAL9602](INFO): Packets left to send: 32
2018-09-12T01:42:01.180Z,1536716521.180 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0032.sbd
2018-09-12T01:42:12.063Z,1536716532.063 [NAL9602](INFO): SBD MO Status=1, MOMSN=49179, MT Status=0, MTMSN=0
2018-09-12T01:42:12.106Z,1536716532.106 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:42:12.106Z,1536716532.106 [NAL9602](INFO): Packets left to send: 31
2018-09-12T01:42:12.108Z,1536716532.108 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0031.sbd
2018-09-12T01:42:26.660Z,1536716546.660 [NAL9602](INFO): SBD MO Status=1, MOMSN=49180, MT Status=0, MTMSN=0
2018-09-12T01:42:26.714Z,1536716546.714 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:42:26.714Z,1536716546.714 [NAL9602](INFO): Packets left to send: 30
2018-09-12T01:42:26.716Z,1536716546.716 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0030.sbd
2018-09-12T01:42:34.512Z,1536716554.512 [NAL9602](INFO): SBD MO Status=1, MOMSN=49181, MT Status=0, MTMSN=0
2018-09-12T01:42:34.568Z,1536716554.568 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:42:34.568Z,1536716554.568 [NAL9602](INFO): Packets left to send: 29
2018-09-12T01:42:34.570Z,1536716554.570 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0029.sbd
2018-09-12T01:42:45.101Z,1536716565.101 [NAL9602](INFO): SBD MO Status=1, MOMSN=49182, MT Status=0, MTMSN=0
2018-09-12T01:42:45.158Z,1536716565.158 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:42:45.158Z,1536716565.158 [NAL9602](INFO): Packets left to send: 28
2018-09-12T01:42:45.160Z,1536716565.160 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0028.sbd
2018-09-12T01:43:02.880Z,1536716582.880 [NAL9602](INFO): SBD MO Status=2, MOMSN=49183, MT Status=2, MTMSN=0
2018-09-12T01:43:02.880Z,1536716582.880 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-12T01:43:15.924Z,1536716595.924 [NAL9602](INFO): SBD MO Status=1, MOMSN=49183, MT Status=0, MTMSN=0
2018-09-12T01:43:15.974Z,1536716595.974 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:43:15.974Z,1536716595.974 [NAL9602](INFO): Packets left to send: 27
2018-09-12T01:43:15.976Z,1536716595.976 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0027.sbd
2018-09-12T01:43:27.817Z,1536716607.817 [NAL9602](INFO): SBD MO Status=1, MOMSN=49184, MT Status=0, MTMSN=0
2018-09-12T01:43:27.862Z,1536716607.862 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:43:27.862Z,1536716607.862 [NAL9602](INFO): Packets left to send: 26
2018-09-12T01:43:27.864Z,1536716607.864 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0026.sbd
2018-09-12T01:43:53.228Z,1536716633.228 [NAL9602](INFO): SBD MO Status=1, MOMSN=49185, MT Status=0, MTMSN=0
2018-09-12T01:43:53.282Z,1536716633.282 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:43:53.282Z,1536716633.282 [NAL9602](INFO): Packets left to send: 25
2018-09-12T01:43:53.348Z,1536716633.348 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0025.sbd
2018-09-12T01:44:09.771Z,1536716649.771 [NAL9602](INFO): SBD MO Status=1, MOMSN=49186, MT Status=0, MTMSN=0
2018-09-12T01:44:09.822Z,1536716649.822 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:44:09.822Z,1536716649.822 [NAL9602](INFO): Packets left to send: 24
2018-09-12T01:44:09.824Z,1536716649.824 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0024.sbd
2018-09-12T01:44:19.568Z,1536716659.568 [NAL9602](INFO): SBD MO Status=1, MOMSN=49187, MT Status=0, MTMSN=0
2018-09-12T01:44:19.618Z,1536716659.618 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:44:19.618Z,1536716659.618 [NAL9602](INFO): Packets left to send: 23
2018-09-12T01:44:19.620Z,1536716659.620 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0023.sbd
2018-09-12T01:44:35.287Z,1536716675.287 [NAL9602](INFO): SBD MO Status=1, MOMSN=49188, MT Status=0, MTMSN=0
2018-09-12T01:44:35.332Z,1536716675.332 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:44:35.333Z,1536716675.333 [NAL9602](INFO): Packets left to send: 22
2018-09-12T01:44:35.336Z,1536716675.336 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0022.sbd
2018-09-12T01:45:43.004Z,1536716743.004 [NAL9602](INFO): SBD MO Status=2, MOMSN=49189, MT Status=2, MTMSN=0
2018-09-12T01:45:43.004Z,1536716743.004 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-12T01:46:00.417Z,1536716760.417 [NAL9602](INFO): SBD MO Status=1, MOMSN=49189, MT Status=0, MTMSN=0
2018-09-12T01:46:00.462Z,1536716760.462 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:46:00.462Z,1536716760.462 [NAL9602](INFO): Packets left to send: 21
2018-09-12T01:46:00.464Z,1536716760.464 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0021.sbd
2018-09-12T01:46:10.965Z,1536716770.965 [NAL9602](INFO): SBD MO Status=1, MOMSN=49190, MT Status=0, MTMSN=0
2018-09-12T01:46:11.023Z,1536716771.023 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:46:11.023Z,1536716771.023 [NAL9602](INFO): Packets left to send: 20
2018-09-12T01:46:11.025Z,1536716771.025 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0020.sbd
2018-09-12T01:46:19.492Z,1536716779.492 [NAL9602](INFO): SBD MO Status=1, MOMSN=49191, MT Status=0, MTMSN=0
2018-09-12T01:46:19.546Z,1536716779.546 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:46:19.546Z,1536716779.546 [NAL9602](INFO): Packets left to send: 19
2018-09-12T01:46:19.548Z,1536716779.548 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0019.sbd
2018-09-12T01:46:33.019Z,1536716793.019 [NAL9602](INFO): SBD MO Status=1, MOMSN=49192, MT Status=0, MTMSN=0
2018-09-12T01:46:33.078Z,1536716793.078 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:46:33.078Z,1536716793.078 [NAL9602](INFO): Packets left to send: 18
2018-09-12T01:46:33.080Z,1536716793.080 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0018.sbd
2018-09-12T01:46:49.553Z,1536716809.553 [NAL9602](INFO): SBD MO Status=1, MOMSN=49193, MT Status=0, MTMSN=0
2018-09-12T01:46:49.607Z,1536716809.607 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:46:49.608Z,1536716809.608 [NAL9602](INFO): Packets left to send: 17
2018-09-12T01:46:49.609Z,1536716809.609 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0017.sbd
2018-09-12T01:47:05.405Z,1536716825.405 [NAL9602](INFO): SBD MO Status=1, MOMSN=49194, MT Status=0, MTMSN=0
2018-09-12T01:47:05.463Z,1536716825.463 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:47:05.463Z,1536716825.463 [NAL9602](INFO): Packets left to send: 16
2018-09-12T01:47:05.465Z,1536716825.465 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0016.sbd
2018-09-12T01:47:10.012Z,1536716830.012 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,-32768,-32768,-32768,-32768,V
2018-09-12T01:47:10.457Z,1536716830.457 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2018-09-12T01:47:10.457Z,1536716830.457 [RDI_Pathfinder](ERROR): Failed to parse:
:HM0.000
2018-09-12T01:47:16.447Z,1536716836.447 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2018-09-12T01:47:16.447Z,1536716836.447 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,        +0.00,   0.00,2025.84
2018-09-12T01:47:19.995Z,1536716839.995 [NAL9602](INFO): SBD MO Status=1, MOMSN=49195, MT Status=0, MTMSN=0
2018-09-12T01:47:20.043Z,1536716840.043 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:47:20.044Z,1536716840.044 [NAL9602](INFO): Packets left to send: 15
2018-09-12T01:47:20.045Z,1536716840.045 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0015.sbd
2018-09-12T01:47:35.512Z,1536716855.512 [NAL9602](INFO): SBD MO Status=2, MOMSN=49196, MT Status=2, MTMSN=0
2018-09-12T01:47:35.512Z,1536716855.512 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-12T01:48:04.893Z,1536716884.893 [NAL9602](INFO): SBD MO Status=2, MOMSN=49196, MT Status=2, MTMSN=0
2018-09-12T01:48:04.893Z,1536716884.893 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-12T01:48:52.273Z,1536716932.273 [NAL9602](INFO): SBD MO Status=1, MOMSN=49196, MT Status=0, MTMSN=0
2018-09-12T01:48:52.322Z,1536716932.322 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:48:52.322Z,1536716932.322 [NAL9602](INFO): Packets left to send: 14
2018-09-12T01:48:52.324Z,1536716932.324 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0014.sbd
2018-09-12T01:49:08.492Z,1536716948.492 [NAL9602](INFO): SBD MO Status=1, MOMSN=49197, MT Status=0, MTMSN=0
2018-09-12T01:49:08.550Z,1536716948.550 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:49:08.550Z,1536716948.550 [NAL9602](INFO): Packets left to send: 13
2018-09-12T01:49:08.552Z,1536716948.552 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0013.sbd
2018-09-12T01:49:21.091Z,1536716961.091 [NAL9602](INFO): SBD MO Status=1, MOMSN=49198, MT Status=0, MTMSN=0
2018-09-12T01:49:21.150Z,1536716961.150 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:49:21.150Z,1536716961.150 [NAL9602](INFO): Packets left to send: 12
2018-09-12T01:49:21.152Z,1536716961.152 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0012.sbd
2018-09-12T01:49:56.053Z,1536716996.053 [NAL9602](INFO): SBD MO Status=2, MOMSN=49199, MT Status=2, MTMSN=0
2018-09-12T01:49:56.054Z,1536716996.054 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-12T01:50:13.154Z,1536717013.154 [NAL9602](INFO): SBD MO Status=1, MOMSN=49199, MT Status=0, MTMSN=0
2018-09-12T01:50:13.203Z,1536717013.203 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:50:13.203Z,1536717013.203 [NAL9602](INFO): Packets left to send: 11
2018-09-12T01:50:13.204Z,1536717013.204 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0011.sbd
2018-09-12T01:50:25.717Z,1536717025.717 [NAL9602](INFO): SBD MO Status=1, MOMSN=49200, MT Status=0, MTMSN=0
2018-09-12T01:50:25.770Z,1536717025.770 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:50:25.770Z,1536717025.770 [NAL9602](INFO): Packets left to send: 10
2018-09-12T01:50:25.772Z,1536717025.772 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0010.sbd
2018-09-12T01:50:36.020Z,1536717036.020 [NAL9602](INFO): SBD MO Status=1, MOMSN=49201, MT Status=0, MTMSN=0
2018-09-12T01:50:36.066Z,1536717036.066 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:50:36.066Z,1536717036.066 [NAL9602](INFO): Packets left to send: 9
2018-09-12T01:50:36.068Z,1536717036.068 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0009.sbd
2018-09-12T01:50:46.148Z,1536717046.148 [NAL9602](INFO): SBD MO Status=1, MOMSN=49202, MT Status=0, MTMSN=0
2018-09-12T01:50:46.198Z,1536717046.198 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:50:46.198Z,1536717046.198 [NAL9602](INFO): Packets left to send: 8
2018-09-12T01:50:46.200Z,1536717046.200 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0008.sbd
2018-09-12T01:51:02.272Z,1536717062.272 [NAL9602](INFO): SBD MO Status=1, MOMSN=49203, MT Status=0, MTMSN=0
2018-09-12T01:51:02.326Z,1536717062.326 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:51:02.326Z,1536717062.326 [NAL9602](INFO): Packets left to send: 7
2018-09-12T01:51:02.328Z,1536717062.328 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0007.sbd
2018-09-12T01:51:16.936Z,1536717076.936 [NAL9602](INFO): SBD MO Status=1, MOMSN=49204, MT Status=0, MTMSN=0
2018-09-12T01:51:16.986Z,1536717076.986 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:51:16.986Z,1536717076.986 [NAL9602](INFO): Packets left to send: 6
2018-09-12T01:51:16.988Z,1536717076.988 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0006.sbd
2018-09-12T01:51:30.398Z,1536717090.398 [NAL9602](INFO): SBD MO Status=1, MOMSN=49205, MT Status=0, MTMSN=0
2018-09-12T01:51:30.449Z,1536717090.449 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:51:30.449Z,1536717090.449 [NAL9602](INFO): Packets left to send: 5
2018-09-12T01:51:30.451Z,1536717090.451 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0005.sbd
2018-09-12T01:51:39.412Z,1536717099.412 [NAL9602](INFO): SBD MO Status=1, MOMSN=49206, MT Status=0, MTMSN=0
2018-09-12T01:51:39.462Z,1536717099.462 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:51:39.462Z,1536717099.462 [NAL9602](INFO): Packets left to send: 4
2018-09-12T01:51:39.464Z,1536717099.464 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0004.sbd
2018-09-12T01:51:58.852Z,1536717118.852 [NAL9602](INFO): SBD MO Status=2, MOMSN=49207, MT Status=2, MTMSN=0
2018-09-12T01:51:58.852Z,1536717118.852 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-12T01:52:26.244Z,1536717146.244 [NAL9602](INFO): SBD MO Status=1, MOMSN=49207, MT Status=0, MTMSN=0
2018-09-12T01:52:26.298Z,1536717146.298 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:52:26.298Z,1536717146.298 [NAL9602](INFO): Packets left to send: 3
2018-09-12T01:52:26.300Z,1536717146.300 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0003.sbd
2018-09-12T01:52:55.692Z,1536717175.692 [NAL9602](INFO): SBD MO Status=2, MOMSN=49208, MT Status=2, MTMSN=0
2018-09-12T01:52:55.692Z,1536717175.692 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-12T01:53:08.265Z,1536717188.265 [NAL9602](INFO): SBD MO Status=1, MOMSN=49208, MT Status=0, MTMSN=0
2018-09-12T01:53:08.318Z,1536717188.318 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:53:08.318Z,1536717188.318 [NAL9602](INFO): Packets left to send: 2
2018-09-12T01:53:08.320Z,1536717188.320 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0002.sbd
2018-09-12T01:53:30.448Z,1536717210.448 [NAL9602](INFO): SBD MO Status=1, MOMSN=49209, MT Status=0, MTMSN=0
2018-09-12T01:53:30.498Z,1536717210.498 [NAL9602](INFO): Sent 332 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:53:30.498Z,1536717210.498 [NAL9602](INFO): Packets left to send: 1
2018-09-12T01:53:30.500Z,1536717210.500 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0001.sbd
2018-09-12T01:53:39.905Z,1536717219.905 [NAL9602](INFO): SBD MO Status=1, MOMSN=49210, MT Status=0, MTMSN=0
2018-09-12T01:53:39.962Z,1536717219.962 [NAL9602](INFO): Sent 151 bytes from file Logs/20180908T084424/Express0107.lzma
2018-09-12T01:53:39.962Z,1536717219.962 [NAL9602](INFO): Packets left to send: 0
2018-09-12T01:53:39.964Z,1536717219.964 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0107.lzma.parts/0000.sbd
2018-09-12T01:53:39.964Z,1536717219.964 [NAL9602](DEBUG): Completed sending Logs/20180908T084424/Express0107.lzma
2018-09-12T01:53:45.423Z,1536717225.423 [NAL9602](INFO): SBD MO Status=1, MOMSN=49211, MT Status=0, MTMSN=0
2018-09-12T01:53:45.471Z,1536717225.471 [NAL9602](INFO): Sent 25 bytes from file Logs/20180908T084424/Express0110.lzma
2018-09-12T01:53:45.471Z,1536717225.471 [NAL9602](INFO): Packets left to send: 0
2018-09-12T01:53:45.473Z,1536717225.473 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0110.lzma.parts/0000.sbd
2018-09-12T01:53:45.473Z,1536717225.473 [NAL9602](DEBUG): Completed sending Logs/20180908T084424/Express0110.lzma
2018-09-12T01:53:52.824Z,1536717232.824 [NAL9602](INFO): SBD MO Status=1, MOMSN=49212, MT Status=0, MTMSN=0
2018-09-12T01:53:52.874Z,1536717232.874 [NAL9602](INFO): Sent 18 bytes from file Logs/20180908T084424/Express0113.lzma
2018-09-12T01:53:52.874Z,1536717232.874 [NAL9602](INFO): Packets left to send: 0
2018-09-12T01:53:52.876Z,1536717232.876 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180908T084424/Express0113.lzma.parts/0000.sbd
2018-09-12T01:53:52.876Z,1536717232.876 [NAL9602](DEBUG): Completed sending Logs/20180908T084424/Express0113.lzma
2018-09-12T01:54:05.938Z,1536717245.938 [NAL9602](INFO): SBD MO Status=1, MOMSN=49213, MT Status=0, MTMSN=0
2018-09-12T01:54:05.986Z,1536717245.986 [NAL9602](INFO): Sent 332 bytes from file Logs/20180911T234333/Express0001.lzma
2018-09-12T01:54:05.986Z,1536717245.986 [NAL9602](INFO): Packets left to send: 2
2018-09-12T01:54:05.988Z,1536717245.988 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180911T234333/Express0001.lzma.parts/0002.sbd
2018-09-12T01:54:14.911Z,1536717254.911 [NAL9602](INFO): SBD MO Status=1, MOMSN=49214, MT Status=0, MTMSN=0
2018-09-12T01:54:14.974Z,1536717254.974 [NAL9602](INFO): Sent 332 bytes from file Logs/20180911T234333/Express0001.lzma
2018-09-12T01:54:14.974Z,1536717254.974 [NAL9602](INFO): Packets left to send: 1
2018-09-12T01:54:14.975Z,1536717254.975 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180911T234333/Express0001.lzma.parts/0001.sbd
2018-09-12T01:54:26.352Z,1536717266.352 [NAL9602](INFO): SBD MO Status=2, MOMSN=49215, MT Status=2, MTMSN=0
2018-09-12T01:54:26.352Z,1536717266.352 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-12T01:54:46.529Z,1536717286.529 [NAL9602](INFO): SBD MO Status=1, MOMSN=49215, MT Status=0, MTMSN=0
2018-09-12T01:54:46.582Z,1536717286.582 [NAL9602](INFO): Sent 224 bytes from file Logs/20180911T234333/Express0001.lzma
2018-09-12T01:54:46.582Z,1536717286.582 [NAL9602](INFO): Packets left to send: 0
2018-09-12T01:54:46.583Z,1536717286.583 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180911T234333/Express0001.lzma.parts/0000.sbd
2018-09-12T01:54:46.584Z,1536717286.584 [NAL9602](DEBUG): Completed sending Logs/20180911T234333/Express0001.lzma
2018-09-12T01:54:58.329Z,1536717298.329 [NAL9602](INFO): SBD MO Status=1, MOMSN=49216, MT Status=0, MTMSN=0
2018-09-12T01:54:58.382Z,1536717298.382 [NAL9602](INFO): Sent 211 bytes from file Logs/20180911T234333/Express0005.lzma
2018-09-12T01:54:58.382Z,1536717298.382 [NAL9602](INFO): Packets left to send: 0
2018-09-12T01:54:58.384Z,1536717298.384 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180911T234333/Express0005.lzma.parts/0000.sbd
2018-09-12T01:54:58.384Z,1536717298.384 [NAL9602](DEBUG): Completed sending Logs/20180911T234333/Express0005.lzma
2018-09-12T01:55:11.421Z,1536717311.421 [NAL9602](INFO): SBD MO Status=1, MOMSN=49217, MT Status=0, MTMSN=0
2018-09-12T01:55:11.466Z,1536717311.466 [NAL9602](INFO): Sent 332 bytes from file Logs/20180911T234333/Express0008.lzma
2018-09-12T01:55:11.467Z,1536717311.467 [NAL9602](INFO): Packets left to send: 1
2018-09-12T01:55:11.468Z,1536717311.468 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180911T234333/Express0008.lzma.parts/0001.sbd
2018-09-12T01:55:15.650Z,1536717315.650 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,-32768,-32768,-32768,-32768,V
2018-09-12T01:55:32.420Z,1536717332.420 [NAL9602](INFO): SBD MO Status=1, MOMSN=49218, MT Status=0, MTMSN=0
2018-09-12T01:55:32.474Z,1536717332.474 [NAL9602](INFO): Sent 97 bytes from file Logs/20180911T234333/Express0008.lzma
2018-09-12T01:55:32.474Z,1536717332.474 [NAL9602](INFO): Packets left to send: 0
2018-09-12T01:55:32.475Z,1536717332.475 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180911T234333/Express0008.lzma.parts/0000.sbd
2018-09-12T01:55:32.476Z,1536717332.476 [NAL9602](DEBUG): Completed sending Logs/20180911T234333/Express0008.lzma
2018-09-12T01:55:43.976Z,1536717343.976 [NAL9602](INFO): SBD MO Status=1, MOMSN=49219, MT Status=0, MTMSN=0
2018-09-12T01:55:44.026Z,1536717344.026 [NAL9602](INFO): Sent 52 bytes from file Logs/20180911T234333/Express0011.lzma
2018-09-12T01:55:44.026Z,1536717344.026 [NAL9602](INFO): Packets left to send: 0
2018-09-12T01:55:44.028Z,1536717344.028 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180911T234333/Express0011.lzma.parts/0000.sbd
2018-09-12T01:55:44.028Z,1536717344.028 [NAL9602](DEBUG): Completed sending Logs/20180911T234333/Express0011.lzma
2018-09-12T01:55:55.416Z,1536717355.416 [NAL9602](INFO): SBD MO Status=1, MOMSN=49220, MT Status=0, MTMSN=0
2018-09-12T01:55:55.474Z,1536717355.474 [NAL9602](INFO): Sent 159 bytes from file Logs/20180911T234333/Express0014.lzma
2018-09-12T01:55:55.474Z,1536717355.474 [NAL9602](INFO): Packets left to send: 0
2018-09-12T01:55:55.476Z,1536717355.476 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180911T234333/Express0014.lzma.parts/0000.sbd
2018-09-12T01:55:55.476Z,1536717355.476 [NAL9602](DEBUG): Completed sending Logs/20180911T234333/Express0014.lzma
2018-09-12T01:56:07.213Z,1536717367.213 [NAL9602](INFO): SBD MO Status=1, MOMSN=49221, MT Status=0, MTMSN=0
2018-09-12T01:56:07.266Z,1536717367.266 [NAL9602](INFO): Sent 173 bytes from file Logs/20180911T234333/Express0017.lzma
2018-09-12T01:56:07.266Z,1536717367.266 [NAL9602](INFO): Packets left to send: 0
2018-09-12T01:56:07.268Z,1536717367.268 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180911T234333/Express0017.lzma.parts/0000.sbd
2018-09-12T01:56:07.268Z,1536717367.268 [NAL9602](DEBUG): Completed sending Logs/20180911T234333/Express0017.lzma
2018-09-12T01:56:15.965Z,1536717375.965 [NAL9602](INFO): SBD MO Status=1, MOMSN=49222, MT Status=0, MTMSN=0
2018-09-12T01:56:16.023Z,1536717376.023 [NAL9602](INFO): Sent 332 bytes from file Logs/20180911T234333/Express0020.lzma
2018-09-12T01:56:16.023Z,1536717376.023 [NAL9602](INFO): Packets left to send: 1
2018-09-12T01:56:16.025Z,1536717376.025 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180911T234333/Express0020.lzma.parts/0001.sbd
2018-09-12T01:56:23.382Z,1536717383.382 [NAL9602](INFO): SBD MO Status=1, MOMSN=49223, MT Status=0, MTMSN=0
2018-09-12T01:56:23.429Z,1536717383.429 [NAL9602](INFO): Sent 26 bytes from file Logs/20180911T234333/Express0020.lzma
2018-09-12T01:56:23.429Z,1536717383.429 [NAL9602](INFO): Packets left to send: 0
2018-09-12T01:56:23.431Z,1536717383.431 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180911T234333/Express0020.lzma.parts/0000.sbd
2018-09-12T01:56:23.431Z,1536717383.431 [NAL9602](DEBUG): Completed sending Logs/20180911T234333/Express0020.lzma
2018-09-12T01:56:34.301Z,1536717394.301 [NAL9602](INFO): SBD MO Status=1, MOMSN=49224, MT Status=0, MTMSN=0
2018-09-12T01:56:34.356Z,1536717394.356 [NAL9602](INFO): Sent 141 bytes from file Logs/20180911T234333/Express0023.lzma
2018-09-12T01:56:34.356Z,1536717394.356 [NAL9602](INFO): Packets left to send: 0
2018-09-12T01:56:34.361Z,1536717394.361 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180911T234333/Express0023.lzma.parts/0000.sbd
2018-09-12T01:56:34.362Z,1536717394.362 [NAL9602](DEBUG): Completed sending Logs/20180911T234333/Express0023.lzma
2018-09-12T01:56:46.130Z,1536717406.130 [NAL9602](INFO): SBD MO Status=1, MOMSN=49225, MT Status=0, MTMSN=0
2018-09-12T01:56:46.190Z,1536717406.190 [NAL9602](INFO): Sent 332 bytes from file Logs/20180912T011304/Express0001.lzma
2018-09-12T01:56:46.190Z,1536717406.190 [NAL9602](INFO): Packets left to send: 1
2018-09-12T01:56:46.192Z,1536717406.192 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180912T011304/Express0001.lzma.parts/0001.sbd
2018-09-12T01:56:56.352Z,1536717416.352 [NAL9602](INFO): SBD MO Status=1, MOMSN=49226, MT Status=0, MTMSN=0
2018-09-12T01:56:56.408Z,1536717416.408 [NAL9602](INFO): Sent 330 bytes from file Logs/20180912T011304/Express0001.lzma
2018-09-12T01:56:56.408Z,1536717416.408 [NAL9602](INFO): Packets left to send: 0
2018-09-12T01:56:56.411Z,1536717416.411 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180912T011304/Express0001.lzma.parts/0000.sbd
2018-09-12T01:56:56.412Z,1536717416.412 [NAL9602](DEBUG): Completed sending Logs/20180912T011304/Express0001.lzma
2018-09-12T01:57:00.620Z,1536717420.620 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,-32768,-32768,-32768,-32768,V
2018-09-12T01:57:04.188Z,1536717424.188 [NAL9602](INFO): SBD MO Status=1, MOMSN=49227, MT Status=0, MTMSN=0
2018-09-12T01:57:04.246Z,1536717424.246 [NAL9602](INFO): Sent 210 bytes from file Logs/20180912T011304/Express0005.lzma
2018-09-12T01:57:04.246Z,1536717424.246 [NAL9602](INFO): Packets left to send: 0
2018-09-12T01:57:04.248Z,1536717424.248 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180912T011304/Express0005.lzma.parts/0000.sbd
2018-09-12T01:57:04.248Z,1536717424.248 [NAL9602](DEBUG): Completed sending Logs/20180912T011304/Express0005.lzma
2018-09-12T01:57:12.988Z,1536717432.988 [NAL9602](INFO): SBD MO Status=0, MOMSN=49228, MT Status=0, MTMSN=0
2018-09-12T01:57:13.079Z,1536717433.079 [Default:CheckIn:Read_Iridium] Stopped
2018-09-12T01:57:13.079Z,1536717433.079 [Default:CheckIn:C.Wait] Running Loop=1
2018-09-12T01:57:13.079Z,1536717433.079 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-09-12T01:57:43.790Z,1536717463.790 [NAL9602](INFO): Powering down
2018-09-12T02:02:13.832Z,1536717733.832 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-09-12T02:02:13.832Z,1536717733.832 [Default:CheckIn:C.Wait] Stopped
2018-09-12T02:02:13.832Z,1536717733.832 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-09-12T02:02:13.832Z,1536717733.832 [Default:CheckIn:D] Running Loop=1
2018-09-12T02:02:14.230Z,1536717734.230 [Default:CheckIn:D] Stopped
2018-09-12T02:02:14.230Z,1536717734.230 [Default:CheckIn:E] Running Loop=1
2018-09-12T02:02:14.643Z,1536717734.643 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.581303 min 
2018-09-12T02:02:14.645Z,1536717734.645 [Default:CheckIn:E] Stopped
2018-09-12T02:02:14.645Z,1536717734.645 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-09-12T02:02:14.645Z,1536717734.645 [Default:CheckIn] Stopped
2018-09-12T02:02:14.645Z,1536717734.645 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-09-12T02:02:14.645Z,1536717734.645 [Default:CheckIn](INFO): Running loop #2
2018-09-12T02:02:14.645Z,1536717734.645 [Default:CheckIn] Running Loop=2
2018-09-12T02:02:14.646Z,1536717734.646 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-09-12T02:02:14.646Z,1536717734.646 [Default:CheckIn:Read_GPS] Running Loop=1
2018-09-12T02:02:15.403Z,1536717735.403 [NAL9602](INFO): Powering up
2018-09-12T02:02:26.191Z,1536717746.191 [NAL9602](INFO): NAL9602 initialized
2018-09-12T02:02:51.791Z,1536717771.791 [NAL9602](INFO): SBD MO Status=2, MOMSN=49229, MT Status=2, MTMSN=0
2018-09-12T02:02:51.791Z,1536717771.791 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-12T02:03:15.792Z,1536717795.792 [NAL9602](INFO): SBD MO Status=2, MOMSN=49229, MT Status=2, MTMSN=0
2018-09-12T02:03:15.792Z,1536717795.792 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-12T02:03:24.192Z,1536717804.192 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=49229, MT Status=1, MTMSN=1526
2018-09-12T02:03:24.192Z,1536717804.192 [NAL9602](INFO): Data available in MT queue
2018-09-12T02:03:25.060Z,1536717805.060 [NAL9602](INFO): Received command:configSet Express none ESPComponent.sampling persist;configSet Express none ESPComponent.sample_number persist;configSet RDI_Pathfinder.loadAtStartup 0 bool persist;configSet CBIT.gf24Offset 180 microampere persist
2018-09-12T02:03:26.979Z,1536717806.979 [CommandLine](IMPORTANT): got command configSet Express none ESPComponent.sampling persist
2018-09-12T02:03:26.987Z,1536717806.987 [CommandLine](IMPORTANT): got command configSet Express none ESPComponent.sample_number persist
2018-09-12T02:03:26.989Z,1536717806.989 [CommandLine](IMPORTANT): got command configSet RDI_Pathfinder.loadAtStartup 0.000000 bool persist
2018-09-12T02:03:26.990Z,1536717806.990 [CommandLine](IMPORTANT): configSet RDI_Pathfinder.loadAtStartup requires a restart to take effect.
2018-09-12T02:03:26.992Z,1536717806.992 [CommandLine](IMPORTANT): got command configSet CBIT.gf24Offset 180.000000 microampere persist
2018-09-12T02:03:42.766Z,1536717822.766 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2018-09-12T02:03:42.767Z,1536717822.767 [RDI_Pathfinder](ERROR): Failed to parse:
:BD,        +0.00,     ,        +0.00,   0.00,3011.60
2018-09-12T02:05:27.579Z,1536717927.579 [RDI_Pathfinder](ERROR): only read 1 of 1 data item for altitude
2018-09-12T02:05:27.579Z,1536717927.579 [RDI_Pathfinder](ERROR): Failed to parse:
:HM,G0e89,*14.167,*-0.142,*0.000
2018-09-12T02:05:38.744Z,1536717938.744 [NAL9602](INFO): GPS fix at 20180912T020500: (36.857774, -122.241847)
2018-09-12T02:05:38.815Z,1536717938.815 [Default:CheckIn:Read_GPS] Stopped
2018-09-12T02:05:38.815Z,1536717938.815 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-09-12T02:05:55.265Z,1536717955.265 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=49230, MT Status=1, MTMSN=1527
2018-09-12T02:05:55.326Z,1536717955.326 [NAL9602](INFO): Sent 223 bytes from file Logs/20180912T011304/Courier0007.lzma
2018-09-12T02:05:55.326Z,1536717955.326 [NAL9602](INFO): Packets left to send: 0
2018-09-12T02:05:55.328Z,1536717955.328 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180912T011304/Courier0007.lzma.parts/0000.sbd
2018-09-12T02:05:55.328Z,1536717955.328 [NAL9602](DEBUG): Completed sending Logs/20180912T011304/Courier0007.lzma
2018-09-12T02:05:56.066Z,1536717956.066 [NAL9602](INFO): Received command:sched asap "load Science/sci2.xml;set sci2.NeedCommsTime 15 minute;set sci2.Lat1 36.89 degree;set sci2.Lon1 -122.2175 degree;set sci2.YoYoMinDepth 10 meter;set sci2.YoYoMaxDepth 40 meter;set sci2.YoYoMinAltitude 1 meter" 4feyy 1 2
2018-09-12T02:05:56.163Z,1536717956.163 [CommandLine](IMPORTANT): got command schedule asap "load Science/sci2.xml;set sci2.NeedCommsTime 15 minute;set sci2.Lat1 36.89 degree;set sci2.Lon1 -122.2175 degree;set sci2.YoYoMinDepth 10 meter;set sci2.YoYoMaxDepth 40 meter;set sci2.YoYoMinAltitude 1 meter" 4feyy 1 2.000000
2018-09-12T02:05:56.164Z,1536717956.164 [CommandLine](IMPORTANT): Scheduling command #1 of 2 with id=4feyy
2018-09-12T02:05:56.165Z,1536717956.165 [CommandLine](IMPORTANT): Scheduled #1 (#1 of 2 with id='4feyy'): "load Science/sci2.xml;set sci2.NeedCommsTime 15 minute;set sci2.Lat1 36.89 degree;set sci2.Lon1 -122.2175 degree;set sci2.YoYoMinDepth 10 meter;set sci2.YoYoMaxDepth 40 meter;set sci2.YoYoMinAltitude 1 meter" ASAP
2018-09-12T02:06:14.384Z,1536717974.384 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=49231, MT Status=1, MTMSN=1528
2018-09-12T02:06:14.434Z,1536717974.434 [NAL9602](INFO): Sent 332 bytes from file Logs/20180912T011304/Express0008.lzma
2018-09-12T02:06:14.435Z,1536717974.435 [NAL9602](INFO): Packets left to send: 1
2018-09-12T02:06:14.436Z,1536717974.436 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180912T011304/Express0008.lzma.parts/0001.sbd
2018-09-12T02:06:15.138Z,1536717975.138 [NAL9602](INFO): Received command:sched asap "set sci2.MinAltitude 1 meter;set sci2.MaxDepth 50 meter;run " 4feyy 2 2
2018-09-12T02:06:15.191Z,1536717975.191 [CommandLine](IMPORTANT): got command schedule asap "set sci2.MinAltitude 1 meter;set sci2.MaxDepth 50 meter;run " 4feyy 2 2.000000
2018-09-12T02:06:15.191Z,1536717975.191 [CommandLine](IMPORTANT): Scheduling command #2 of 2 with id=4feyy
2018-09-12T02:06:15.192Z,1536717975.192 [CommandLine](IMPORTANT): Scheduled #2 (#2 of 2 with id='4feyy'): "set sci2.MinAltitude 1 meter;set sci2.MaxDepth 50 meter;run " ASAP
2018-09-12T02:06:15.365Z,1536717975.365 [CommandLine](IMPORTANT): got command load ./Missions/Science/sci2.xml
2018-09-12T02:06:15.374Z,1536717975.374 [MissionManager](INFO): Loading Mission: ./Missions/Science/sci2.xml
2018-09-12T02:06:15.543Z,1536717975.543 [MissionManager](INFO): DefineArg sci2.MissionTimeout = 2.000000 h
2018-09-12T02:06:15.548Z,1536717975.548 [MissionManager](INFO): DefineArg sci2.NeedCommsTime = 60.000000 min
2018-09-12T02:06:15.551Z,1536717975.551 [MissionManager](INFO): DefineArg sci2.Repeat = 1.000000 count
2018-09-12T02:06:15.554Z,1536717975.554 [MissionManager](INFO): DefineArg sci2.Lat1 = nan arcdeg
2018-09-12T02:06:15.557Z,1536717975.557 [MissionManager](INFO): DefineArg sci2.Lon1 = nan arcdeg
2018-09-12T02:06:15.576Z,1536717975.576 [MissionManager](INFO): DefineArg sci2.Lat2 = nan arcdeg
2018-09-12T02:06:15.583Z,1536717975.583 [MissionManager](INFO): DefineArg sci2.Lon2 = nan arcdeg
2018-09-12T02:06:15.590Z,1536717975.590 [MissionManager](INFO): DefineArg sci2.Lat3 = nan arcdeg
2018-09-12T02:06:15.597Z,1536717975.597 [MissionManager](INFO): DefineArg sci2.Lon3 = nan arcdeg
2018-09-12T02:06:15.600Z,1536717975.600 [MissionManager](INFO): DefineArg sci2.Lat4 = nan arcdeg
2018-09-12T02:06:15.603Z,1536717975.603 [MissionManager](INFO): DefineArg sci2.Lon4 = nan arcdeg
2018-09-12T02:06:15.619Z,1536717975.619 [MissionManager](INFO): DefineArg sci2.Lat5 = nan arcdeg
2018-09-12T02:06:15.621Z,1536717975.621 [MissionManager](INFO): DefineArg sci2.Lon5 = nan arcdeg
2018-09-12T02:06:15.625Z,1536717975.625 [MissionManager](INFO): DefineArg sci2.Lat6 = nan arcdeg
2018-09-12T02:06:15.636Z,1536717975.636 [MissionManager](INFO): DefineArg sci2.Lon6 = nan arcdeg
2018-09-12T02:06:15.710Z,1536717975.710 [MissionManager](INFO): DefineArg sci2.Lat7 = nan arcdeg
2018-09-12T02:06:15.713Z,1536717975.713 [MissionManager](INFO): DefineArg sci2.Lon7 = nan arcdeg
2018-09-12T02:06:15.724Z,1536717975.724 [MissionManager](INFO): DefineArg sci2.Speed = 1.000000 m/s
2018-09-12T02:06:15.747Z,1536717975.747 [MissionManager](INFO): DefineArg sci2.YoYoMinDepth = 2.000000 m
2018-09-12T02:06:15.751Z,1536717975.751 [MissionManager](INFO): DefineArg sci2.YoYoMaxDepth = 200.000000 m
2018-09-12T02:06:15.763Z,1536717975.763 [MissionManager](INFO): DefineArg sci2.YoYoMinAltitude = 9.000000 m
2018-09-12T02:06:15.770Z,1536717975.770 [MissionManager](INFO): DefineArg sci2.YoYoUpPitch = 20.000000 arcdeg
2018-09-12T02:06:15.773Z,1536717975.773 [MissionManager](INFO): DefineArg sci2.YoYoDownPitch = -20.000000 arcdeg
2018-09-12T02:06:15.785Z,1536717975.785 [MissionManager](INFO): DefineArg sci2.BuoyancyNeutral = 325.000001 cc
2018-09-12T02:06:15.797Z,1536717975.797 [MissionManager](INFO): DefineArg sci2.MassDefault = 0.200000 cm
2018-09-12T02:06:15.804Z,1536717975.804 [MissionManager](INFO): DefineArg sci2.MinAltitude = 5.000000 m
2018-09-12T02:06:15.809Z,1536717975.809 [MissionManager](INFO): DefineArg sci2.MaxDepth = 205.000000 m
2018-09-12T02:06:15.820Z,1536717975.820 [MissionManager](INFO): DefineArg sci2.MinOffshore = 2.000000 km
2018-09-12T02:06:15.821Z,1536717975.821 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml
2018-09-12T02:06:16.121Z,1536717976.121 [MissionManager](INFO): DefineArg sci2:Science.SampleISUS = 0 bool
2018-09-12T02:06:16.132Z,1536717976.132 [MissionManager](INFO): DefineArg sci2:Science.SampleISUSmaxPitch = 60.000000 arcdeg
2018-09-12T02:06:16.140Z,1536717976.140 [MissionManager](INFO): DefineArg sci2:Science.SampleISUSminPitch = -60.000000 arcdeg
2018-09-12T02:06:16.163Z,1536717976.163 [MissionManager](INFO): DefineArg sci2:Science.PeakDetectChlActive = 0 bool
2018-09-12T02:06:16.165Z,1536717976.165 [MissionManager](INFO): DefineArg sci2:Science.HighestChlPeakReportActive = 0 bool
2018-09-12T02:06:16.176Z,1536717976.176 [MissionManager](INFO): DefineArg sci2:Science.PatchTracking = 0 bool
2018-09-12T02:06:16.184Z,1536717976.184 [MissionManager](INFO): DefineArg sci2:Science.FilterWidthHorizontal = 3.000000 count
2018-09-12T02:06:16.199Z,1536717976.199 [MissionManager](INFO): DefineArg sci2:Science.NumProfilesSlidingwindow = 100.000000 count
2018-09-12T02:06:16.206Z,1536717976.206 [MissionManager](INFO): DefineArg sci2:Science.PeakDetectNO3Active = 0 bool
2018-09-12T02:06:16.209Z,1536717976.209 [MissionManager](INFO): DefineArg sci2:Science.PeakDetectOilActive = 0 bool
2018-09-12T02:06:16.216Z,1536717976.216 [MissionManager](INFO): DefineArg sci2:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2018-09-12T02:06:16.224Z,1536717976.224 [MissionManager](INFO): DefineArg sci2:Science.EnabledAanderaaO2 = 0.000000 bool
2018-09-12T02:06:16.228Z,1536717976.228 [MissionManager](INFO): DefineArg sci2:Science.EnabledNeilBrown = 0.000000 bool
2018-09-12T02:06:16.240Z,1536717976.240 [MissionManager](INFO): DefineArg sci2:Science.EnabledSeabird = 1.000000 bool
2018-09-12T02:06:16.244Z,1536717976.244 [MissionManager](INFO): DefineArg sci2:Science.EnabledTurbulence_NPS = 0.000000 bool
2018-09-12T02:06:16.247Z,1536717976.247 [MissionManager](INFO): DefineArg sci2:Science.EnabledWetLabsBB2FL = 1.000000 bool
2018-09-12T02:06:16.267Z,1536717976.267 [MissionManager](INFO): DefineArg sci2:Science.EnabledWetLabsSeaOWL_UV_A = 0.000000 bool
2018-09-12T02:06:16.270Z,1536717976.270 [MissionManager](INFO): DefineArg sci2:Science.EnabledISUS = 0.000000 bool
2018-09-12T02:06:16.273Z,1536717976.273 [MissionManager](INFO): DefineArg sci2:Science.LowPassWindowLength = 20.000000 count
2018-09-12T02:06:16.276Z,1536717976.276 [MissionManager](INFO): DefineArg sci2:Science.PeakChlShallowBound = nan m
2018-09-12T02:06:16.291Z,1536717976.291 [MissionManager](INFO): DefineArg sci2:Science.PeakChlDeepBound = nan m
2018-09-12T02:06:16.294Z,1536717976.294 [MissionManager](INFO): DefineOutput sci2:Science.PeakChl = 0.000000 ug/l
2018-09-12T02:06:16.297Z,1536717976.297 [MissionManager](INFO): DefineOutput sci2:Science.PeakChlDepth = 0.000000 m
2018-09-12T02:06:16.300Z,1536717976.300 [MissionManager](INFO): DefineOutput sci2:Science.PeakChlTemperature = 0.000000 degC
2018-09-12T02:06:16.317Z,1536717976.317 [MissionManager](INFO): DefineOutput sci2:Science.PeakChlLatitude = nan arcdeg
2018-09-12T02:06:16.320Z,1536717976.320 [MissionManager](INFO): DefineOutput sci2:Science.PeakChlLongitude = nan arcdeg
2018-09-12T02:06:16.324Z,1536717976.324 [MissionManager](INFO): DefineOutput sci2:Science.PeakNO3 = 0.000000 umol/l
2018-09-12T02:06:16.337Z,1536717976.337 [MissionManager](INFO): DefineOutput sci2:Science.PeakNO3Depth = 0.000000 m
2018-09-12T02:06:16.340Z,1536717976.340 [MissionManager](INFO): DefineOutput sci2:Science.PeakNO3Latitude = nan arcdeg
2018-09-12T02:06:16.343Z,1536717976.343 [MissionManager](INFO): DefineOutput sci2:Science.PeakNO3Longitude = nan arcdeg
2018-09-12T02:06:16.359Z,1536717976.359 [MissionManager](INFO): DefineOutput sci2:Science.PatchChl = 0.000000 m
2018-09-12T02:06:16.363Z,1536717976.363 [MissionManager](INFO): DefineOutput sci2:Science.PatchChlDepth = 0.000000 m
2018-09-12T02:06:16.366Z,1536717976.366 [MissionManager](INFO): DefineOutput sci2:Science.PatchChlLatitude = nan arcdeg
2018-09-12T02:06:16.369Z,1536717976.369 [MissionManager](INFO): DefineOutput sci2:Science.PatchChlLongitude = nan arcdeg
2018-09-12T02:06:16.384Z,1536717976.384 [MissionManager](INFO): DefineOutput sci2:Science.PatchChlDistance = nan m
2018-09-12T02:06:16.390Z,1536717976.390 [MissionManager](INFO): DefineOutput sci2:Science.PeakOil = 0.000000 kg/m3
2018-09-12T02:06:16.407Z,1536717976.407 [MissionManager](INFO): DefineOutput sci2:Science.PeakOilDepth = 0.000000 m
2018-09-12T02:06:16.416Z,1536717976.416 [MissionManager](INFO): DefineOutput sci2:Science.PeakOilLatitude = nan arcdeg
2018-09-12T02:06:16.473Z,1536717976.473 [MissionManager](INFO): DefineOutput sci2:Science.PeakOilLongitude = nan arcdeg
2018-09-12T02:06:16.543Z,1536717976.543 [sci2:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2018-09-12T02:06:16.587Z,1536717976.587 [sci2:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2018-09-12T02:06:16.627Z,1536717976.627 [sci2:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2018-09-12T02:06:16.644Z,1536717976.644 [sci2:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2018-09-12T02:06:16.674Z,1536717976.674 [MissionManager](INFO): RedefineArg sci2:Science.SampleISUS = value:1 bool
2018-09-12T02:06:16.676Z,1536717976.676 [MissionManager](INFO): RedefineArg sci2:Science.PeakDetectChlActive = value:1 bool
2018-09-12T02:06:16.676Z,1536717976.676 [MissionManager](INFO): Inserting Stack: Missions/Insert/NeedComms.xml
2018-09-12T02:06:16.762Z,1536717976.762 [MissionManager](INFO): DefineArg sci2:NeedComms.DiveInterval = 3.000000 h
2018-09-12T02:06:16.765Z,1536717976.765 [MissionManager](INFO): DefineArg sci2:NeedComms.WaitForPitchUp = 10.000000 min
2018-09-12T02:06:16.772Z,1536717976.772 [MissionManager](INFO): DefineArg sci2:NeedComms.SurfacePitch = 20.000000 arcdeg
2018-09-12T02:06:16.784Z,1536717976.784 [MissionManager](INFO): DefineArg sci2:NeedComms.SurfaceDepthRate = nan m/s
2018-09-12T02:06:16.789Z,1536717976.789 [MissionManager](INFO): DefineArg sci2:NeedComms.SurfaceSpeed = 1.000000 m/s
2018-09-12T02:06:16.804Z,1536717976.804 [MissionManager](INFO): DefineArg sci2:NeedComms.GPSTimeout = 7.000000 min
2018-09-12T02:06:16.808Z,1536717976.808 [MissionManager](INFO): DefineArg sci2:NeedComms.CommsTimeout = 30.000000 min
2018-09-12T02:06:16.830Z,1536717976.830 [sci2:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-09-12T02:06:16.936Z,1536717976.936 [MissionManager](INFO): Inserting Stack: Missions/Insert/StandardEnvelopes.xml
2018-09-12T02:06:16.978Z,1536717976.978 [MissionManager](INFO): DefineArg sci2:StandardEnvelopes.MinAltitude = 5.000000 m
2018-09-12T02:06:16.984Z,1536717976.984 [MissionManager](INFO): DefineArg sci2:StandardEnvelopes.MaxDepth = 200.000000 m
2018-09-12T02:06:16.987Z,1536717976.987 [MissionManager](INFO): DefineArg sci2:StandardEnvelopes.MinOffshore = 2000.000000 m
2018-09-12T02:06:16.989Z,1536717976.989 [sci2:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2018-09-12T02:06:17.005Z,1536717977.005 [sci2:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2018-09-12T02:06:17.038Z,1536717977.038 [sci2:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2018-09-12T02:06:17.082Z,1536717977.082 [sci2:I.Pitch](DEBUG): Construct.
2018-09-12T02:06:17.088Z,1536717977.088 [sci2:J.Buoyancy](DEBUG): Construct Buoyancy.
2018-09-12T02:06:17.095Z,1536717977.095 [sci2:K.SetSpeed](DEBUG): Construct.
2018-09-12T02:06:17.102Z,1536717977.102 [sci2:L.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2018-09-12T02:06:17.126Z,1536717977.126 [sci2:M.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2018-09-12T02:06:17.143Z,1536717977.143 [sci2:N.YoYo](DEBUG): Construct YoYo.
2018-09-12T02:06:17.165Z,1536717977.165 [sci2:Lap:Wpt1:A.Waypoint](DEBUG): Construct Waypoint.
2018-09-12T02:06:17.180Z,1536717977.180 [sci2:Lap:Wpt2:A.Waypoint](DEBUG): Construct Waypoint.
2018-09-12T02:06:17.187Z,1536717977.187 [sci2:Lap:Wpt3:A.Waypoint](DEBUG): Construct Waypoint.
2018-09-12T02:06:17.212Z,1536717977.212 [sci2:Lap:Wpt4:A.Waypoint](DEBUG): Construct Waypoint.
2018-09-12T02:06:17.229Z,1536717977.229 [sci2:Lap:Wpt5:A.Waypoint](DEBUG): Construct Waypoint.
2018-09-12T02:06:17.236Z,1536717977.236 [sci2:Lap:Wpt6:A.Waypoint](DEBUG): Construct Waypoint.
2018-09-12T02:06:17.310Z,1536717977.310 [sci2:Lap:Wpt7:A.Waypoint](DEBUG): Construct Waypoint.
2018-09-12T02:06:17.406Z,1536717977.406 [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:Control="Tethys/Control"
         xmlns:Guidance="Tethys/Guidance"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd"
       Id="sci2">

    <Description>
        Vehicle yo-yo's to the specified waypoints, with science turned on.
    </Description>
    <DefineArg Name="MissionTimeout"><Description>
        Maximum duration of mission
    </Description><Units:hour/><Value>2</Value></DefineArg>

    <DefineArg Name="NeedCommsTime"><Description>
        How often to surface for commumications
    </Description><Units:minute/><Value>60</Value></DefineArg>

    <DefineArg Name="Repeat"><Description>
        Number of times the vehicle should try to cycle through waypoints..
    </Description><Units:count/><Value>1</Value></DefineArg>

    <DefineArg Name="Lat1"><Description>
        Latitude of waypoint 1. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon1"><Description>
        Longitude of waypoint 1. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lat2"><Description>
        Latitude of waypoint 2. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon2"><Description>
        Longitude of waypoint 2. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lat3"><Description>
        Latitude of waypoint 3. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon3"><Description>
        Longitude of waypoint 3. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lat4"><Description>
        Latitude of waypoint 4. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon4"><Description>
        Longitude of waypoint 4. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lat5"><Description>
        Latitude of waypoint 5. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon5"><Description>
        Longitude of waypoint 5. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lat6"><Description>
        Latitude of waypoint 6. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon6"><Description>
        Longitude of waypoint 6. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lat7"><Description>
        Latitude of waypoint 7. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon7"><Description>
        Longitude of waypoint 7. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Speed"><Description>
        Speed while performing the YoYo behavior.
    </Description><Units:meter_per_second/><Value>1</Value></DefineArg>

    <DefineArg Name="YoYoMinDepth"><Description>
        Minimum depth while performing the YoYo behavior.
    </Description><Units:meter/><Value>2</Value></DefineArg>

    <DefineArg Name="YoYoMaxDepth"><Description>
        Maximum depth while performing the YoYo behavior.
    </Description><Units:meter/><Value>200</Value></DefineArg>

    <DefineArg Name="YoYoMinAltitude"><Description>
        Minimum altitude while performing the YoYo behavior (for
        bottom-terminated YoYos).
    </Description><Units:meter/><Value>9</Value></DefineArg>

    <DefineArg Name="YoYoUpPitch"><Description>
        Vehicle up pitch while performing the YoYo behavior.
    </Description><Units:degree/><Value>20</Value></DefineArg>

    <DefineArg Name="YoYoDownPitch"><Description>
        Vehicle down pitch while performing the YoYo behavior.
    </Description><Units:degree/><Value>-20</Value></DefineArg>

    <DefineArg Name="BuoyancyNeutral"><Description>
        Buoyancy bladder position while performing the YoYo behavior. Defaults
        to buoyancyNeutral setting in the Config/Control.cfg file. Set to NaN cc
        for active buoyancy
    </Description><Control:VerticalControl.buoyancyNeutral/></DefineArg>

    <DefineArg Name="MassDefault"><Description>
        Static setting for mass during the mission. Set to NaN mm for active
        mass position
    </Description><Control:VerticalControl.massDefault/></DefineArg>

    <DefineArg Name="MinAltitude"><Description>
        Minimum height above the sea floor for the entire mission.
    </Description><Units:meter/><Value>5</Value></DefineArg>

    <DefineArg Name="MaxDepth"><Description>
        Maximum depth for the entire mission.
    </Description><Units:meter/><Value>205</Value></DefineArg>

    <DefineArg Name="MinOffshore"><Description>
        Minimum offshore distance for the entire mission.
    </Description><Units:kilometer/><Value>2</Value></DefineArg>
    <Timeout Duration="MissionTimeout"/>

    <Insert Filename="Insert/Science.xml">
        <Description>
            Most missions will run the science sensors. If you don't place this
            aggregate above NeedComms, science instruments get turned off on the
            last upcast and while floating on the surface.
        </Description>
        <RedefineArg Name="SampleISUS"><True/></RedefineArg>
        <RedefineArg Name="PeakDetectChlActive"><True/></RedefineArg>
    </Insert>

    <Insert Filename="Insert/NeedComms.xml" Id="NeedComms"/>

    <Assign><Sequence/><Arg Name="NeedComms:DiveInterval"/><Arg Name="NeedCommsTime"/></Assign>

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

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MinAltitude"/><Arg Name="MinAltitude"/></Assign>

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MaxDepth"/><Arg Name="MaxDepth"/></Assign>

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MinOffshore"/><Arg Name="MinOffshore"/></Assign>

    <Call Id="StartingMission" RefId="NeedComms"/>

    <Guidance:Pitch>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Arg Name="MassDefault"/></Setting>
    </Guidance:Pitch>

    <Guidance:Buoyancy>
        <Parallel/>
        <Setting><Guidance:Buoyancy.position/><Arg Name="BuoyancyNeutral"/></Setting>
    </Guidance:Buoyancy>

    <Guidance:SetSpeed>
        <Parallel/>
        <Setting><Guidance:SetSpeed.speed/><Arg Name="Speed"/></Setting>
    </Guidance:SetSpeed>

    <Guidance:DepthEnvelope>
        <Description>
            Another depth envelope for the YoYo behavior. This envelope should
            fall within the limits of the standard safety envelopes in
            Insert/StandardEnvelopes.xml in order to avoid commanding high pitch
            angles for depth-terminated YoYos.
        </Description>
        <Parallel/>
        <Setting><Guidance:DepthEnvelope.minDepth/><Arg Name="YoYoMinDepth"/></Setting>
        <Setting><Guidance:DepthEnvelope.maxDepth/><Arg Name="YoYoMaxDepth"/></Setting>
        <Setting><Guidance:DepthEnvelope.downPitch/><Arg Name="YoYoDownPitch"/></Setting>
        <Setting><Guidance:DepthEnvelope.upPitch/><Arg Name="YoYoUpPitch"/></Setting>
    </Guidance:DepthEnvelope>

    <Guidance:AltitudeEnvelope>
        <Description>
            Another altitude envelope for the YoYo behavior. This envelope
            should fall within the limits of the standard safety envelopes in
            Insert/StandardEnvelopes.xml in order to avoid commanding high pitch
            angles for bottom-terminated YoYos.
        </Description>
        <Parallel/>
        <Setting><Guidance:AltitudeEnvelope.minAltitude/><Arg Name="YoYoMinAltitude"/></Setting>
        <Setting><Guidance:AltitudeEnvelope.upPitch/><Arg Name="YoYoUpPitch"/></Setting>
    </Guidance:AltitudeEnvelope>

    <Guidance:YoYo>
        <Parallel/>
        <Setting><Guidance:YoYo.downPitch/><Arg Name="YoYoDownPitch"/></Setting>
        <Setting><Guidance:YoYo.upPitch/><Arg Name="YoYoUpPitch"/></Setting>
    </Guidance:YoYo>

    <Aggregate Id="Lap">
        <Sequence Repeat="Repeat"/>

        <Aggregate Id="Wpt1">
            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat1"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon1"/></Setting>
            </Guidance:Waypoint>
        </Aggregate>

        <Aggregate Id="Wpt2">
            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat2"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon2"/></Setting>
            </Guidance:Waypoint>
        </Aggregate>

        <Aggregate Id="Wpt3">
            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat3"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon3"/></Setting>
            </Guidance:Waypoint>
        </Aggregate>

        <Aggregate Id="Wpt4">
            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat4"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon4"/></Setting>
            </Guidance:Waypoint>
        </Aggregate>

        <Aggregate Id="Wpt5">
            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat5"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon5"/></Setting>
            </Guidance:Waypoint>
        </Aggregate>

        <Aggregate Id="Wpt6">
            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat6"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon6"/></Setting>
            </Guidance:Waypoint>
        </Aggregate>

        <Aggregate Id="Wpt7">
            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat7"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon7"/></Setting>
            </Guidance:Waypoint>
        </Aggregate>
    </Aggregate>
</Mission>

2018-09-12T02:06:17.407Z,1536717977.407 [CommandLine](IMPORTANT): Loaded ./Missions/Science/sci2.xml
2018-09-12T02:06:26.982Z,1536717986.982 [CommandLine](IMPORTANT): got command set sci2.NeedCommsTime 15.000000 minute
2018-09-12T02:06:26.985Z,1536717986.985 [CommandLine](IMPORTANT): got command set sci2.Lat1 36.889999 degree
2018-09-12T02:06:26.986Z,1536717986.986 [CommandLine](IMPORTANT): got command set sci2.Lon1 -122.217499 degree
2018-09-12T02:06:26.987Z,1536717986.987 [CommandLine](IMPORTANT): got command set sci2.YoYoMinDepth 10.000000 meter
2018-09-12T02:06:26.987Z,1536717986.987 [CommandLine](IMPORTANT): got command set sci2.YoYoMaxDepth 40.000000 meter
2018-09-12T02:06:26.988Z,1536717986.988 [CommandLine](IMPORTANT): got command set sci2.YoYoMinAltitude 1.000000 meter
2018-09-12T02:06:28.356Z,1536717988.356 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=49232, MT Status=1, MTMSN=1529
2018-09-12T02:06:28.406Z,1536717988.406 [NAL9602](INFO): Sent 221 bytes from file Logs/20180912T011304/Express0008.lzma
2018-09-12T02:06:28.406Z,1536717988.406 [NAL9602](INFO): Packets left to send: 0
2018-09-12T02:06:28.408Z,1536717988.408 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180912T011304/Express0008.lzma.parts/0000.sbd
2018-09-12T02:06:28.408Z,1536717988.408 [NAL9602](DEBUG): Completed sending Logs/20180912T011304/Express0008.lzma
2018-09-12T02:06:29.090Z,1536717989.090 [NAL9602](INFO): Received command:configSet Express linearApproximation latitude 0.005 angular_degree persist;configSet Express linearApproximation longitude 0.005 angular_degree persist;configSet Express linearApproximation depth 5 meter persist
2018-09-12T02:06:29.674Z,1536717989.674 [CommandLine](IMPORTANT): got command set sci2.MinAltitude 1.000000 meter
2018-09-12T02:06:29.676Z,1536717989.676 [CommandLine](IMPORTANT): got command set sci2.MaxDepth 50.000000 meter
2018-09-12T02:06:29.677Z,1536717989.677 [CommandLine](IMPORTANT): got command run 
2018-09-12T02:06:29.697Z,1536717989.697 [CommandLine](IMPORTANT): Running 
2018-09-12T02:06:29.715Z,1536717989.715 [CommandLine](IMPORTANT): got command configSet 
2018-09-12T02:06:29.715Z,1536717989.715 [CommandLine](FAULT): Incomplete syntax. Try: help configSet
2018-09-12T02:06:29.729Z,1536717989.729 [NAL9602](CRITICAL): SIGSEGV: address not mapped to object
2018-09-12T02:06:29.738Z,1536717989.738 [NAL9602](CRITICAL): Bad address: 0x8
2018-09-12T02:06:29.738Z,1536717989.738 [NAL9602](CRITICAL): Backtrace: 
./bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x169c20]

2018-09-12T02:06:29.739Z,1536717989.739 [NAL9602] Software Fault, FailCount= 1
2018-09-12T02:06:29.739Z,1536717989.739 [NAL9602](ERROR): Software Fault
2018-09-12T02:06:29.762Z,1536717989.762 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-09-12T02:06:29.767Z,1536717989.767 [SyncHandler](INFO): Protected caller Thread ID is 930
2018-09-12T02:06:29.855Z,1536717989.855 [Default] Stopped
2018-09-12T02:06:29.855Z,1536717989.855 [Default](DEBUG): Aggregate::uninitialize Default
2018-09-12T02:06:29.855Z,1536717989.855 [Default:B.GoToSurface] Stopped
2018-09-12T02:06:29.855Z,1536717989.855 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-09-12T02:06:29.855Z,1536717989.855 [Default:CheckIn] Stopped
2018-09-12T02:06:29.855Z,1536717989.855 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-09-12T02:06:29.855Z,1536717989.855 [Default:CheckIn:Read_Iridium] Stopped
2018-09-12T02:06:29.856Z,1536717989.856 [MissionManager](IMPORTANT): Started mission sci2
2018-09-12T02:06:29.856Z,1536717989.856 [sci2] Running Loop=1
2018-09-12T02:06:29.856Z,1536717989.856 [sci2](DEBUG): Aggregate::initialize sci2
2018-09-12T02:06:29.856Z,1536717989.856 [sci2:Science] Running Loop=1
2018-09-12T02:06:29.856Z,1536717989.856 [sci2:Science](DEBUG): Aggregate::initialize sci2:Science
2018-09-12T02:06:29.856Z,1536717989.856 [sci2:Science:A] Running Loop=1
2018-09-12T02:06:29.856Z,1536717989.856 [sci2:Science:B] Running Loop=1
2018-09-12T02:06:29.856Z,1536717989.856 [sci2:Science:C] Running Loop=1
2018-09-12T02:06:29.857Z,1536717989.857 [sci2:Science:D] Running Loop=1
2018-09-12T02:06:29.857Z,1536717989.857 [sci2:Science:E] Running Loop=1
2018-09-12T02:06:29.857Z,1536717989.857 [sci2:Science:F] Running Loop=1
2018-09-12T02:06:29.857Z,1536717989.857 [sci2:Science:G] Running Loop=1
2018-09-12T02:06:29.857Z,1536717989.857 [sci2:Science:Read_Oil] Running Loop=1
2018-09-12T02:06:29.857Z,1536717989.857 [sci2:Science:PeakDetectChl] Running Loop=1
2018-09-12T02:06:29.857Z,1536717989.857 [sci2:Science:PeakDetectChl](DEBUG): Aggregate::initialize sci2:Science:PeakDetectChl
2018-09-12T02:06:29.857Z,1536717989.857 [sci2:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2018-09-12T02:06:29.857Z,1536717989.857 [sci2:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2018-09-12T02:06:29.863Z,1536717989.863 [sci2:Science:HighestChlPeakReport] Running Loop=1
2018-09-12T02:06:29.864Z,1536717989.864 [sci2:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize sci2:Science:HighestChlPeakReport
2018-09-12T02:06:29.864Z,1536717989.864 [sci2:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2018-09-12T02:06:29.864Z,1536717989.864 [sci2:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2018-09-12T02:06:29.864Z,1536717989.864 [sci2:Science:PeakDetectNO3] Running Loop=1
2018-09-12T02:06:29.864Z,1536717989.864 [sci2:Science:PeakDetectNO3](DEBUG): Aggregate::initialize sci2:Science:PeakDetectNO3
2018-09-12T02:06:29.865Z,1536717989.865 [sci2:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2018-09-12T02:06:29.865Z,1536717989.865 [sci2:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2018-09-12T02:06:29.867Z,1536717989.867 [sci2:Science:PeakDetectOil] Running Loop=1
2018-09-12T02:06:29.867Z,1536717989.867 [sci2:Science:PeakDetectOil](DEBUG): Aggregate::initialize sci2:Science:PeakDetectOil
2018-09-12T02:06:29.867Z,1536717989.867 [sci2:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2018-09-12T02:06:29.867Z,1536717989.867 [sci2:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2018-09-12T02:06:29.869Z,1536717989.869 [sci2:StandardEnvelopes] Running Loop=1
2018-09-12T02:06:29.869Z,1536717989.869 [sci2:StandardEnvelopes](DEBUG): Aggregate::initialize sci2:StandardEnvelopes
2018-09-12T02:06:29.878Z,1536717989.878 [sci2:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2018-09-12T02:06:29.878Z,1536717989.878 [sci2:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2018-09-12T02:06:29.878Z,1536717989.878 [sci2:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2018-09-12T02:06:29.878Z,1536717989.878 [sci2:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2018-09-12T02:06:29.879Z,1536717989.879 [sci2:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2018-09-12T02:06:29.879Z,1536717989.879 [sci2:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2018-09-12T02:06:29.879Z,1536717989.879 [sci2:I.Pitch] Running Loop=1
2018-09-12T02:06:29.879Z,1536717989.879 [sci2:I.Pitch](DEBUG): Initialize.
2018-09-12T02:06:29.879Z,1536717989.879 [sci2:J.Buoyancy] Running Loop=1
2018-09-12T02:06:29.879Z,1536717989.879 [sci2:J.Buoyancy](DEBUG): Initialize Buoyancy Component.
2018-09-12T02:06:29.879Z,1536717989.879 [sci2:K.SetSpeed] Running Loop=1
2018-09-12T02:06:29.879Z,1536717989.879 [sci2:K.SetSpeed](DEBUG): Initialize.
2018-09-12T02:06:29.880Z,1536717989.880 [sci2:L.DepthEnvelope] Running Loop=1
2018-09-12T02:06:29.880Z,1536717989.880 [sci2:L.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2018-09-12T02:06:29.880Z,1536717989.880 [sci2:M.AltitudeEnvelope] Running Loop=1
2018-09-12T02:06:29.880Z,1536717989.880 [sci2:M.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2018-09-12T02:06:29.880Z,1536717989.880 [sci2:N.YoYo] Running Loop=1
2018-09-12T02:06:29.880Z,1536717989.880 [sci2:N.YoYo](DEBUG): Initialize YoYoComponent.
2018-09-12T02:06:29.881Z,1536717989.881 [sci2:C] Running Loop=1
2018-09-12T02:06:29.881Z,1536717989.881 [sci2:N.YoYo] Running Loop=1
2018-09-12T02:06:29.895Z,1536717989.895 [sci2:M.AltitudeEnvelope] Running Loop=1
2018-09-12T02:06:29.904Z,1536717989.904 [sci2:L.DepthEnvelope] Running Loop=1
2018-09-12T02:06:29.916Z,1536717989.916 [sci2:K.SetSpeed] Running Loop=1
2018-09-12T02:06:29.929Z,1536717989.929 [sci2:J.Buoyancy] Running Loop=1
2018-09-12T02:06:29.942Z,1536717989.942 [sci2:I.Pitch] Running Loop=1
2018-09-12T02:06:29.951Z,1536717989.951 [sci2:StandardEnvelopes] Running Loop=1
2018-09-12T02:06:29.951Z,1536717989.951 [sci2:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2018-09-12T02:06:29.957Z,1536717989.957 [sci2:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2018-09-12T02:06:29.975Z,1536717989.975 [sci2:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2018-09-12T02:06:29.985Z,1536717989.985 [sci2:C] Stopped
2018-09-12T02:06:29.990Z,1536717989.990 [sci2:E] Running Loop=1
2018-09-12T02:06:29.990Z,1536717989.990 [sci2:NeedComms] Running Loop=1
2018-09-12T02:06:29.990Z,1536717989.990 [sci2:NeedComms](DEBUG): Aggregate::initialize sci2:NeedComms
2018-09-12T02:06:29.990Z,1536717989.990 [sci2:NeedComms:B.GoToSurface] Running Loop=1
2018-09-12T02:06:29.990Z,1536717989.990 [sci2:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-09-12T02:06:29.991Z,1536717989.991 [sci2:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2018-09-12T02:06:29.991Z,1536717989.991 [sci2:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2018-09-12T02:06:29.992Z,1536717989.992 [sci2:NeedComms:B.GoToSurface](INFO): Received speed setting 1.0000