2018-08-22T21:57:14.410Z,1534975034.410 [CommandLine](IMPORTANT): got command restart logs 2018-08-22T21:57:22.322Z,1534975042.322 [NAL9602](INFO): Powering up NAL9602 2018-08-22T21:57:33.122Z,1534975053.122 [NAL9602](INFO): NAL9602 initialized 2018-08-22T21:57:33.922Z,1534975053.922 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-08-22T21:57:33.923Z,1534975053.923 [NAL9602] Data Fault, FailCount= 4 2018-08-22T21:57:33.923Z,1534975053.923 [NAL9602](ERROR): Data Fault 2018-08-22T21:57:34.030Z,1534975054.030 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-22T21:57:34.322Z,1534975054.322 [NAL9602](INFO): Powering down 2018-08-22T21:57:35.185Z,1534975055.185 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-22T21:57:35.185Z,1534975055.185 [NAL9602] No Fault, FailCount= 4 2018-08-22T21:58:04.723Z,1534975084.723 [NAL9602](INFO): Powering up NAL9602 2018-08-22T21:58:16.002Z,1534975096.002 [NAL9602](INFO): NAL9602 initialized 2018-08-22T21:58:16.792Z,1534975096.792 [DataOverHttps](IMPORTANT): SBD MTMSN=20180822T215733 2018-08-22T21:58:21.638Z,1534975101.638 [DataOverHttps](INFO): Received command:sched asap "load Maintenance/sample.xml;set sample.MissionTimeout 5 hour;set sample.Depth 0 meter;set sample.NumberOfSamples 2 count;set sample.WaitBeforeSample 3 second;set sample:SampleAtDepth.Speed 0 meter_per_second" 3e2a2 1 2 2018-08-22T21:58:21.676Z,1534975101.676 [CommandLine](IMPORTANT): got command schedule asap "load Maintenance/sample.xml;set sample.MissionTimeout 5 hour;set sample.Depth 0 meter;set sample.NumberOfSamples 2 count;set sample.WaitBeforeSample 3 second;set sample:SampleAtDepth.Speed 0 meter_per_second" 3e2a2 1 2.000000 2018-08-22T21:58:21.676Z,1534975101.676 [CommandLine](IMPORTANT): Scheduling command #1 of 2 with id=3e2a2 2018-08-22T21:58:21.678Z,1534975101.678 [CommandLine](IMPORTANT): Scheduled #3 (#1 of 2 with id='3e2a2'): "load Maintenance/sample.xml;set sample.MissionTimeout 5 hour;set sample.Depth 0 meter;set sample.NumberOfSamples 2 count;set sample.WaitBeforeSample 3 second;set sample:SampleAtDepth.Speed 0 meter_per_second" ASAP 2018-08-22T21:58:22.436Z,1534975102.436 [DataOverHttps](IMPORTANT): SBD MTMSN=20180822T215739 2018-08-22T21:58:27.366Z,1534975107.366 [DataOverHttps](INFO): Received command:sched asap "set sample:SampleAtDepth.SpeedApproachingDepth 0 meter_per_second;set sample:SampleAtDepth.SpeedSamplingAtDepth 0 meter_per_second;set sample:SampleAtDepth.TargetDepth 0 meter;run " 3e2a2 2 2 2018-08-22T21:58:27.380Z,1534975107.380 [CommandLine](IMPORTANT): got command schedule asap "set sample:SampleAtDepth.SpeedApproachingDepth 0 meter_per_second;set sample:SampleAtDepth.SpeedSamplingAtDepth 0 meter_per_second;set sample:SampleAtDepth.TargetDepth 0 meter;run " 3e2a2 2 2.000000 2018-08-22T21:58:27.381Z,1534975107.381 [CommandLine](IMPORTANT): Scheduling command #2 of 2 with id=3e2a2 2018-08-22T21:58:27.382Z,1534975107.382 [CommandLine](IMPORTANT): Scheduled #4 (#2 of 2 with id='3e2a2'): "set sample:SampleAtDepth.SpeedApproachingDepth 0 meter_per_second;set sample:SampleAtDepth.SpeedSamplingAtDepth 0 meter_per_second;set sample:SampleAtDepth.TargetDepth 0 meter;run " ASAP 2018-08-22T21:58:27.497Z,1534975107.497 [CommandLine](IMPORTANT): got command load ./Missions/Maintenance/sample.xml 2018-08-22T21:58:27.498Z,1534975107.498 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/sample.xml 2018-08-22T21:58:27.580Z,1534975107.580 [MissionManager](INFO): DefineArg sample.MissionTimeout = 90.000000 min 2018-08-22T21:58:27.592Z,1534975107.592 [MissionManager](INFO): DefineArg sample.Depth = 7.000000 m 2018-08-22T21:58:27.603Z,1534975107.603 [MissionManager](INFO): DefineArg sample.NumberOfSamples = 1.000000 count 2018-08-22T21:58:27.607Z,1534975107.607 [MissionManager](INFO): DefineArg sample.SpeedApproachingTarget = 0.000000 m/s 2018-08-22T21:58:27.621Z,1534975107.621 [MissionManager](INFO): DefineArg sample.SpeedSampling = 0.000000 m/s 2018-08-22T21:58:27.624Z,1534975107.624 [MissionManager](INFO): DefineArg sample.RudderAngleSpiralOrDonut = 13.000000 arcdeg 2018-08-22T21:58:27.627Z,1534975107.627 [MissionManager](INFO): DefineArg sample.WaitBeforeSample = 3.000000 min 2018-08-22T21:58:27.629Z,1534975107.629 [sample:A.Pitch](DEBUG): Construct. 2018-08-22T21:58:27.645Z,1534975107.645 [MissionManager](INFO): Inserting Stack: Missions/Insert/SampleAtDepth.xml 2018-08-22T21:58:27.916Z,1534975107.916 [MissionManager](INFO): DefineArg sample:SampleAtDepth.Speed = 1.000000 m/s 2018-08-22T21:58:27.919Z,1534975107.919 [MissionManager](INFO): DefineArg sample:SampleAtDepth.SpeedApproachingDepth = 1.000000 m/s 2018-08-22T21:58:27.949Z,1534975107.949 [MissionManager](INFO): DefineArg sample:SampleAtDepth.SpeedSamplingAtDepth = 1.000000 m/s 2018-08-22T21:58:27.952Z,1534975107.952 [MissionManager](INFO): DefineArg sample:SampleAtDepth.RudderAngleInSpiralOrDonut = 13.000000 arcdeg 2018-08-22T21:58:27.956Z,1534975107.956 [MissionManager](INFO): DefineArg sample:SampleAtDepth.TargetDepth = 5.000000 m 2018-08-22T21:58:27.959Z,1534975107.959 [MissionManager](INFO): DefineArg sample:SampleAtDepth.SettleTime = 10.000000 s 2018-08-22T21:58:27.962Z,1534975107.962 [MissionManager](INFO): DefineArg sample:SampleAtDepth.MaxWaitNotReachingDepth = 3.000000 h 2018-08-22T21:58:27.971Z,1534975107.971 [MissionManager](INFO): DefineArg sample:SampleAtDepth.RotateOnly = 0.000000 bool 2018-08-22T21:58:27.977Z,1534975107.977 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseCANONSampler = 0.000000 bool 2018-08-22T21:58:27.991Z,1534975107.991 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseESP = 1.000000 bool 2018-08-22T21:58:28.006Z,1534975108.006 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTriggerTimeout = 1.000000 min 2018-08-22T21:58:28.009Z,1534975108.009 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTimeout = 6.000000 min 2018-08-22T21:58:28.013Z,1534975108.013 [MissionManager](INFO): DefineArg sample:SampleAtDepth.BuoyancyNeutral = 199.999995 cc 2018-08-22T21:58:28.031Z,1534975108.031 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:A.SetSpeed](DEBUG): Construct. 2018-08-22T21:58:28.034Z,1534975108.034 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:B.Buoyancy](DEBUG): Construct Buoyancy. 2018-08-22T21:58:28.037Z,1534975108.037 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:C.Point](DEBUG): Construct. 2018-08-22T21:58:28.050Z,1534975108.050 [sample:SampleAtDepth:SetZeroRudderInDriftMode:A.SetSpeed](DEBUG): Construct. 2018-08-22T21:58:28.053Z,1534975108.053 [sample:SampleAtDepth:SetZeroRudderInDriftMode:B.Point](DEBUG): Construct. 2018-08-22T21:58:28.085Z,1534975108.085 [sample:SampleAtDepth:D.Pitch](DEBUG): Construct. 2018-08-22T21:58:28.092Z,1534975108.092 [sample:SampleAtDepth:D.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute. 2018-08-22T21:58:28.110Z,1534975108.110 [sample:SampleAtDepth:SampleWrapper:B.Wait](DEBUG): Construct Wait. 2018-08-22T21:58:28.125Z,1534975108.125 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler:A_Timeout:B.Execute](DEBUG): Construct Execute. 2018-08-22T21:58:28.128Z,1534975108.128 [MissionManager](ERROR): Slate does not contain CTD_NeilBrown.bin_mean_sea_water_temperature 2018-08-22T21:58:28.128Z,1534975108.128 [MissionManager](ERROR): Slate does not contain celsius 2018-08-22T21:58:28.205Z,1534975108.205 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:E:A_Timeout:B.Execute](DEBUG): Construct Execute. 2018-08-22T21:58:28.219Z,1534975108.219 [MissionManager](ERROR): Slate does not contain CTD_NeilBrown.bin_mean_sea_water_temperature 2018-08-22T21:58:28.219Z,1534975108.219 [MissionManager](ERROR): Slate does not contain celsius 2018-08-22T21:58:28.318Z,1534975108.318 [MissionManager](DEBUG): This mission is designed to be run in the test tank only and samples whichever sampler is installed once the vehicle reaches the target depth. How long to let the mission run. 90 Depth to sample at. 7 Number of samples to take. 1 Vehicle speed when approaching the target depth. Initialized to zero. 0 Vehicle speed during sampling: 0.0 for drift mode (prop off); 1.0 for donut mode (prop on). Initialized to zero. 0 Rudder angle during spiral or donut, but not in drift mode. 13 How long to wait between samples. This starts *before* the first sample to exercise the SettleTime setting in the insert aggregate. 3 2018-08-22T21:58:28.318Z,1534975108.318 [CommandLine](IMPORTANT): Loaded ./Missions/Maintenance/sample.xml 2018-08-22T21:58:38.630Z,1534975118.630 [CommandLine](IMPORTANT): got command set sample.MissionTimeout 5.000000 hour 2018-08-22T21:58:38.631Z,1534975118.631 [CommandLine](IMPORTANT): got command set sample.Depth 0.000000 meter 2018-08-22T21:58:38.632Z,1534975118.632 [CommandLine](IMPORTANT): got command set sample.NumberOfSamples 2.000000 count 2018-08-22T21:58:38.633Z,1534975118.633 [CommandLine](IMPORTANT): got command set sample.WaitBeforeSample 3.000000 second 2018-08-22T21:58:38.633Z,1534975118.633 [CommandLine](IMPORTANT): got command set sample:SampleAtDepth.Speed 0.000000 meter_per_second 2018-08-22T21:58:48.757Z,1534975128.757 [CommandLine](IMPORTANT): got command set sample:SampleAtDepth.SpeedApproachingDepth 0.000000 meter_per_second 2018-08-22T21:58:48.758Z,1534975128.758 [CommandLine](IMPORTANT): got command set sample:SampleAtDepth.SpeedSamplingAtDepth 0.000000 meter_per_second 2018-08-22T21:58:48.759Z,1534975128.759 [CommandLine](IMPORTANT): got command set sample:SampleAtDepth.TargetDepth 0.000000 meter 2018-08-22T21:58:48.759Z,1534975128.759 [CommandLine](IMPORTANT): got command run 2018-08-22T21:58:48.762Z,1534975128.762 [CommandLine](IMPORTANT): Running 2018-08-22T21:58:49.029Z,1534975129.029 [Default] Stopped 2018-08-22T21:58:49.029Z,1534975129.029 [Default](DEBUG): Aggregate::uninitialize Default 2018-08-22T21:58:49.029Z,1534975129.029 [Default:B.GoToSurface] Stopped 2018-08-22T21:58:49.029Z,1534975129.029 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2018-08-22T21:58:49.029Z,1534975129.029 [Default:CheckIn] Stopped 2018-08-22T21:58:49.029Z,1534975129.029 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-08-22T21:58:49.029Z,1534975129.029 [Default:CheckIn:Read_GPS] Stopped 2018-08-22T21:58:49.029Z,1534975129.029 [MissionManager](IMPORTANT): Started mission sample 2018-08-22T21:58:49.030Z,1534975129.030 [sample] Running Loop=1 2018-08-22T21:58:49.030Z,1534975129.030 [sample](DEBUG): Aggregate::initialize sample 2018-08-22T21:58:49.030Z,1534975129.030 [sample:A.Pitch] Running Loop=1 2018-08-22T21:58:49.030Z,1534975129.030 [sample:A.Pitch](DEBUG): Initialize. 2018-08-22T21:58:49.030Z,1534975129.030 [sample:C] Running Loop=1 2018-08-22T21:58:49.032Z,1534975129.032 [sample:C] Stopped 2018-08-22T21:58:49.032Z,1534975129.032 [sample:D] Running Loop=1 2018-08-22T21:58:49.032Z,1534975129.032 [sample:A.Pitch] Running Loop=1 2018-08-22T21:58:49.416Z,1534975129.416 [sample:D] Stopped 2018-08-22T21:58:49.417Z,1534975129.417 [sample:E] Running Loop=1 2018-08-22T21:58:49.813Z,1534975129.813 [sample:E] Stopped 2018-08-22T21:58:49.813Z,1534975129.813 [sample:F] Running Loop=1 2018-08-22T21:58:50.227Z,1534975130.227 [sample:F] Stopped 2018-08-22T21:58:50.227Z,1534975130.227 [sample:G] Running Loop=1 2018-08-22T21:58:50.626Z,1534975130.626 [sample:G] Stopped 2018-08-22T21:58:50.626Z,1534975130.626 [sample:SampleRepeater] Running Loop=1 2018-08-22T21:58:50.626Z,1534975130.626 [sample:SampleRepeater](DEBUG): Aggregate::initialize sample:SampleRepeater 2018-08-22T21:58:50.626Z,1534975130.626 [sample:SampleRepeater:Sample] Running Loop=1 2018-08-22T21:58:50.626Z,1534975130.626 [sample:SampleRepeater:Sample](DEBUG): Aggregate::initialize sample:SampleRepeater:Sample 2018-08-22T21:58:50.885Z,1534975130.885 [CommandLine](IMPORTANT): got command stop 2018-08-22T21:58:50.885Z,1534975130.885 [CommandLine](IMPORTANT): Scheduling is paused 2018-08-22T21:58:50.885Z,1534975130.885 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop 2018-08-22T21:58:51.033Z,1534975131.033 [sample:SampleAtDepth] Running Loop=1 2018-08-22T21:58:51.033Z,1534975131.033 [sample:SampleAtDepth](DEBUG): Aggregate::initialize sample:SampleAtDepth 2018-08-22T21:58:51.033Z,1534975131.033 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode] Running Loop=1 2018-08-22T21:58:51.034Z,1534975131.034 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode](DEBUG): Aggregate::initialize sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode 2018-08-22T21:58:51.034Z,1534975131.034 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:A.SetSpeed] Running Loop=1 2018-08-22T21:58:51.034Z,1534975131.034 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:A.SetSpeed](DEBUG): Initialize. 2018-08-22T21:58:51.034Z,1534975131.034 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:B.Buoyancy] Running Loop=1 2018-08-22T21:58:51.034Z,1534975131.034 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:B.Buoyancy](DEBUG): Initialize Buoyancy Component. 2018-08-22T21:58:51.034Z,1534975131.034 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:C.Point] Running Loop=1 2018-08-22T21:58:51.034Z,1534975131.034 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:C.Point](DEBUG): Initialize. 2018-08-22T21:58:51.034Z,1534975131.034 [sample:SampleAtDepth:SetZeroRudderInDriftMode] Running Loop=1 2018-08-22T21:58:51.035Z,1534975131.035 [sample:SampleAtDepth:SetZeroRudderInDriftMode](DEBUG): Aggregate::initialize sample:SampleAtDepth:SetZeroRudderInDriftMode 2018-08-22T21:58:51.035Z,1534975131.035 [sample:SampleAtDepth:SetZeroRudderInDriftMode:A.SetSpeed] Running Loop=1 2018-08-22T21:58:51.035Z,1534975131.035 [sample:SampleAtDepth:SetZeroRudderInDriftMode:A.SetSpeed](DEBUG): Initialize. 2018-08-22T21:58:51.035Z,1534975131.035 [sample:SampleAtDepth:SetZeroRudderInDriftMode:B.Point] Running Loop=1 2018-08-22T21:58:51.035Z,1534975131.035 [sample:SampleAtDepth:SetZeroRudderInDriftMode:B.Point](DEBUG): Initialize. 2018-08-22T21:58:51.035Z,1534975131.035 [sample:SampleAtDepth:D.Pitch] Running Loop=1 2018-08-22T21:58:51.035Z,1534975131.035 [sample:SampleAtDepth:D.Pitch](DEBUG): Initialize. 2018-08-22T21:58:51.036Z,1534975131.036 [sample:SampleAtDepth:SetSpeedApproachDepth] Running Loop=1 2018-08-22T21:58:51.036Z,1534975131.036 [sample:SampleAtDepth:SetSpeedApproachDepth](DEBUG): Aggregate::initialize sample:SampleAtDepth:SetSpeedApproachDepth 2018-08-22T21:58:51.036Z,1534975131.036 [sample:SampleAtDepth:SetSpeedApproachDepth:A] Running Loop=1 2018-08-22T21:58:51.045Z,1534975131.045 [sample:SampleAtDepth:SetZeroRudderInDriftMode] Running Loop=1 2018-08-22T21:58:51.046Z,1534975131.046 [sample:SampleAtDepth:SetZeroRudderInDriftMode:B.Point] Running Loop=1 2018-08-22T21:58:51.051Z,1534975131.051 [sample:SampleAtDepth:SetZeroRudderInDriftMode:A.SetSpeed] Running Loop=1 2018-08-22T21:58:51.064Z,1534975131.064 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode] Stopped 2018-08-22T21:58:51.064Z,1534975131.064 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode 2018-08-22T21:58:51.064Z,1534975131.064 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:A.SetSpeed] Stopped 2018-08-22T21:58:51.064Z,1534975131.064 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:A.SetSpeed](DEBUG): Uninitialize. 2018-08-22T21:58:51.064Z,1534975131.064 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:B.Buoyancy] Stopped 2018-08-22T21:58:51.064Z,1534975131.064 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2018-08-22T21:58:51.064Z,1534975131.064 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:C.Point] Stopped 2018-08-22T21:58:51.069Z,1534975131.069 [sample:SampleAtDepth:SetSpeedApproachDepth:A](INFO): Moving to 0.000000 m 2018-08-22T21:58:51.070Z,1534975131.070 [sample:SampleAtDepth:SetSpeedApproachDepth:A] Stopped 2018-08-22T21:58:51.071Z,1534975131.071 [sample:SampleAtDepth:SetSpeedApproachDepth:B] Running Loop=1 2018-08-22T21:58:51.071Z,1534975131.071 [MissionManager](INFO): MissionManager is completed. 2018-08-22T21:58:51.071Z,1534975131.071 [MissionManager](INFO): Uninitializing Mission sample 2018-08-22T21:58:51.071Z,1534975131.071 [sample] Stopped 2018-08-22T21:58:51.072Z,1534975131.072 [sample](DEBUG): Aggregate::uninitialize sample 2018-08-22T21:58:51.072Z,1534975131.072 [sample:A.Pitch] Stopped 2018-08-22T21:58:51.072Z,1534975131.072 [sample:SampleAtDepth] Stopped 2018-08-22T21:58:51.072Z,1534975131.072 [sample:SampleAtDepth](DEBUG): Aggregate::uninitialize sample:SampleAtDepth 2018-08-22T21:58:51.072Z,1534975131.072 [sample:SampleAtDepth:SetSpeedApproachDepth] Stopped 2018-08-22T21:58:51.072Z,1534975131.072 [sample:SampleAtDepth:SetSpeedApproachDepth](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SetSpeedApproachDepth 2018-08-22T21:58:51.072Z,1534975131.072 [sample:SampleAtDepth:SetSpeedApproachDepth:B] Stopped 2018-08-22T21:58:51.072Z,1534975131.072 [sample:SampleAtDepth:SetZeroRudderInDriftMode] Stopped 2018-08-22T21:58:51.072Z,1534975131.072 [sample:SampleAtDepth:SetZeroRudderInDriftMode](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SetZeroRudderInDriftMode 2018-08-22T21:58:51.075Z,1534975131.075 [sample:SampleAtDepth:SetZeroRudderInDriftMode:A.SetSpeed] Stopped 2018-08-22T21:58:51.075Z,1534975131.075 [sample:SampleAtDepth:SetZeroRudderInDriftMode:A.SetSpeed](DEBUG): Uninitialize. 2018-08-22T21:58:51.075Z,1534975131.075 [sample:SampleAtDepth:SetZeroRudderInDriftMode:B.Point] Stopped 2018-08-22T21:58:51.075Z,1534975131.075 [sample:SampleAtDepth:D.Pitch] Stopped 2018-08-22T21:58:51.076Z,1534975131.076 [sample:SampleRepeater] Stopped 2018-08-22T21:58:51.076Z,1534975131.076 [sample:SampleRepeater](DEBUG): Aggregate::uninitialize sample:SampleRepeater 2018-08-22T21:58:51.076Z,1534975131.076 [sample:SampleRepeater:Sample] Stopped 2018-08-22T21:58:51.076Z,1534975131.076 [sample:SampleRepeater:Sample](DEBUG): Aggregate::uninitialize sample:SampleRepeater:Sample 2018-08-22T21:58:51.412Z,1534975131.412 [MissionManager](IMPORTANT): Started mission Default 2018-08-22T21:58:51.412Z,1534975131.412 [Default] Running Loop=1 2018-08-22T21:58:51.412Z,1534975131.412 [Default](DEBUG): Aggregate::initialize Default 2018-08-22T21:58:51.412Z,1534975131.412 [Default:B.GoToSurface] Running Loop=1 2018-08-22T21:58:51.412Z,1534975131.412 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2018-08-22T21:58:51.441Z,1534975131.441 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2018-08-22T21:58:51.441Z,1534975131.441 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2018-08-22T21:58:51.441Z,1534975131.441 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2018-08-22T21:58:51.442Z,1534975131.442 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2018-08-22T21:58:51.442Z,1534975131.442 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2018-08-22T21:58:51.443Z,1534975131.443 [Default:A.Wait] Running Loop=1 2018-08-22T21:58:51.443Z,1534975131.443 [Default:A.Wait](DEBUG): Initialize Wait Component. 2018-08-22T21:58:55.008Z,1534975135.008 [CommandLine](IMPORTANT): got command show stack 2018-08-22T21:58:55.009Z,1534975135.009 [CommandLine](IMPORTANT): Behavior Stack: 2018-08-22T21:58:55.009Z,1534975135.009 [Default](IMPORTANT): Priority 0: Default:A.Wait 2018-08-22T21:58:55.009Z,1534975135.009 [Default](IMPORTANT): Priority 1: Default:B.GoToSurface 2018-08-22T21:58:56.971Z,1534975136.971 [NAL9602](INFO): SBD MO Status=2, MOMSN=23407, MT Status=2, MTMSN=0 2018-08-22T21:58:56.971Z,1534975136.971 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2018-08-22T21:59:04.801Z,1534975144.801 [Default:A.Wait](INFO): Done Waiting. 2018-08-22T21:59:04.801Z,1534975144.801 [Default:A.Wait] Stopped 2018-08-22T21:59:04.804Z,1534975144.804 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2018-08-22T21:59:05.196Z,1534975145.196 [Default:CheckIn] Running Loop=1 2018-08-22T21:59:05.196Z,1534975145.196 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-08-22T21:59:05.196Z,1534975145.196 [Default:CheckIn:Read_GPS] Running Loop=1 2018-08-22T21:59:19.920Z,1534975159.920 [NAL9602](INFO): SBD MO Status=2, MOMSN=23407, MT Status=2, MTMSN=0 2018-08-22T21:59:19.920Z,1534975159.920 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2018-08-22T21:59:29.840Z,1534975169.840 [DataOverHttps](IMPORTANT): SBD MTMSN=20180822T215846 2018-08-22T21:59:34.930Z,1534975174.930 [DataOverHttps](INFO): Received command:sched asap "load Maintenance/sample.xml;set sample.MissionTimeout 5 hour;set sample.Depth 0 meter;set sample.NumberOfSamples 2 count;set sample.WaitBeforeSample 3 second;set sample:SampleAtDepth.Speed 0 meter_per_second" 3e2cl 1 2 2018-08-22T21:59:34.978Z,1534975174.978 [CommandLine](IMPORTANT): got command schedule asap "load Maintenance/sample.xml;set sample.MissionTimeout 5 hour;set sample.Depth 0 meter;set sample.NumberOfSamples 2 count;set sample.WaitBeforeSample 3 second;set sample:SampleAtDepth.Speed 0 meter_per_second" 3e2cl 1 2.000000 2018-08-22T21:59:34.978Z,1534975174.978 [CommandLine](IMPORTANT): Scheduling command #1 of 2 with id=3e2cl 2018-08-22T21:59:34.979Z,1534975174.979 [CommandLine](IMPORTANT): Scheduled #5 (#1 of 2 with id='3e2cl'): "load Maintenance/sample.xml;set sample.MissionTimeout 5 hour;set sample.Depth 0 meter;set sample.NumberOfSamples 2 count;set sample.WaitBeforeSample 3 second;set sample:SampleAtDepth.Speed 0 meter_per_second" ASAP 2018-08-22T21:59:35.728Z,1534975175.728 [DataOverHttps](IMPORTANT): SBD MTMSN=20180822T215852 2018-08-22T21:59:40.603Z,1534975180.603 [DataOverHttps](INFO): Received command:sched asap "set sample:SampleAtDepth.SpeedApproachingDepth 0 meter_per_second;set sample:SampleAtDepth.SpeedSamplingAtDepth 0 meter_per_second;set sample:SampleAtDepth.TargetDepth 0 meter;run " 3e2cl 2 2 2018-08-22T21:59:40.680Z,1534975180.680 [CommandLine](IMPORTANT): got command schedule asap "set sample:SampleAtDepth.SpeedApproachingDepth 0 meter_per_second;set sample:SampleAtDepth.SpeedSamplingAtDepth 0 meter_per_second;set sample:SampleAtDepth.TargetDepth 0 meter;run " 3e2cl 2 2.000000 2018-08-22T21:59:40.681Z,1534975180.681 [CommandLine](IMPORTANT): Scheduling command #2 of 2 with id=3e2cl 2018-08-22T21:59:40.682Z,1534975180.682 [CommandLine](IMPORTANT): Scheduled #6 (#2 of 2 with id='3e2cl'): "set sample:SampleAtDepth.SpeedApproachingDepth 0 meter_per_second;set sample:SampleAtDepth.SpeedSamplingAtDepth 0 meter_per_second;set sample:SampleAtDepth.TargetDepth 0 meter;run " ASAP 2018-08-22T21:59:40.790Z,1534975180.790 [CommandLine](IMPORTANT): got command load ./Missions/Maintenance/sample.xml 2018-08-22T21:59:40.790Z,1534975180.790 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/sample.xml 2018-08-22T21:59:40.844Z,1534975180.844 [MissionManager](INFO): DefineArg sample.MissionTimeout = 90.000000 min 2018-08-22T21:59:40.887Z,1534975180.887 [MissionManager](INFO): DefineArg sample.Depth = 7.000000 m 2018-08-22T21:59:40.889Z,1534975180.889 [MissionManager](INFO): DefineArg sample.NumberOfSamples = 1.000000 count 2018-08-22T21:59:40.891Z,1534975180.891 [MissionManager](INFO): DefineArg sample.SpeedApproachingTarget = 0.000000 m/s 2018-08-22T21:59:40.894Z,1534975180.894 [MissionManager](INFO): DefineArg sample.SpeedSampling = 0.000000 m/s 2018-08-22T21:59:40.896Z,1534975180.896 [MissionManager](INFO): DefineArg sample.RudderAngleSpiralOrDonut = 13.000000 arcdeg 2018-08-22T21:59:40.912Z,1534975180.912 [MissionManager](INFO): DefineArg sample.WaitBeforeSample = 3.000000 min 2018-08-22T21:59:40.913Z,1534975180.913 [sample:A.Pitch](DEBUG): Construct. 2018-08-22T21:59:40.917Z,1534975180.917 [MissionManager](INFO): Inserting Stack: Missions/Insert/SampleAtDepth.xml 2018-08-22T21:59:41.175Z,1534975181.175 [MissionManager](INFO): DefineArg sample:SampleAtDepth.Speed = 1.000000 m/s 2018-08-22T21:59:41.178Z,1534975181.178 [MissionManager](INFO): DefineArg sample:SampleAtDepth.SpeedApproachingDepth = 1.000000 m/s 2018-08-22T21:59:41.180Z,1534975181.180 [MissionManager](INFO): DefineArg sample:SampleAtDepth.SpeedSamplingAtDepth = 1.000000 m/s 2018-08-22T21:59:41.182Z,1534975181.182 [MissionManager](INFO): DefineArg sample:SampleAtDepth.RudderAngleInSpiralOrDonut = 13.000000 arcdeg 2018-08-22T21:59:41.184Z,1534975181.184 [MissionManager](INFO): DefineArg sample:SampleAtDepth.TargetDepth = 5.000000 m 2018-08-22T21:59:41.186Z,1534975181.186 [MissionManager](INFO): DefineArg sample:SampleAtDepth.SettleTime = 10.000000 s 2018-08-22T21:59:41.188Z,1534975181.188 [MissionManager](INFO): DefineArg sample:SampleAtDepth.MaxWaitNotReachingDepth = 3.000000 h 2018-08-22T21:59:41.191Z,1534975181.191 [MissionManager](INFO): DefineArg sample:SampleAtDepth.RotateOnly = 0.000000 bool 2018-08-22T21:59:41.193Z,1534975181.193 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseCANONSampler = 0.000000 bool 2018-08-22T21:59:41.195Z,1534975181.195 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseESP = 1.000000 bool 2018-08-22T21:59:41.198Z,1534975181.198 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTriggerTimeout = 1.000000 min 2018-08-22T21:59:41.200Z,1534975181.200 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTimeout = 6.000000 min 2018-08-22T21:59:41.235Z,1534975181.235 [MissionManager](INFO): DefineArg sample:SampleAtDepth.BuoyancyNeutral = 199.999995 cc 2018-08-22T21:59:41.240Z,1534975181.240 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:A.SetSpeed](DEBUG): Construct. 2018-08-22T21:59:41.242Z,1534975181.242 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:B.Buoyancy](DEBUG): Construct Buoyancy. 2018-08-22T21:59:41.273Z,1534975181.273 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:C.Point](DEBUG): Construct. 2018-08-22T21:59:41.279Z,1534975181.279 [sample:SampleAtDepth:SetZeroRudderInDriftMode:A.SetSpeed](DEBUG): Construct. 2018-08-22T21:59:41.281Z,1534975181.281 [sample:SampleAtDepth:SetZeroRudderInDriftMode:B.Point](DEBUG): Construct. 2018-08-22T21:59:41.322Z,1534975181.322 [sample:SampleAtDepth:D.Pitch](DEBUG): Construct. 2018-08-22T21:59:41.327Z,1534975181.327 [sample:SampleAtDepth:D.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute. 2018-08-22T21:59:41.332Z,1534975181.332 [sample:SampleAtDepth:SampleWrapper:B.Wait](DEBUG): Construct Wait. 2018-08-22T21:59:41.375Z,1534975181.375 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler:A_Timeout:B.Execute](DEBUG): Construct Execute. 2018-08-22T21:59:41.390Z,1534975181.390 [MissionManager](ERROR): Slate does not contain CTD_NeilBrown.bin_mean_sea_water_temperature 2018-08-22T21:59:41.390Z,1534975181.390 [MissionManager](ERROR): Slate does not contain celsius 2018-08-22T21:59:41.462Z,1534975181.462 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:E:A_Timeout:B.Execute](DEBUG): Construct Execute. 2018-08-22T21:59:41.474Z,1534975181.474 [MissionManager](ERROR): Slate does not contain CTD_NeilBrown.bin_mean_sea_water_temperature 2018-08-22T21:59:41.475Z,1534975181.475 [MissionManager](ERROR): Slate does not contain celsius 2018-08-22T21:59:41.543Z,1534975181.543 [MissionManager](DEBUG): This mission is designed to be run in the test tank only and samples whichever sampler is installed once the vehicle reaches the target depth. How long to let the mission run. 90 Depth to sample at. 7 Number of samples to take. 1 Vehicle speed when approaching the target depth. Initialized to zero. 0 Vehicle speed during sampling: 0.0 for drift mode (prop off); 1.0 for donut mode (prop on). Initialized to zero. 0 Rudder angle during spiral or donut, but not in drift mode. 13 How long to wait between samples. This starts *before* the first sample to exercise the SettleTime setting in the insert aggregate. 3 2018-08-22T21:59:41.544Z,1534975181.544 [CommandLine](IMPORTANT): Loaded ./Missions/Maintenance/sample.xml 2018-08-22T21:59:51.151Z,1534975191.151 [CommandLine](IMPORTANT): got command set sample.MissionTimeout 5.000000 hour 2018-08-22T21:59:51.152Z,1534975191.152 [CommandLine](IMPORTANT): got command set sample.Depth 0.000000 meter 2018-08-22T21:59:51.157Z,1534975191.157 [CommandLine](IMPORTANT): got command set sample.NumberOfSamples 2.000000 count 2018-08-22T21:59:51.158Z,1534975191.158 [CommandLine](IMPORTANT): got command set sample.WaitBeforeSample 3.000000 second 2018-08-22T21:59:51.159Z,1534975191.159 [CommandLine](IMPORTANT): got command set sample:SampleAtDepth.Speed 0.000000 meter_per_second 2018-08-22T22:00:00.986Z,1534975200.986 [CommandLine](IMPORTANT): got command set sample:SampleAtDepth.SpeedApproachingDepth 0.000000 meter_per_second 2018-08-22T22:00:00.987Z,1534975200.987 [CommandLine](IMPORTANT): got command set sample:SampleAtDepth.SpeedSamplingAtDepth 0.000000 meter_per_second 2018-08-22T22:00:00.988Z,1534975200.988 [CommandLine](IMPORTANT): got command set sample:SampleAtDepth.TargetDepth 0.000000 meter 2018-08-22T22:00:00.988Z,1534975200.988 [CommandLine](IMPORTANT): got command run 2018-08-22T22:00:00.990Z,1534975200.990 [CommandLine](IMPORTANT): Running 2018-08-22T22:00:01.117Z,1534975201.117 [Default] Stopped 2018-08-22T22:00:01.117Z,1534975201.117 [Default](DEBUG): Aggregate::uninitialize Default 2018-08-22T22:00:01.117Z,1534975201.117 [Default:B.GoToSurface] Stopped 2018-08-22T22:00:01.118Z,1534975201.118 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2018-08-22T22:00:01.118Z,1534975201.118 [Default:CheckIn] Stopped 2018-08-22T22:00:01.118Z,1534975201.118 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-08-22T22:00:01.118Z,1534975201.118 [Default:CheckIn:Read_GPS] Stopped 2018-08-22T22:00:01.118Z,1534975201.118 [MissionManager](IMPORTANT): Started mission sample 2018-08-22T22:00:01.118Z,1534975201.118 [sample] Running Loop=1 2018-08-22T22:00:01.118Z,1534975201.118 [sample](DEBUG): Aggregate::initialize sample 2018-08-22T22:00:01.119Z,1534975201.119 [sample:A.Pitch] Running Loop=1 2018-08-22T22:00:01.119Z,1534975201.119 [sample:A.Pitch](DEBUG): Initialize. 2018-08-22T22:00:01.119Z,1534975201.119 [sample:C] Running Loop=1 2018-08-22T22:00:01.120Z,1534975201.120 [sample:C] Stopped 2018-08-22T22:00:01.120Z,1534975201.120 [sample:D] Running Loop=1 2018-08-22T22:00:01.120Z,1534975201.120 [sample:A.Pitch] Running Loop=1 2018-08-22T22:00:01.576Z,1534975201.576 [sample:D] Stopped 2018-08-22T22:00:01.577Z,1534975201.577 [sample:E] Running Loop=1 2018-08-22T22:00:01.861Z,1534975201.861 [sample:E] Stopped 2018-08-22T22:00:01.861Z,1534975201.861 [sample:F] Running Loop=1 2018-08-22T22:00:02.359Z,1534975202.359 [sample:F] Stopped 2018-08-22T22:00:02.359Z,1534975202.359 [sample:G] Running Loop=1 2018-08-22T22:00:02.772Z,1534975202.772 [sample:G] Stopped 2018-08-22T22:00:02.772Z,1534975202.772 [sample:SampleRepeater] Running Loop=1 2018-08-22T22:00:02.772Z,1534975202.772 [sample:SampleRepeater](DEBUG): Aggregate::initialize sample:SampleRepeater 2018-08-22T22:00:02.772Z,1534975202.772 [sample:SampleRepeater:Sample] Running Loop=1 2018-08-22T22:00:02.772Z,1534975202.772 [sample:SampleRepeater:Sample](DEBUG): Aggregate::initialize sample:SampleRepeater:Sample 2018-08-22T22:00:03.137Z,1534975203.137 [sample:SampleAtDepth] Running Loop=1 2018-08-22T22:00:03.137Z,1534975203.137 [sample:SampleAtDepth](DEBUG): Aggregate::initialize sample:SampleAtDepth 2018-08-22T22:00:03.137Z,1534975203.137 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode] Running Loop=1 2018-08-22T22:00:03.138Z,1534975203.138 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode](DEBUG): Aggregate::initialize sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode 2018-08-22T22:00:03.138Z,1534975203.138 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:A.SetSpeed] Running Loop=1 2018-08-22T22:00:03.138Z,1534975203.138 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:A.SetSpeed](DEBUG): Initialize. 2018-08-22T22:00:03.138Z,1534975203.138 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:B.Buoyancy] Running Loop=1 2018-08-22T22:00:03.138Z,1534975203.138 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:B.Buoyancy](DEBUG): Initialize Buoyancy Component. 2018-08-22T22:00:03.138Z,1534975203.138 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:C.Point] Running Loop=1 2018-08-22T22:00:03.138Z,1534975203.138 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:C.Point](DEBUG): Initialize. 2018-08-22T22:00:03.138Z,1534975203.138 [sample:SampleAtDepth:SetZeroRudderInDriftMode] Running Loop=1 2018-08-22T22:00:03.139Z,1534975203.139 [sample:SampleAtDepth:SetZeroRudderInDriftMode](DEBUG): Aggregate::initialize sample:SampleAtDepth:SetZeroRudderInDriftMode 2018-08-22T22:00:03.139Z,1534975203.139 [sample:SampleAtDepth:SetZeroRudderInDriftMode:A.SetSpeed] Running Loop=1 2018-08-22T22:00:03.139Z,1534975203.139 [sample:SampleAtDepth:SetZeroRudderInDriftMode:A.SetSpeed](DEBUG): Initialize. 2018-08-22T22:00:03.139Z,1534975203.139 [sample:SampleAtDepth:SetZeroRudderInDriftMode:B.Point] Running Loop=1 2018-08-22T22:00:03.139Z,1534975203.139 [sample:SampleAtDepth:SetZeroRudderInDriftMode:B.Point](DEBUG): Initialize. 2018-08-22T22:00:03.139Z,1534975203.139 [sample:SampleAtDepth:D.Pitch] Running Loop=1 2018-08-22T22:00:03.139Z,1534975203.139 [sample:SampleAtDepth:D.Pitch](DEBUG): Initialize. 2018-08-22T22:00:03.140Z,1534975203.140 [sample:SampleAtDepth:SetSpeedApproachDepth] Running Loop=1 2018-08-22T22:00:03.140Z,1534975203.140 [sample:SampleAtDepth:SetSpeedApproachDepth](DEBUG): Aggregate::initialize sample:SampleAtDepth:SetSpeedApproachDepth 2018-08-22T22:00:03.140Z,1534975203.140 [sample:SampleAtDepth:SetSpeedApproachDepth:A] Running Loop=1 2018-08-22T22:00:03.166Z,1534975203.166 [sample:SampleAtDepth:SetZeroRudderInDriftMode] Running Loop=1 2018-08-22T22:00:03.166Z,1534975203.166 [sample:SampleAtDepth:SetZeroRudderInDriftMode:B.Point] Running Loop=1 2018-08-22T22:00:03.167Z,1534975203.167 [sample:SampleAtDepth:SetZeroRudderInDriftMode:A.SetSpeed] Running Loop=1 2018-08-22T22:00:03.168Z,1534975203.168 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode] Stopped 2018-08-22T22:00:03.168Z,1534975203.168 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode 2018-08-22T22:00:03.168Z,1534975203.168 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:A.SetSpeed] Stopped 2018-08-22T22:00:03.168Z,1534975203.168 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:A.SetSpeed](DEBUG): Uninitialize. 2018-08-22T22:00:03.168Z,1534975203.168 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:B.Buoyancy] Stopped 2018-08-22T22:00:03.168Z,1534975203.168 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2018-08-22T22:00:03.168Z,1534975203.168 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:C.Point] Stopped 2018-08-22T22:00:03.175Z,1534975203.175 [sample:SampleAtDepth:SetSpeedApproachDepth:A](INFO): Moving to 0.000000 m 2018-08-22T22:00:03.189Z,1534975203.189 [sample:SampleAtDepth:SetSpeedApproachDepth:A] Stopped 2018-08-22T22:00:03.189Z,1534975203.189 [sample:SampleAtDepth:SetSpeedApproachDepth:B] Running Loop=1 2018-08-22T22:00:03.492Z,1534975203.492 [sample:SampleAtDepth:SetSpeedApproachDepth:B] Stopped 2018-08-22T22:00:03.492Z,1534975203.492 [sample:SampleAtDepth:SetSpeedApproachDepth](INFO): Completed sample:SampleAtDepth:SetSpeedApproachDepth 2018-08-22T22:00:03.492Z,1534975203.492 [sample:SampleAtDepth:SetSpeedApproachDepth] Stopped 2018-08-22T22:00:03.492Z,1534975203.492 [sample:SampleAtDepth:SetSpeedApproachDepth](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SetSpeedApproachDepth 2018-08-22T22:00:05.004Z,1534975205.004 [NAL9602](INFO): SBD MO Status=2, MOMSN=23407, MT Status=2, MTMSN=0 2018-08-22T22:00:05.004Z,1534975205.004 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2018-08-22T22:00:15.299Z,1534975215.299 [CommandLine](IMPORTANT): got command maintain sensor Depth_Keller.depth 0.000000 meter 2018-08-22T22:00:15.300Z,1534975215.300 [ComponentRegistry](DEBUG): SyncComponent "Maintain_Depth_Keller.depth" handled in the control thread. 2018-08-22T22:00:15.510Z,1534975215.510 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,Maintain_NAL9602.latitude_fix,Maintain_NAL9602.longitude_fix,Maintain_Depth_Keller.depth,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2018-08-22T22:00:15.869Z,1534975215.869 [sample:SampleAtDepth:E] Running Loop=1 2018-08-22T22:00:16.262Z,1534975216.262 [sample:SampleAtDepth:E] Stopped 2018-08-22T22:00:16.262Z,1534975216.262 [sample:SampleAtDepth:SampleWrapper] Running Loop=1 2018-08-22T22:00:16.262Z,1534975216.262 [sample:SampleAtDepth:SampleWrapper](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper 2018-08-22T22:00:16.262Z,1534975216.262 [sample:SampleAtDepth:SampleWrapper:A] Running Loop=1 2018-08-22T22:00:16.674Z,1534975216.674 [sample:SampleAtDepth:SampleWrapper:A](INFO): At 0.000000 m , settling for 0.050000 min 2018-08-22T22:00:16.676Z,1534975216.676 [sample:SampleAtDepth:SampleWrapper:A] Stopped 2018-08-22T22:00:16.676Z,1534975216.676 [sample:SampleAtDepth:SampleWrapper:B.Wait] Running Loop=1 2018-08-22T22:00:16.676Z,1534975216.676 [sample:SampleAtDepth:SampleWrapper:B.Wait](DEBUG): Initialize Wait Component. 2018-08-22T22:00:20.275Z,1534975220.275 [sample:SampleAtDepth:SampleWrapper:B.Wait](INFO): Done Waiting. 2018-08-22T22:00:20.276Z,1534975220.276 [sample:SampleAtDepth:SampleWrapper:B.Wait] Stopped 2018-08-22T22:00:20.276Z,1534975220.276 [sample:SampleAtDepth:SampleWrapper:B.Wait](DEBUG): Uninitialize Wait Component. 2018-08-22T22:00:20.276Z,1534975220.276 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler] Running Loop=1 2018-08-22T22:00:20.276Z,1534975220.276 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper:SampleCANONSampler 2018-08-22T22:00:20.276Z,1534975220.276 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:A] Running Loop=1 2018-08-22T22:00:20.276Z,1534975220.276 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:B] Running Loop=1 2018-08-22T22:00:20.276Z,1534975220.276 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler] Running Loop=1 2018-08-22T22:00:20.364Z,1534975220.364 [Reporter](INFO): platform_buoyancy_position 954.460062 cc 2018-08-22T22:00:20.683Z,1534975220.683 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler] Stopped 2018-08-22T22:00:20.683Z,1534975220.683 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper:SampleCANONSampler 2018-08-22T22:00:20.683Z,1534975220.683 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:A] Stopped 2018-08-22T22:00:20.683Z,1534975220.683 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:B] Stopped 2018-08-22T22:00:20.683Z,1534975220.683 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler] Stopped 2018-08-22T22:00:20.684Z,1534975220.684 [sample:SampleAtDepth:SampleWrapper:SampleESP] Running Loop=1 2018-08-22T22:00:20.684Z,1534975220.684 [sample:SampleAtDepth:SampleWrapper:SampleESP](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper:SampleESP 2018-08-22T22:00:20.684Z,1534975220.684 [sample:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP] Running Loop=1 2018-08-22T22:00:20.728Z,1534975220.728 [Reporter](INFO): platform_buoyancy_position 954.325835 cc 2018-08-22T22:00:21.075Z,1534975221.075 [sample:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP](DEBUG): Initialize ReadDataComponent to sense ESPComponent.sampling 2018-08-22T22:00:21.123Z,1534975221.123 [Reporter](INFO): platform_buoyancy_position 952.311268 cc 2018-08-22T22:00:21.540Z,1534975221.540 [Reporter](INFO): platform_buoyancy_position 943.581806 cc 2018-08-22T22:00:21.851Z,1534975221.851 [ESPComponent](IMPORTANT): Setting regex for ESP Log summary: 'Selecting Cartridge|Sampled|Error|Fail|Retry|Cmd::|Sampler::' 2018-08-22T22:00:21.853Z,1534975221.853 [ESPComponent](INFO): compiled regex: "Selecting Cartridge|Sampled|Error|Fail|Retry|Cmd::|Sampler::" 2018-08-22T22:00:21.956Z,1534975221.956 [Reporter](INFO): platform_buoyancy_position 941.567239 cc 2018-08-22T22:00:22.252Z,1534975222.252 [ESPComponent](INFO): powering up ESP 2018-08-22T22:00:22.253Z,1534975222.253 [ESPComponent](INFO): manually powering up ESP 2018-08-22T22:00:22.255Z,1534975222.255 [ESPComponent](IMPORTANT): Powered ESP with command: ! echo 1 > /dev/loadA6 2018-08-22T22:00:22.256Z,1534975222.256 [ESPComponent](IMPORTANT): Starting PPPD with command:/sbin/pppd xonxoff asyncmap A0000 /dev/ttyTX1 linkname esp noauth local lock 115200 10.89.5.2:10.89.5.3 persist maxfail 0 holdoff 10 lcp-echo-interval 60 lcp-echo-failure 3 proxyarp ktune deflate 12 ms-dns 8.8.8.8 2018-08-22T22:00:22.314Z,1534975222.314 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadA6 2018-08-22T22:00:22.482Z,1534975222.482 [ESPComponent](IMPORTANT): Waiting for ESP to connect (timeout=150.0000) 2018-08-22T22:00:22.617Z,1534975222.617 [Reporter](INFO): platform_buoyancy_position 934.986572 cc 2018-08-22T22:00:22.745Z,1534975222.745 [ESPComponent](INFO): console: 2018-08-22T22:00:22.824Z,1534975222.824 [Reporter](INFO): platform_buoyancy_position 932.972063 cc 2018-08-22T22:00:23.150Z,1534975223.150 [Reporter](INFO): platform_buoyancy_position 928.540190 cc 2018-08-22T22:00:23.485Z,1534975223.485 [ESPComponent](INFO): console: 2018-08-22T22:00:23.589Z,1534975223.589 [Reporter](INFO): platform_buoyancy_position 924.242544 cc 2018-08-22T22:00:23.885Z,1534975223.885 [ESPComponent](INFO): console:NAND: 256 MiB 2018-08-22T22:00:23.972Z,1534975223.972 [Reporter](INFO): platform_buoyancy_position 917.930447 cc 2018-08-22T22:00:24.295Z,1534975224.295 [ESPComponent](INFO): console: BOOTMODE: SDMMC 2018-08-22T22:00:24.357Z,1534975224.357 [Reporter](INFO): platform_buoyancy_position 913.498516 cc 2018-08-22T22:00:24.702Z,1534975224.702 [ESPComponent](INFO): console: 2018-08-22T22:00:24.778Z,1534975224.778 [Reporter](INFO): platform_buoyancy_position 909.200928 cc 2018-08-22T22:00:25.077Z,1534975225.077 [ESPComponent](INFO): console: 2018-08-22T22:00:25.184Z,1534975225.184 [Reporter](INFO): platform_buoyancy_position 902.888831 cc 2018-08-22T22:00:25.478Z,1534975225.478 [ESPComponent](INFO): console: U-Boot 2009.11-mbariB (Dec 07 2017 - 19:07:59) 2018-08-22T22:00:25.584Z,1534975225.584 [Reporter](INFO): platform_buoyancy_position 898.456958 cc 2018-08-22T22:00:25.875Z,1534975225.875 [ESPComponent](INFO): console: 2018-08-22T22:00:25.968Z,1534975225.968 [Reporter](INFO): platform_buoyancy_position 892.144861 cc 2018-08-22T22:00:26.280Z,1534975226.280 [ESPComponent](INFO): console: MBARI LPC31xx ESP 3G 2018-08-22T22:00:26.396Z,1534975226.396 [Reporter](INFO): platform_buoyancy_position 887.712929 cc 2018-08-22T22:00:26.673Z,1534975226.673 [ESPComponent](INFO): console: flash params are already written into flash 2018-08-22T22:00:26.774Z,1534975226.774 [Reporter](INFO): platform_buoyancy_position 881.803746 cc 2018-08-22T22:00:27.072Z,1534975227.072 [ESPComponent](INFO): console: DRAM: 64 MB 2018-08-22T22:00:27.184Z,1534975227.184 [Reporter](INFO): platform_buoyancy_position 877.103244 cc 2018-08-22T22:00:27.474Z,1534975227.474 [ESPComponent](INFO): console: In: serial 2018-08-22T22:00:27.604Z,1534975227.604 [Reporter](INFO): platform_buoyancy_position 872.671313 cc 2018-08-22T22:00:27.894Z,1534975227.894 [ESPComponent](INFO): console: Out: serial 2018-08-22T22:00:27.968Z,1534975227.968 [Reporter](INFO): platform_buoyancy_position 867.433671 cc 2018-08-22T22:00:28.289Z,1534975228.289 [ESPComponent](INFO): console: Err: serial 2018-08-22T22:00:28.361Z,1534975228.361 [Reporter](INFO): platform_buoyancy_position 862.061628 cc 2018-08-22T22:00:28.679Z,1534975228.679 [ESPComponent](INFO): console: Net: ks8851_mll 2018-08-22T22:00:28.743Z,1534975228.743 [Reporter](INFO): platform_buoyancy_position 857.898325 cc 2018-08-22T22:00:29.090Z,1534975229.090 [ESPComponent](INFO): console: Hit to stop autoboot: 1  0 2018-08-22T22:00:29.188Z,1534975229.188 [Reporter](INFO): platform_buoyancy_position 851.183373 cc 2018-08-22T22:00:29.475Z,1534975229.475 [ESPComponent](INFO): console: mmc1 is available 2018-08-22T22:00:29.569Z,1534975229.569 [Reporter](INFO): platform_buoyancy_position 846.751442 cc 2018-08-22T22:00:29.880Z,1534975229.880 [ESPComponent](INFO): console: reading uImage 2018-08-22T22:00:29.977Z,1534975229.977 [Reporter](INFO): platform_buoyancy_position 840.573688 cc 2018-08-22T22:00:30.285Z,1534975230.285 [ESPComponent](INFO): console: 2018-08-22T22:00:30.377Z,1534975230.377 [Reporter](INFO): platform_buoyancy_position 836.141699 cc 2018-08-22T22:00:30.672Z,1534975230.672 [ESPComponent](INFO): console: bytes read 2018-08-22T22:00:30.768Z,1534975230.768 [Reporter](INFO): platform_buoyancy_position 829.829660 cc 2018-08-22T22:00:31.079Z,1534975231.079 [ESPComponent](INFO): console: ## Booting kernel from Legacy Image at 31000000 ... 2018-08-22T22:00:31.182Z,1534975231.182 [Reporter](INFO): platform_buoyancy_position 825.397787 cc 2018-08-22T22:00:31.478Z,1534975231.478 [ESPComponent](INFO): console: Image Name: Linux-2.6.33-ea3131-mbari6 2018-08-22T22:00:31.580Z,1534975231.580 [Reporter](INFO): platform_buoyancy_position 819.219975 cc 2018-08-22T22:00:31.880Z,1534975231.880 [ESPComponent](INFO): console: Image Type: ARM Linux Kernel Image (uncompressed) 2018-08-22T22:00:31.972Z,1534975231.972 [Reporter](INFO): platform_buoyancy_position 814.653758 cc 2018-08-22T22:00:32.283Z,1534975232.283 [ESPComponent](INFO): console: Data Size: 1681144 Bytes = 1.6 MB 2018-08-22T22:00:32.412Z,1534975232.412 [Reporter](INFO): platform_buoyancy_position 808.341603 cc 2018-08-22T22:00:32.684Z,1534975232.684 [ESPComponent](INFO): console: Load Address: 30008000 2018-08-22T22:00:32.784Z,1534975232.784 [Reporter](INFO): platform_buoyancy_position 804.044073 cc 2018-08-22T22:00:33.086Z,1534975233.086 [ESPComponent](INFO): console: Entry Point: 30008000 2018-08-22T22:00:33.172Z,1534975233.172 [Reporter](INFO): platform_buoyancy_position 799.209229 cc 2018-08-22T22:00:33.457Z,1534975233.457 [CommandLine](IMPORTANT): got command report clear 2018-08-22T22:00:33.502Z,1534975233.502 [ESPComponent](INFO): console: Verifying Checksum ... OK 2018-08-22T22:00:33.889Z,1534975233.889 [ESPComponent](INFO): console: Loading Kernel Image ... OK 2018-08-22T22:00:34.279Z,1534975234.279 [ESPComponent](INFO): console: OK 2018-08-22T22:00:34.671Z,1534975234.671 [ESPComponent](INFO): console: 2018-08-22T22:00:35.073Z,1534975235.073 [ESPComponent](INFO): console: Starting kernel ... 2018-08-22T22:00:35.472Z,1534975235.472 [ESPComponent](INFO): console: 2018-08-22T22:00:35.879Z,1534975235.879 [ESPComponent](INFO): console: Uncompressing Linux... done, booting the kernel. 2018-08-22T22:00:36.281Z,1534975236.281 [ESPComponent](INFO): console: [ 0.00] CPU: ARM926EJ-S [41069265] revision 5 (ARMv5TEJ), cr=00053177 2018-08-22T22:00:36.691Z,1534975236.691 [ESPComponent](INFO): console: [ 0.00] CPU: VIVT data cache, VIVT instruction cache 2018-08-22T22:00:40.316Z,1534975240.316 [ESPComponent](INFO): console: [ 0.00] Machine: NXP EA313X 2018-08-22T22:00:40.443Z,1534975240.443 [ESPComponent](INFO): console: [ 0.00] Memory policy: ECC disabled, Data cache writeback 2018-08-22T22:00:40.854Z,1534975240.854 [ESPComponent](INFO): console: [ 0.00] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 16256 2018-08-22T22:00:41.256Z,1534975241.256 [ESPComponent](INFO): console: [ 0.24] Mount-cache hash table entries: 512 2018-08-22T22:00:41.634Z,1534975241.634 [ESPComponent](INFO): console: [ 0.29] MBARI ESP 3G 2018-08-22T22:00:42.032Z,1534975242.032 [ESPComponent](INFO): console: [ 0.39] bio: create slab at 0 2018-08-22T22:00:42.429Z,1534975242.429 [ESPComponent](INFO): console: [ 0.46] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master... 2018-08-22T22:00:42.829Z,1534975242.829 [ESPComponent](INFO): console: [ 0.48] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master... 2018-08-22T22:00:43.236Z,1534975243.236 [ESPComponent](INFO): console: [ 0.50] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master... 2018-08-22T22:00:43.636Z,1534975243.636 [ESPComponent](INFO): console: [ 0.52] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master... 2018-08-22T22:00:44.037Z,1534975244.037 [ESPComponent](INFO): console: [ 0.54] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master... 2018-08-22T22:00:44.445Z,1534975244.445 [ESPComponent](INFO): console: [ 0.56] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master... 2018-08-22T22:00:44.829Z,1534975244.829 [ESPComponent](INFO): console: [ 0.56] NetWinder Floating Point Emulator V0.97 (double precision) 2018-08-22T22:00:45.251Z,1534975245.251 [ESPComponent](INFO): console: [ 0.58] yaffs Jul 6 2018 16:45:28 Installing. 2018-08-22T22:00:45.639Z,1534975245.639 [ESPComponent](INFO): console: [ 0.72] m25p80 spi0.3: m25p80 found s25sl032a flash 2018-08-22T22:00:46.035Z,1534975246.035 [ESPComponent](INFO): console: [ 2.33] VFS: Mounted root (ext2 filesystem) readonly on device 179:2. 2018-08-22T22:00:46.435Z,1534975246.435 [ESPComponent](INFO): console: 2018-08-22T22:00:46.828Z,1534975246.828 [ESPComponent](INFO): console:INIT: version 2.85 booting 2018-08-22T22:00:47.228Z,1534975247.228 [ESPComponent](INFO): console: 2018-08-22T22:00:47.632Z,1534975247.632 [ESPComponent](INFO): console:MBARI ESP Embedded Linux http://www.mbari.org mailto:brent@mbari.org 2018-08-22T22:00:48.039Z,1534975248.039 [ESPComponent](INFO): console: ESPhonu 2018-08-22T22:00:48.432Z,1534975248.432 [ESPComponent](INFO): console: 2018-08-22T22:00:48.828Z,1534975248.828 [ESPComponent](INFO): console:INIT: Entering runlevel: 3 2018-08-22T22:00:49.228Z,1534975249.228 [ESPComponent](INFO): console: 2018-08-22T22:00:49.653Z,1534975249.653 [ESPComponent](INFO): console:Loading kernel modules 2018-08-22T22:00:50.051Z,1534975250.051 [ESPComponent](INFO): console: Mounting filesystems and adding swapfiles listed in /etc/fstab 2018-08-22T22:00:50.435Z,1534975250.435 [ESPComponent](INFO): console: mount: /dev/mmcblk0p2 already mounted or /card busy 2018-08-22T22:00:50.836Z,1534975250.836 [ESPComponent](INFO): console: Starting hotplug events dispatcher udevd 2018-08-22T22:00:51.237Z,1534975251.237 [ESPComponent](INFO): console: Set system clock to: Wed Aug 22 17:59:55 EDT 2018 2018-08-22T22:00:51.639Z,1534975251.639 [ESPComponent](INFO): console: Starting syslogd klogd... 2018-08-22T22:00:52.041Z,1534975252.041 [ESPComponent](INFO): console: Bringing up interface lo ... 2018-08-22T22:00:52.428Z,1534975252.428 [ESPComponent](INFO): console: lo IP=127.0.0.1 2018-08-22T22:00:52.832Z,1534975252.832 [ESPComponent](INFO): console: Packet forwarding enabled 2018-08-22T22:00:53.233Z,1534975253.233 [ESPComponent](INFO): console: Bringing up interface eth0 ... 2018-08-22T22:00:53.632Z,1534975253.632 [ESPComponent](INFO): console: Determining IP configuration for eth0....udhcpc (v1.11.2) started 2018-08-22T22:00:54.042Z,1534975254.042 [ESPComponent](INFO): console: Sending discover... 2018-08-22T22:00:54.443Z,1534975254.443 [ESPComponent](INFO): console: No lease, forking to background 2018-08-22T22:00:54.847Z,1534975254.847 [ESPComponent](INFO): console: Bringing up interface eth0:10 ... 2018-08-22T22:00:55.245Z,1534975255.245 [ESPComponent](INFO): console: eth0:10 IP=10.10.10.10 2018-08-22T22:00:55.642Z,1534975255.642 [ESPComponent](INFO): console: Bringing up interface ppp2 ... 2018-08-22T22:00:56.035Z,1534975256.035 [ESPComponent](INFO): console: Starting portmap... 2018-08-22T22:00:56.428Z,1534975256.428 [ESPComponent](INFO): console: Network unavailable: Local time is Wed Aug 22 18:00:01 EDT 2018 2018-08-22T22:00:56.828Z,1534975256.828 [ESPComponent](INFO): console: Starting thttpd... 2018-08-22T22:00:57.227Z,1534975257.227 [ESPComponent](IMPORTANT): ESP has connected as client 2018-08-22T22:00:58.037Z,1534975258.037 [ESPComponent](IMPORTANT): [sample #1] ESP sampling sequence starting. Sampling state: S_WAITING_INITIAL_PROMPT 2018-08-22T22:00:58.037Z,1534975258.037 [ESPComponent](DEBUG): Writing samplingActive=1, sampleNumber=1 2018-08-22T22:00:58.083Z,1534975258.083 [sample:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP] Stopped 2018-08-22T22:00:58.084Z,1534975258.084 [sample:SampleAtDepth:SampleWrapper:SampleESP:B] Running Loop=1 2018-08-22T22:00:58.450Z,1534975258.450 [sample:SampleAtDepth:SampleWrapper:SampleESP:B](IMPORTANT): ESP sampling at 0.000000 m inwater with nan ug/l chlorophyll fluorescence. 2018-08-22T22:00:58.452Z,1534975258.452 [sample:SampleAtDepth:SampleWrapper:SampleESP:B] Stopped 2018-08-22T22:00:58.452Z,1534975258.452 [sample:SampleAtDepth:SampleWrapper:SampleESP:WaitForESP] Running Loop=1 2018-08-22T22:00:58.872Z,1534975258.872 [sample:SampleAtDepth:SampleWrapper:SampleESP:WaitForESP](DEBUG): Initialize ReadDataComponent to sense ESPComponent.sample_number 2018-08-22T22:00:59.254Z,1534975259.254 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PREPARING_SHOW_LOG 2018-08-22T22:00:59.650Z,1534975259.650 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PREPARING_SHOW_STATUS 2018-08-22T22:01:01.239Z,1534975261.239 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_LOADING_CARTRIDGE 2018-08-22T22:01:23.202Z,1534975283.202 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-08-22T22:01:42.516Z,1534975302.516 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_FILTERING 2018-08-22T22:01:44.921Z,1534975304.921 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_WAITING_FOR_PAUSED 2018-08-22T22:01:53.690Z,1534975313.690 [NAL9602](INFO): Powering down 2018-08-22T22:02:46.194Z,1534975366.194 [BPC1](ERROR): Failed to receive data from both battery packs 2018-08-22T22:02:46.194Z,1534975366.194 [BPC1] Communications Fault, FailCount= 9 2018-08-22T22:02:46.194Z,1534975366.194 [BPC1](ERROR): Communications Fault 2018-08-22T22:02:46.223Z,1534975366.223 [CBIT](ERROR): Communications Fault in component: BPC1 2018-08-22T22:02:47.426Z,1534975367.426 [CBIT](INFO): Clearing failed state for component BPC1 2018-08-22T22:02:47.426Z,1534975367.426 [BPC1] No Fault, FailCount= 9 2018-08-22T22:08:48.358Z,1534975728.358 [BPC1](ERROR): Failed to receive data from both battery packs 2018-08-22T22:08:48.358Z,1534975728.358 [BPC1] Communications Fault, FailCount= 10 2018-08-22T22:08:48.358Z,1534975728.358 [BPC1](ERROR): Communications Fault 2018-08-22T22:08:48.387Z,1534975728.387 [CBIT](ERROR): Communications Fault in component: BPC1 2018-08-22T22:08:48.388Z,1534975728.388 [CBIT](CRITICAL): Communications Fault in component: BPC1 2018-08-22T22:08:48.819Z,1534975728.819 [CommandLine](FAULT): Scheduling is paused 2018-08-22T22:08:48.819Z,1534975728.819 [CBIT](INFO): Critical error at 20180822T220848 2018-08-22T22:08:48.819Z,1534975728.819 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2018-08-22T22:08:49.184Z,1534975729.184 [MissionManager](INFO): MissionManager is completed. 2018-08-22T22:08:49.184Z,1534975729.184 [MissionManager](INFO): Uninitializing Mission sample 2018-08-22T22:08:49.184Z,1534975729.184 [sample] Stopped 2018-08-22T22:08:49.184Z,1534975729.184 [sample](DEBUG): Aggregate::uninitialize sample 2018-08-22T22:08:49.184Z,1534975729.184 [sample:A.Pitch] Stopped 2018-08-22T22:08:49.184Z,1534975729.184 [sample:SampleAtDepth] Stopped 2018-08-22T22:08:49.184Z,1534975729.184 [sample:SampleAtDepth](DEBUG): Aggregate::uninitialize sample:SampleAtDepth 2018-08-22T22:08:49.185Z,1534975729.185 [sample:SampleAtDepth:SetZeroRudderInDriftMode] Stopped 2018-08-22T22:08:49.185Z,1534975729.185 [sample:SampleAtDepth:SetZeroRudderInDriftMode](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SetZeroRudderInDriftMode 2018-08-22T22:08:49.185Z,1534975729.185 [sample:SampleAtDepth:SetZeroRudderInDriftMode:A.SetSpeed] Stopped 2018-08-22T22:08:49.185Z,1534975729.185 [sample:SampleAtDepth:SetZeroRudderInDriftMode:A.SetSpeed](DEBUG): Uninitialize. 2018-08-22T22:08:49.185Z,1534975729.185 [sample:SampleAtDepth:SetZeroRudderInDriftMode:B.Point] Stopped 2018-08-22T22:08:49.185Z,1534975729.185 [sample:SampleAtDepth:D.Pitch] Stopped 2018-08-22T22:08:49.185Z,1534975729.185 [sample:SampleAtDepth:SampleWrapper] Stopped 2018-08-22T22:08:49.185Z,1534975729.185 [sample:SampleAtDepth:SampleWrapper](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper 2018-08-22T22:08:49.185Z,1534975729.185 [sample:SampleAtDepth:SampleWrapper:SampleESP] Stopped 2018-08-22T22:08:49.185Z,1534975729.185 [sample:SampleAtDepth:SampleWrapper:SampleESP](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper:SampleESP 2018-08-22T22:08:49.186Z,1534975729.186 [sample:SampleAtDepth:SampleWrapper:SampleESP:WaitForESP] Stopped 2018-08-22T22:08:49.186Z,1534975729.186 [sample:SampleRepeater] Stopped 2018-08-22T22:08:49.186Z,1534975729.186 [sample:SampleRepeater](DEBUG): Aggregate::uninitialize sample:SampleRepeater 2018-08-22T22:08:49.186Z,1534975729.186 [sample:SampleRepeater:Sample] Stopped 2018-08-22T22:08:49.186Z,1534975729.186 [sample:SampleRepeater:Sample](DEBUG): Aggregate::uninitialize sample:SampleRepeater:Sample 2018-08-22T22:08:49.585Z,1534975729.585 [MissionManager](IMPORTANT): Started mission Default 2018-08-22T22:08:49.585Z,1534975729.585 [Default] Running Loop=1 2018-08-22T22:08:49.585Z,1534975729.585 [Default](DEBUG): Aggregate::initialize Default 2018-08-22T22:08:49.585Z,1534975729.585 [Default:B.GoToSurface] Running Loop=1 2018-08-22T22:08:49.585Z,1534975729.585 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2018-08-22T22:08:49.586Z,1534975729.586 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2018-08-22T22:08:49.586Z,1534975729.586 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2018-08-22T22:08:49.586Z,1534975729.586 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2018-08-22T22:08:49.587Z,1534975729.587 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2018-08-22T22:08:49.587Z,1534975729.587 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2018-08-22T22:08:49.588Z,1534975729.588 [Default:A.Wait] Running Loop=1 2018-08-22T22:08:49.588Z,1534975729.588 [Default:A.Wait](DEBUG): Initialize Wait Component. 2018-08-22T22:09:02.770Z,1534975742.770 [Default:A.Wait](INFO): Done Waiting. 2018-08-22T22:09:02.770Z,1534975742.770 [Default:A.Wait] Stopped 2018-08-22T22:09:02.770Z,1534975742.770 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2018-08-22T22:09:03.172Z,1534975743.172 [Default:CheckIn] Running Loop=1 2018-08-22T22:09:03.172Z,1534975743.172 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-08-22T22:09:03.172Z,1534975743.172 [Default:CheckIn:Read_GPS] Running Loop=1 2018-08-22T22:09:03.926Z,1534975743.926 [NAL9602](INFO): Powering up 2018-08-22T22:09:14.726Z,1534975754.726 [NAL9602](INFO): NAL9602 initialized 2018-08-22T22:09:15.526Z,1534975755.526 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-08-22T22:09:15.527Z,1534975755.527 [NAL9602] Data Fault, FailCount= 5 2018-08-22T22:09:15.527Z,1534975755.527 [NAL9602](ERROR): Data Fault 2018-08-22T22:09:15.639Z,1534975755.639 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-22T22:09:15.639Z,1534975755.639 [CBIT](CRITICAL): Data Fault in component: NAL9602 2018-08-22T22:09:15.926Z,1534975755.926 [NAL9602](INFO): Powering down 2018-08-22T22:09:16.025Z,1534975756.025 [CBIT](INFO): Critical error at 20180822T220915 2018-08-22T22:11:15.871Z,1534975875.871 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-22T22:11:15.871Z,1534975875.871 [NAL9602] No Fault, FailCount= 5 2018-08-22T22:11:16.206Z,1534975876.206 [NAL9602](INFO): Powering up NAL9602 2018-08-22T22:11:27.406Z,1534975887.406 [NAL9602](INFO): NAL9602 initialized 2018-08-22T22:13:48.531Z,1534976028.531 [CBIT](INFO): Clearing failed state for component BPC1 2018-08-22T22:13:48.532Z,1534976028.532 [BPC1] No Fault, FailCount= 10 2018-08-22T22:14:03.307Z,1534976043.307 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-22T22:09:03.2Z 2018-08-22T22:14:03.307Z,1534976043.307 [Default:CheckIn:Read_GPS] Stopped 2018-08-22T22:14:03.308Z,1534976043.308 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-08-22T22:14:09.365Z,1534976049.365 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180822T180436/Courier0075.lzma 2018-08-22T22:14:10.159Z,1534976050.159 [DataOverHttps](INFO): Moved sent file to Logs/20180822T180436/Courier0075.lzma.bak 2018-08-22T22:14:10.160Z,1534976050.160 [DataOverHttps](INFO): SBD MOMSN=8436487 2018-08-22T22:14:21.402Z,1534976061.402 [DataOverHttps](INFO): Sending 118 bytes from file Logs/20180822T215714/Courier0000.lzma 2018-08-22T22:14:23.130Z,1534976063.130 [DataOverHttps](INFO): Moved sent file to Logs/20180822T215714/Courier0000.lzma.bak 2018-08-22T22:14:23.130Z,1534976063.130 [DataOverHttps](INFO): SBD MOMSN=8436489 2018-08-22T22:14:36.142Z,1534976076.142 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180822T215714/Courier0003.lzma 2018-08-22T22:14:36.939Z,1534976076.939 [DataOverHttps](INFO): Moved sent file to Logs/20180822T215714/Courier0003.lzma.bak 2018-08-22T22:14:36.939Z,1534976076.939 [DataOverHttps](INFO): SBD MOMSN=8436494 2018-08-22T22:14:51.155Z,1534976091.155 [DataOverHttps](INFO): Sending 310 bytes from file Logs/20180822T180436/Express0076.lzma 2018-08-22T22:14:52.351Z,1534976092.351 [DataOverHttps](INFO): Moved sent file to Logs/20180822T180436/Express0076.lzma.bak 2018-08-22T22:14:52.352Z,1534976092.352 [DataOverHttps](INFO): SBD MOMSN=8436496 2018-08-22T22:15:06.025Z,1534976106.025 [DataOverHttps](INFO): Sending 1781 bytes from file Logs/20180822T215714/Express0001.lzma 2018-08-22T22:15:10.003Z,1534976110.003 [DataOverHttps](INFO): Moved sent file to Logs/20180822T215714/Express0001.lzma.bak 2018-08-22T22:15:10.003Z,1534976110.003 [DataOverHttps](INFO): SBD MOMSN=8436504 2018-08-22T22:15:22.390Z,1534976122.390 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20180822T215714/Express0004.lzma 2018-08-22T22:15:25.187Z,1534976125.187 [DataOverHttps](INFO): Moved sent file to Logs/20180822T215714/Express0004.lzma.bak 2018-08-22T22:15:25.187Z,1534976125.187 [DataOverHttps](INFO): SBD MOMSN=8436576 2018-08-22T22:15:26.931Z,1534976126.931 [Default:CheckIn:Read_Iridium] Stopped 2018-08-22T22:15:26.932Z,1534976126.932 [Default:CheckIn:C.Wait] Running Loop=1 2018-08-22T22:15:26.932Z,1534976126.932 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-08-22T22:16:31.240Z,1534976191.240 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-08-22T22:17:01.750Z,1534976221.750 [NAL9602](INFO): Powering down 2018-08-22T22:19:51.083Z,1534976391.083 [BPC1](ERROR): Failed to receive data from both battery packs 2018-08-22T22:19:51.083Z,1534976391.083 [BPC1] Communications Fault, FailCount= 1 2018-08-22T22:19:51.083Z,1534976391.083 [BPC1](ERROR): Communications Fault 2018-08-22T22:19:51.139Z,1534976391.139 [CBIT](ERROR): Communications Fault in component: BPC1 2018-08-22T22:19:52.341Z,1534976392.341 [CBIT](INFO): Clearing failed state for component BPC1 2018-08-22T22:19:52.341Z,1534976392.341 [BPC1] No Fault, FailCount= 1 2018-08-22T22:20:27.499Z,1534976427.499 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-08-22T22:20:27.500Z,1534976427.500 [Default:CheckIn:C.Wait] Stopped 2018-08-22T22:20:27.500Z,1534976427.500 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-08-22T22:20:27.500Z,1534976427.500 [Default:CheckIn:D] Running Loop=1 2018-08-22T22:20:27.908Z,1534976427.908 [Default:CheckIn:D] Stopped 2018-08-22T22:20:27.908Z,1534976427.908 [Default:CheckIn:E] Running Loop=1 2018-08-22T22:20:28.304Z,1534976428.304 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.638711 min 2018-08-22T22:20:28.305Z,1534976428.305 [Default:CheckIn:E] Stopped 2018-08-22T22:20:28.305Z,1534976428.305 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-08-22T22:20:28.305Z,1534976428.305 [Default:CheckIn] Stopped 2018-08-22T22:20:28.305Z,1534976428.305 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-08-22T22:20:28.305Z,1534976428.305 [Default:CheckIn](INFO): Running loop #2 2018-08-22T22:20:28.306Z,1534976428.306 [Default:CheckIn] Running Loop=2 2018-08-22T22:20:28.306Z,1534976428.306 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-08-22T22:20:28.306Z,1534976428.306 [Default:CheckIn:Read_GPS] Running Loop=1 2018-08-22T22:20:31.960Z,1534976431.960 [NAL9602](INFO): Powering up 2018-08-22T22:20:43.122Z,1534976443.122 [NAL9602](INFO): NAL9602 initialized 2018-08-22T22:21:15.118Z,1534976475.118 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2018-08-22T22:21:15.193Z,1534976475.193 [NAL9602](FAULT): received: +CSQ:0 OK407, 2, 0, 0, 0 OK 2018-08-22T22:21:15.193Z,1534976475.193 [NAL9602] Data Fault, FailCount= 1 2018-08-22T22:21:15.193Z,1534976475.193 [NAL9602](ERROR): Data Fault 2018-08-22T22:21:15.274Z,1534976475.274 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-22T22:21:15.522Z,1534976475.522 [NAL9602](INFO): Powering down 2018-08-22T22:21:16.395Z,1534976476.395 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-22T22:21:16.395Z,1534976476.395 [NAL9602] No Fault, FailCount= 1 2018-08-22T22:21:45.842Z,1534976505.842 [NAL9602](INFO): Powering up NAL9602 2018-08-22T22:21:57.046Z,1534976517.046 [NAL9602](INFO): NAL9602 initialized 2018-08-22T22:21:57.842Z,1534976517.842 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-08-22T22:21:57.843Z,1534976517.843 [NAL9602] Data Fault, FailCount= 2 2018-08-22T22:21:57.843Z,1534976517.843 [NAL9602](ERROR): Data Fault 2018-08-22T22:21:57.928Z,1534976517.928 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-22T22:21:58.246Z,1534976518.246 [NAL9602](INFO): Powering down 2018-08-22T22:21:59.099Z,1534976519.099 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-22T22:21:59.099Z,1534976519.099 [NAL9602] No Fault, FailCount= 2 2018-08-22T22:22:28.642Z,1534976548.642 [NAL9602](INFO): Powering up NAL9602 2018-08-22T22:22:39.506Z,1534976559.506 [NAL9602](INFO): NAL9602 initialized 2018-08-22T22:25:28.682Z,1534976728.682 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-22T22:20:28.3Z 2018-08-22T22:25:28.682Z,1534976728.682 [Default:CheckIn:Read_GPS] Stopped 2018-08-22T22:25:28.682Z,1534976728.682 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-08-22T22:25:36.833Z,1534976736.833 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180822T215714/Courier0006.lzma 2018-08-22T22:25:38.031Z,1534976738.031 [DataOverHttps](INFO): Moved sent file to Logs/20180822T215714/Courier0006.lzma.bak 2018-08-22T22:25:38.031Z,1534976738.031 [DataOverHttps](INFO): SBD MOMSN=8436578 2018-08-22T22:25:46.343Z,1534976746.342 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-08-22T22:25:50.406Z,1534976750.406 [DataOverHttps](INFO): Sending 283 bytes from file Logs/20180822T215714/Express0007.lzma 2018-08-22T22:25:51.203Z,1534976751.203 [DataOverHttps](INFO): Moved sent file to Logs/20180822T215714/Express0007.lzma.bak 2018-08-22T22:25:51.203Z,1534976751.203 [DataOverHttps](INFO): SBD MOMSN=8436580 2018-08-22T22:25:52.901Z,1534976752.901 [BPC1](ERROR): Failed to receive data from both battery packs 2018-08-22T22:25:52.902Z,1534976752.902 [BPC1] Communications Fault, FailCount= 2 2018-08-22T22:25:52.902Z,1534976752.902 [BPC1](ERROR): Communications Fault 2018-08-22T22:25:52.985Z,1534976752.985 [Default:CheckIn:Read_Iridium] Stopped 2018-08-22T22:25:52.985Z,1534976752.985 [Default:CheckIn:C.Wait] Running Loop=1 2018-08-22T22:25:52.985Z,1534976752.985 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-08-22T22:25:53.007Z,1534976753.007 [CBIT](ERROR): Communications Fault in component: BPC1 2018-08-22T22:25:56.804Z,1534976756.804 [CBIT](INFO): Clearing failed state for component BPC1 2018-08-22T22:25:56.804Z,1534976756.804 [BPC1] No Fault, FailCount= 2 2018-08-22T22:26:20.326Z,1534976780.326 [NAL9602](INFO): Powering down 2018-08-22T22:27:09.631Z,1534976829.631 [BPC1](ERROR): Failed to parse Bank A battery data 2018-08-22T22:30:53.462Z,1534977053.462 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-08-22T22:30:53.463Z,1534977053.463 [Default:CheckIn:C.Wait] Stopped 2018-08-22T22:30:53.463Z,1534977053.463 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-08-22T22:30:53.463Z,1534977053.463 [Default:CheckIn:D] Running Loop=1 2018-08-22T22:30:53.869Z,1534977053.869 [Default:CheckIn:D] Stopped 2018-08-22T22:30:53.869Z,1534977053.869 [Default:CheckIn:E] Running Loop=1 2018-08-22T22:30:57.457Z,1534977057.457 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 22.071401 min 2018-08-22T22:30:57.458Z,1534977057.458 [Default:CheckIn:E] Stopped 2018-08-22T22:30:57.458Z,1534977057.458 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-08-22T22:30:57.458Z,1534977057.458 [Default:CheckIn] Stopped 2018-08-22T22:30:57.458Z,1534977057.458 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-08-22T22:30:57.458Z,1534977057.458 [Default:CheckIn](INFO): Running loop #3 2018-08-22T22:30:57.458Z,1534977057.458 [Default:CheckIn] Running Loop=3 2018-08-22T22:30:57.459Z,1534977057.459 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-08-22T22:30:57.459Z,1534977057.459 [Default:CheckIn:Read_GPS] Running Loop=1 2018-08-22T22:30:57.890Z,1534977057.890 [NAL9602](INFO): Powering up 2018-08-22T22:31:09.082Z,1534977069.082 [NAL9602](INFO): NAL9602 initialized 2018-08-22T22:31:41.087Z,1534977101.087 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2018-08-22T22:31:41.169Z,1534977101.169 [NAL9602](FAULT): received: +CSQ:0 OK407, 2, 0, 0, 0 OK 2018-08-22T22:31:41.169Z,1534977101.169 [NAL9602] Data Fault, FailCount= 3 2018-08-22T22:31:41.169Z,1534977101.169 [NAL9602](ERROR): Data Fault 2018-08-22T22:31:41.280Z,1534977101.280 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-22T22:31:41.482Z,1534977101.482 [NAL9602](INFO): Powering down 2018-08-22T22:31:42.344Z,1534977102.344 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-22T22:31:42.344Z,1534977102.344 [NAL9602] No Fault, FailCount= 3 2018-08-22T22:32:11.862Z,1534977131.862 [NAL9602](INFO): Powering up NAL9602 2018-08-22T22:32:22.705Z,1534977142.705 [BPC1](ERROR): Failed to receive data from both battery packs 2018-08-22T22:32:22.706Z,1534977142.706 [BPC1] Communications Fault, FailCount= 3 2018-08-22T22:32:22.706Z,1534977142.706 [BPC1](ERROR): Communications Fault 2018-08-22T22:32:22.772Z,1534977142.772 [CBIT](ERROR): Communications Fault in component: BPC1 2018-08-22T22:32:23.062Z,1534977143.062 [NAL9602](INFO): NAL9602 initialized 2018-08-22T22:32:23.961Z,1534977143.961 [CBIT](INFO): Clearing failed state for component BPC1 2018-08-22T22:32:23.961Z,1534977143.961 [BPC1] No Fault, FailCount= 3 2018-08-22T22:32:31.566Z,1534977151.566 [CBIT](IMPORTANT): Beginning ground fault scan 2018-08-22T22:32:42.341Z,1534977162.341 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.122804 CHAN A1 (24V): -0.016316 CHAN A2 (12V): -0.004470 CHAN A3 (5V): -0.003376 CHAN B0 (3.3V): -0.000867 CHAN B1 (3.15aV): -0.001038 CHAN B2 (3.15bV): -0.000926 CHAN B3 (GND): 0.000255 OPEN: 0.005102 Full Scale Calc: 4.765 mA, -1.589 mA 2018-08-22T22:35:58.181Z,1534977358.181 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-22T22:30:57.5Z 2018-08-22T22:35:58.181Z,1534977358.181 [Default:CheckIn:Read_GPS] Stopped 2018-08-22T22:35:58.181Z,1534977358.181 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-08-22T22:35:59.146Z,1534977359.146 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180822T215714/Courier0009.lzma 2018-08-22T22:36:00.059Z,1534977360.059 [DataOverHttps](INFO): Moved sent file to Logs/20180822T215714/Courier0009.lzma.bak 2018-08-22T22:36:00.060Z,1534977360.060 [DataOverHttps](INFO): SBD MOMSN=8436586 2018-08-22T22:36:11.983Z,1534977371.983 [DataOverHttps](INFO): Sending 439 bytes from file Logs/20180822T215714/Express0010.lzma 2018-08-22T22:36:12.390Z,1534977372.390 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-08-22T22:36:13.179Z,1534977373.179 [DataOverHttps](INFO): Moved sent file to Logs/20180822T215714/Express0010.lzma.bak 2018-08-22T22:36:13.179Z,1534977373.179 [DataOverHttps](INFO): SBD MOMSN=8436588 2018-08-22T22:36:14.758Z,1534977374.758 [Default:CheckIn:Read_Iridium] Stopped 2018-08-22T22:36:14.759Z,1534977374.759 [Default:CheckIn:C.Wait] Running Loop=1 2018-08-22T22:36:14.759Z,1534977374.759 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-08-22T22:36:42.904Z,1534977402.904 [NAL9602](INFO): Powering down 2018-08-22T22:38:24.680Z,1534977504.680 [BPC1](ERROR): Failed to receive data from both battery packs 2018-08-22T22:38:24.680Z,1534977504.680 [BPC1] Communications Fault, FailCount= 4 2018-08-22T22:38:24.680Z,1534977504.680 [BPC1](ERROR): Communications Fault 2018-08-22T22:38:24.707Z,1534977504.707 [CBIT](ERROR): Communications Fault in component: BPC1 2018-08-22T22:38:25.908Z,1534977505.908 [CBIT](INFO): Clearing failed state for component BPC1 2018-08-22T22:38:25.908Z,1534977505.908 [BPC1] No Fault, FailCount= 4 2018-08-22T22:41:14.898Z,1534977674.898 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-08-22T22:41:14.898Z,1534977674.898 [Default:CheckIn:C.Wait] Stopped 2018-08-22T22:41:14.898Z,1534977674.898 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-08-22T22:41:14.899Z,1534977674.899 [Default:CheckIn:D] Running Loop=1 2018-08-22T22:41:15.300Z,1534977675.300 [Default:CheckIn:D] Stopped 2018-08-22T22:41:15.300Z,1534977675.300 [Default:CheckIn:E] Running Loop=1 2018-08-22T22:41:15.695Z,1534977675.695 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.428575 min 2018-08-22T22:41:15.695Z,1534977675.695 [Default:CheckIn:E] Stopped 2018-08-22T22:41:15.695Z,1534977675.695 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-08-22T22:41:15.695Z,1534977675.695 [Default:CheckIn] Stopped 2018-08-22T22:41:15.696Z,1534977675.696 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-08-22T22:41:15.696Z,1534977675.696 [Default:CheckIn](INFO): Running loop #4 2018-08-22T22:41:15.696Z,1534977675.696 [Default:CheckIn] Running Loop=4 2018-08-22T22:41:15.696Z,1534977675.696 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-08-22T22:41:15.696Z,1534977675.696 [Default:CheckIn:Read_GPS] Running Loop=1 2018-08-22T22:41:19.367Z,1534977679.367 [NAL9602](INFO): Powering up 2018-08-22T22:41:30.530Z,1534977690.530 [NAL9602](INFO): NAL9602 initialized 2018-08-22T22:41:31.330Z,1534977691.330 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-08-22T22:41:31.331Z,1534977691.331 [NAL9602] Data Fault, FailCount= 4 2018-08-22T22:41:31.331Z,1534977691.331 [NAL9602](ERROR): Data Fault 2018-08-22T22:41:31.432Z,1534977691.432 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-22T22:41:31.730Z,1534977691.730 [NAL9602](INFO): Powering down 2018-08-22T22:41:32.614Z,1534977692.614 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-22T22:41:32.614Z,1534977692.614 [NAL9602] No Fault, FailCount= 4 2018-08-22T22:42:02.127Z,1534977722.127 [NAL9602](INFO): Powering up NAL9602 2018-08-22T22:42:12.942Z,1534977732.942 [NAL9602](INFO): NAL9602 initialized 2018-08-22T22:43:27.166Z,1534977807.166 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PROCESSING 2018-08-22T22:43:29.563Z,1534977809.563 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_WAITING_FOR_PROCESSED 2018-08-22T22:44:26.634Z,1534977866.634 [BPC1](ERROR): Failed to receive data from both battery packs 2018-08-22T22:44:26.634Z,1534977866.634 [BPC1] Communications Fault, FailCount= 5 2018-08-22T22:44:26.634Z,1534977866.634 [BPC1](ERROR): Communications Fault 2018-08-22T22:44:26.708Z,1534977866.708 [CBIT](ERROR): Communications Fault in component: BPC1 2018-08-22T22:44:27.880Z,1534977867.880 [CBIT](INFO): Clearing failed state for component BPC1 2018-08-22T22:44:27.880Z,1534977867.880 [BPC1] No Fault, FailCount= 5 2018-08-22T22:46:15.988Z,1534977975.988 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-22T22:41:15.7Z 2018-08-22T22:46:15.988Z,1534977975.988 [Default:CheckIn:Read_GPS] Stopped 2018-08-22T22:46:15.989Z,1534977975.989 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-08-22T22:46:20.962Z,1534977980.962 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180822T215714/Courier0012.lzma 2018-08-22T22:46:21.759Z,1534977981.759 [DataOverHttps](INFO): Moved sent file to Logs/20180822T215714/Courier0012.lzma.bak 2018-08-22T22:46:21.759Z,1534977981.759 [DataOverHttps](INFO): SBD MOMSN=8436595 2018-08-22T22:46:33.678Z,1534977993.678 [DataOverHttps](INFO): Sending 281 bytes from file Logs/20180822T215714/Express0013.lzma 2018-08-22T22:46:34.475Z,1534977994.475 [DataOverHttps](INFO): Moved sent file to Logs/20180822T215714/Express0013.lzma.bak 2018-08-22T22:46:34.475Z,1534977994.475 [DataOverHttps](INFO): SBD MOMSN=8436597 2018-08-22T22:46:36.065Z,1534977996.065 [Default:CheckIn:Read_Iridium] Stopped 2018-08-22T22:46:36.065Z,1534977996.065 [Default:CheckIn:C.Wait] Running Loop=1 2018-08-22T22:46:36.065Z,1534977996.065 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-08-22T22:47:15.866Z,1534978035.866 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-08-22T22:47:46.350Z,1534978066.350 [NAL9602](INFO): Powering down 2018-08-22T22:50:28.403Z,1534978228.403 [BPC1](ERROR): Failed to receive data from both battery packs 2018-08-22T22:50:28.403Z,1534978228.403 [BPC1] Communications Fault, FailCount= 6 2018-08-22T22:50:28.403Z,1534978228.403 [BPC1](ERROR): Communications Fault 2018-08-22T22:50:28.430Z,1534978228.430 [CBIT](ERROR): Communications Fault in component: BPC1 2018-08-22T22:50:29.628Z,1534978229.628 [CBIT](INFO): Clearing failed state for component BPC1 2018-08-22T22:50:29.628Z,1534978229.628 [BPC1] No Fault, FailCount= 6 2018-08-22T22:51:36.548Z,1534978296.548 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-08-22T22:51:36.548Z,1534978296.548 [Default:CheckIn:C.Wait] Stopped 2018-08-22T22:51:36.548Z,1534978296.548 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-08-22T22:51:36.549Z,1534978296.549 [Default:CheckIn:D] Running Loop=1 2018-08-22T22:51:36.951Z,1534978296.951 [Default:CheckIn:D] Stopped 2018-08-22T22:51:36.951Z,1534978296.951 [Default:CheckIn:E] Running Loop=1 2018-08-22T22:51:37.333Z,1534978297.333 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.789429 min 2018-08-22T22:51:37.334Z,1534978297.334 [Default:CheckIn:E] Stopped 2018-08-22T22:51:37.334Z,1534978297.334 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-08-22T22:51:37.334Z,1534978297.334 [Default:CheckIn] Stopped 2018-08-22T22:51:37.334Z,1534978297.334 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-08-22T22:51:37.334Z,1534978297.334 [Default:CheckIn](INFO): Running loop #5 2018-08-22T22:51:37.334Z,1534978297.334 [Default:CheckIn] Running Loop=5 2018-08-22T22:51:37.335Z,1534978297.335 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-08-22T22:51:37.335Z,1534978297.335 [Default:CheckIn:Read_GPS] Running Loop=1 2018-08-22T22:51:38.066Z,1534978298.066 [NAL9602](INFO): Powering up 2018-08-22T22:51:48.990Z,1534978308.990 [NAL9602](INFO): NAL9602 initialized 2018-08-22T22:52:20.986Z,1534978340.986 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2018-08-22T22:52:21.065Z,1534978341.065 [NAL9602](FAULT): received: +CSQ:0 OK407, 2, 0, 0, 0 OK 2018-08-22T22:52:21.065Z,1534978341.065 [NAL9602] Data Fault, FailCount= 5 2018-08-22T22:52:21.065Z,1534978341.065 [NAL9602](ERROR): Data Fault 2018-08-22T22:52:21.157Z,1534978341.157 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-22T22:52:21.157Z,1534978341.157 [CBIT](CRITICAL): Data Fault in component: NAL9602 2018-08-22T22:52:21.397Z,1534978341.397 [NAL9602](INFO): Powering down 2018-08-22T22:52:21.498Z,1534978341.498 [CBIT](INFO): Critical error at 20180822T225221 2018-08-22T22:54:21.417Z,1534978461.417 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-22T22:54:21.417Z,1534978461.417 [NAL9602] No Fault, FailCount= 5 2018-08-22T22:54:21.758Z,1534978461.758 [NAL9602](INFO): Powering up NAL9602 2018-08-22T22:54:32.958Z,1534978472.958 [NAL9602](INFO): NAL9602 initialized 2018-08-22T22:54:33.758Z,1534978473.758 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-08-22T22:54:33.759Z,1534978473.759 [NAL9602] Data Fault, FailCount= 1 2018-08-22T22:54:33.759Z,1534978473.759 [NAL9602](ERROR): Data Fault 2018-08-22T22:54:33.855Z,1534978473.855 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-22T22:54:34.158Z,1534978474.158 [NAL9602](INFO): Powering down 2018-08-22T22:54:35.028Z,1534978475.028 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-22T22:54:35.028Z,1534978475.028 [NAL9602] No Fault, FailCount= 1 2018-08-22T22:54:55.445Z,1534978495.445 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_STOPPING 2018-08-22T22:55:04.214Z,1534978504.214 [NAL9602](INFO): Powering up NAL9602 2018-08-22T22:55:15.014Z,1534978515.014 [NAL9602](INFO): NAL9602 initialized 2018-08-22T22:55:21.844Z,1534978521.844 [ESPComponent](IMPORTANT): [sample #1] ESP sampling sequence completed normally. 2018-08-22T22:55:21.849Z,1534978521.849 [ESPComponent](DEBUG): Writing samplingActive=0, sampleNumber=1 2018-08-22T22:55:22.248Z,1534978522.248 [ESPComponent](IMPORTANT): [sample #1] ESP log summary report (2 messages): @18:00:29.25 Selecting Cartridge 58 @18:42:35.84 Sampled 1000.0ml 2018-08-22T22:55:22.249Z,1534978522.249 [ESPComponent](INFO): powering down ESP 2018-08-22T22:56:30.365Z,1534978590.365 [BPC1](ERROR): Failed to receive data from both battery packs 2018-08-22T22:56:30.372Z,1534978590.372 [BPC1] Communications Fault, FailCount= 7 2018-08-22T22:56:30.372Z,1534978590.372 [BPC1](ERROR): Communications Fault 2018-08-22T22:56:30.400Z,1534978590.400 [CBIT](ERROR): Communications Fault in component: BPC1 2018-08-22T22:56:31.603Z,1534978591.603 [CBIT](INFO): Clearing failed state for component BPC1 2018-08-22T22:56:31.603Z,1534978591.603 [BPC1] No Fault, FailCount= 7 2018-08-22T22:56:37.610Z,1534978597.610 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-22T22:51:37.3Z 2018-08-22T22:56:37.610Z,1534978597.610 [Default:CheckIn:Read_GPS] Stopped 2018-08-22T22:56:37.610Z,1534978597.610 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-08-22T22:56:42.583Z,1534978602.583 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20180822T215714/Courier0015.lzma 2018-08-22T22:56:43.379Z,1534978603.379 [DataOverHttps](INFO): Moved sent file to Logs/20180822T215714/Courier0015.lzma.bak 2018-08-22T22:56:43.379Z,1534978603.379 [DataOverHttps](INFO): SBD MOMSN=8436604 2018-08-22T22:56:55.695Z,1534978615.695 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-08-22T22:56:56.197Z,1534978616.197 [DataOverHttps](INFO): Sending 427 bytes from file Logs/20180822T215714/Express0016.lzma 2018-08-22T22:56:56.991Z,1534978616.991 [DataOverHttps](INFO): Moved sent file to Logs/20180822T215714/Express0016.lzma.bak 2018-08-22T22:56:56.992Z,1534978616.992 [DataOverHttps](INFO): SBD MOMSN=8436607 2018-08-22T22:56:58.575Z,1534978618.575 [Default:CheckIn:Read_Iridium] Stopped 2018-08-22T22:56:58.575Z,1534978618.575 [Default:CheckIn:C.Wait] Running Loop=1 2018-08-22T22:56:58.575Z,1534978618.575 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-08-22T22:57:25.948Z,1534978645.948 [NAL9602](INFO): Powering down 2018-08-22T23:01:59.014Z,1534978919.014 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-08-22T23:01:59.014Z,1534978919.014 [Default:CheckIn:C.Wait] Stopped 2018-08-22T23:01:59.014Z,1534978919.014 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-08-22T23:01:59.015Z,1534978919.015 [Default:CheckIn:D] Running Loop=1 2018-08-22T23:01:59.419Z,1534978919.419 [Default:CheckIn:D] Stopped 2018-08-22T23:01:59.420Z,1534978919.420 [Default:CheckIn:E] Running Loop=1 2018-08-22T23:01:59.821Z,1534978919.821 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 53.163904 min 2018-08-22T23:01:59.821Z,1534978919.821 [Default:CheckIn:E] Stopped 2018-08-22T23:01:59.821Z,1534978919.821 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-08-22T23:01:59.822Z,1534978919.822 [Default:CheckIn] Stopped 2018-08-22T23:01:59.822Z,1534978919.822 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-08-22T23:01:59.822Z,1534978919.822 [Default:CheckIn](INFO): Running loop #6 2018-08-22T23:01:59.822Z,1534978919.822 [Default:CheckIn] Running Loop=6 2018-08-22T23:01:59.822Z,1534978919.822 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-08-22T23:01:59.822Z,1534978919.822 [Default:CheckIn:Read_GPS] Running Loop=1 2018-08-22T23:02:00.570Z,1534978920.570 [NAL9602](INFO): Powering up 2018-08-22T23:02:11.446Z,1534978931.446 [NAL9602](INFO): NAL9602 initialized 2018-08-22T23:02:32.681Z,1534978952.681 [BPC1](ERROR): Failed to receive data from both battery packs 2018-08-22T23:02:32.681Z,1534978952.681 [BPC1] Communications Fault, FailCount= 8 2018-08-22T23:02:32.681Z,1534978952.681 [BPC1](ERROR): Communications Fault 2018-08-22T23:02:32.745Z,1534978952.745 [CBIT](ERROR): Communications Fault in component: BPC1 2018-08-22T23:02:33.903Z,1534978953.903 [CBIT](INFO): Clearing failed state for component BPC1 2018-08-22T23:02:33.903Z,1534978953.903 [BPC1] No Fault, FailCount= 8 2018-08-22T23:02:43.446Z,1534978963.446 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2018-08-22T23:02:43.525Z,1534978963.525 [NAL9602](FAULT): received: +CSQ:0 OK407, 2, 0, 0, 0 OK 2018-08-22T23:02:43.525Z,1534978963.525 [NAL9602] Data Fault, FailCount= 2 2018-08-22T23:02:43.525Z,1534978963.525 [NAL9602](ERROR): Data Fault 2018-08-22T23:02:43.617Z,1534978963.617 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-22T23:02:43.846Z,1534978963.846 [NAL9602](INFO): Powering down 2018-08-22T23:02:44.718Z,1534978964.718 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-22T23:02:44.718Z,1534978964.718 [NAL9602] No Fault, FailCount= 2 2018-08-22T23:03:13.906Z,1534978993.906 [NAL9602](INFO): Powering up NAL9602 2018-08-22T23:03:25.106Z,1534979005.106 [NAL9602](INFO): NAL9602 initialized 2018-08-22T23:07:03.352Z,1534979223.352 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-22T23:01:59.8Z 2018-08-22T23:07:03.352Z,1534979223.352 [Default:CheckIn:Read_GPS] Stopped 2018-08-22T23:07:03.352Z,1534979223.352 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-08-22T23:07:04.328Z,1534979224.328 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180822T215714/Courier0018.lzma 2018-08-22T23:07:05.219Z,1534979225.219 [DataOverHttps](INFO): Moved sent file to Logs/20180822T215714/Courier0018.lzma.bak 2018-08-22T23:07:05.219Z,1534979225.219 [DataOverHttps](INFO): SBD MOMSN=8436616 2018-08-22T23:07:16.586Z,1534979236.586 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-08-22T23:07:17.074Z,1534979237.074 [DataOverHttps](INFO): Sending 237 bytes from file Logs/20180822T215714/Express0019.lzma 2018-08-22T23:07:18.271Z,1534979238.271 [DataOverHttps](INFO): Moved sent file to Logs/20180822T215714/Express0019.lzma.bak 2018-08-22T23:07:18.272Z,1534979238.272 [DataOverHttps](INFO): SBD MOMSN=8436618 2018-08-22T23:07:19.778Z,1534979239.778 [Default:CheckIn:Read_Iridium] Stopped 2018-08-22T23:07:19.778Z,1534979239.778 [Default:CheckIn:C.Wait] Running Loop=1 2018-08-22T23:07:19.779Z,1534979239.779 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-08-22T23:07:46.758Z,1534979266.758 [NAL9602](INFO): Powering down 2018-08-22T23:08:34.445Z,1534979314.445 [BPC1](ERROR): Failed to receive data from both battery packs 2018-08-22T23:08:34.445Z,1534979314.445 [BPC1] Communications Fault, FailCount= 9 2018-08-22T23:08:34.445Z,1534979314.445 [BPC1](ERROR): Communications Fault 2018-08-22T23:08:34.515Z,1534979314.515 [CBIT](ERROR): Communications Fault in component: BPC1 2018-08-22T23:08:35.676Z,1534979315.676 [CBIT](INFO): Clearing failed state for component BPC1 2018-08-22T23:08:35.676Z,1534979315.676 [BPC1] No Fault, FailCount= 9 2018-08-22T23:12:20.300Z,1534979540.300 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-08-22T23:12:20.300Z,1534979540.300 [Default:CheckIn:C.Wait] Stopped 2018-08-22T23:12:20.300Z,1534979540.300 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-08-22T23:12:20.300Z,1534979540.300 [Default:CheckIn:D] Running Loop=1 2018-08-22T23:12:20.675Z,1534979540.675 [Default:CheckIn:D] Stopped 2018-08-22T23:12:20.675Z,1534979540.675 [Default:CheckIn:E] Running Loop=1 2018-08-22T23:12:21.085Z,1534979541.085 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 63.518168 min 2018-08-22T23:12:21.086Z,1534979541.086 [Default:CheckIn:E] Stopped 2018-08-22T23:12:21.086Z,1534979541.086 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-08-22T23:12:21.086Z,1534979541.086 [Default:CheckIn] Stopped 2018-08-22T23:12:21.086Z,1534979541.086 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-08-22T23:12:21.086Z,1534979541.086 [Default:CheckIn](INFO): Running loop #7 2018-08-22T23:12:21.086Z,1534979541.086 [Default:CheckIn] Running Loop=7 2018-08-22T23:12:21.086Z,1534979541.086 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-08-22T23:12:21.087Z,1534979541.087 [Default:CheckIn:Read_GPS] Running Loop=1 2018-08-22T23:12:24.723Z,1534979544.723 [NAL9602](INFO): Powering up 2018-08-22T23:12:35.894Z,1534979555.894 [NAL9602](INFO): NAL9602 initialized 2018-08-22T23:12:36.694Z,1534979556.694 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-08-22T23:12:36.695Z,1534979556.695 [NAL9602] Data Fault, FailCount= 3 2018-08-22T23:12:36.695Z,1534979556.695 [NAL9602](ERROR): Data Fault 2018-08-22T23:12:36.817Z,1534979556.817 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-22T23:12:37.094Z,1534979557.094 [NAL9602](INFO): Powering down 2018-08-22T23:12:37.963Z,1534979557.963 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-22T23:12:37.963Z,1534979557.963 [NAL9602] No Fault, FailCount= 3 2018-08-22T23:13:07.499Z,1534979587.499 [NAL9602](INFO): Powering up NAL9602 2018-08-22T23:13:18.694Z,1534979598.694 [NAL9602](INFO): NAL9602 initialized 2018-08-22T23:14:36.149Z,1534979676.149 [BPC1](ERROR): Failed to receive data from both battery packs 2018-08-22T23:14:36.149Z,1534979676.149 [BPC1] Communications Fault, FailCount= 10 2018-08-22T23:14:36.149Z,1534979676.149 [BPC1](ERROR): Communications Fault 2018-08-22T23:14:36.175Z,1534979676.175 [CBIT](ERROR): Communications Fault in component: BPC1 2018-08-22T23:14:36.176Z,1534979676.176 [CBIT](CRITICAL): Communications Fault in component: BPC1 2018-08-22T23:14:36.570Z,1534979676.570 [CBIT](INFO): Critical error at 20180822T231436 2018-08-22T23:17:21.175Z,1534979841.175 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-22T23:12:21.1Z 2018-08-22T23:17:21.175Z,1534979841.175 [Default:CheckIn:Read_GPS] Stopped 2018-08-22T23:17:21.176Z,1534979841.176 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-08-22T23:17:25.526Z,1534979845.526 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20180822T215714/Courier0021.lzma 2018-08-22T23:17:26.443Z,1534979846.443 [DataOverHttps](INFO): Moved sent file to Logs/20180822T215714/Courier0021.lzma.bak 2018-08-22T23:17:26.443Z,1534979846.443 [DataOverHttps](INFO): SBD MOMSN=8436623 2018-08-22T23:17:39.898Z,1534979859.898 [DataOverHttps](INFO): Sending 214 bytes from file Logs/20180822T215714/Express0022.lzma 2018-08-22T23:17:40.695Z,1534979860.695 [DataOverHttps](INFO): Moved sent file to Logs/20180822T215714/Express0022.lzma.bak 2018-08-22T23:17:40.696Z,1534979860.696 [DataOverHttps](INFO): SBD MOMSN=8436626 2018-08-22T23:17:42.364Z,1534979862.364 [Default:CheckIn:Read_Iridium] Stopped 2018-08-22T23:17:42.364Z,1534979862.364 [Default:CheckIn:C.Wait] Running Loop=1 2018-08-22T23:17:42.364Z,1534979862.364 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-08-22T23:18:24.494Z,1534979904.494 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-08-22T23:18:54.958Z,1534979934.958 [NAL9602](INFO): Powering down 2018-08-22T23:19:36.240Z,1534979976.240 [CBIT](INFO): Clearing failed state for component BPC1 2018-08-22T23:19:36.257Z,1534979976.257 [BPC1] No Fault, FailCount= 10 2018-08-22T23:22:42.903Z,1534980162.903 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-08-22T23:22:42.904Z,1534980162.904 [Default:CheckIn:C.Wait] Stopped 2018-08-22T23:22:42.904Z,1534980162.904 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-08-22T23:22:42.904Z,1534980162.904 [Default:CheckIn:D] Running Loop=1 2018-08-22T23:22:43.311Z,1534980163.311 [Default:CheckIn:D] Stopped 2018-08-22T23:22:43.311Z,1534980163.311 [Default:CheckIn:E] Running Loop=1 2018-08-22T23:22:43.710Z,1534980163.710 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 73.895426 min 2018-08-22T23:22:43.710Z,1534980163.710 [Default:CheckIn:E] Stopped 2018-08-22T23:22:43.710Z,1534980163.710 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-08-22T23:22:43.710Z,1534980163.710 [Default:CheckIn] Stopped 2018-08-22T23:22:43.710Z,1534980163.710 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-08-22T23:22:43.711Z,1534980163.711 [Default:CheckIn](INFO): Running loop #8 2018-08-22T23:22:43.711Z,1534980163.711 [Default:CheckIn] Running Loop=8 2018-08-22T23:22:43.711Z,1534980163.711 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-08-22T23:22:43.711Z,1534980163.711 [Default:CheckIn:Read_GPS] Running Loop=1 2018-08-22T23:22:44.458Z,1534980164.458 [NAL9602](INFO): Powering up 2018-08-22T23:22:55.318Z,1534980175.318 [NAL9602](INFO): NAL9602 initialized 2018-08-22T23:23:27.318Z,1534980207.318 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2018-08-22T23:23:27.397Z,1534980207.397 [NAL9602](FAULT): received: +CSQ:0 OK407, 2, 0, 0, 0 OK 2018-08-22T23:23:27.397Z,1534980207.397 [NAL9602] Data Fault, FailCount= 4 2018-08-22T23:23:27.397Z,1534980207.397 [NAL9602](ERROR): Data Fault 2018-08-22T23:23:27.487Z,1534980207.487 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-22T23:23:27.718Z,1534980207.718 [NAL9602](INFO): Powering down 2018-08-22T23:23:28.578Z,1534980208.578 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-22T23:23:28.578Z,1534980208.578 [NAL9602] No Fault, FailCount= 4 2018-08-22T23:23:58.009Z,1534980238.009 [NAL9602](INFO): Powering up NAL9602 2018-08-22T23:24:09.210Z,1534980249.210 [NAL9602](INFO): NAL9602 initialized 2018-08-22T23:24:10.006Z,1534980250.006 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-08-22T23:24:10.007Z,1534980250.007 [NAL9602] Data Fault, FailCount= 5 2018-08-22T23:24:10.007Z,1534980250.007 [NAL9602](ERROR): Data Fault 2018-08-22T23:24:10.101Z,1534980250.101 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-22T23:24:10.102Z,1534980250.102 [CBIT](CRITICAL): Data Fault in component: NAL9602 2018-08-22T23:24:10.406Z,1534980250.406 [NAL9602](INFO): Powering down 2018-08-22T23:24:10.499Z,1534980250.499 [CBIT](INFO): Critical error at 20180822T232410 2018-08-22T23:25:36.894Z,1534980336.894 [BPC1](ERROR): Failed to receive data from both battery packs 2018-08-22T23:25:36.894Z,1534980336.894 [BPC1] Communications Fault, FailCount= 1 2018-08-22T23:25:36.895Z,1534980336.895 [BPC1](ERROR): Communications Fault 2018-08-22T23:25:36.959Z,1534980336.959 [CBIT](ERROR): Communications Fault in component: BPC1 2018-08-22T23:25:38.198Z,1534980338.198 [CBIT](INFO): Clearing failed state for component BPC1 2018-08-22T23:25:38.198Z,1534980338.198 [BPC1] No Fault, FailCount= 1 2018-08-22T23:26:10.194Z,1534980370.194 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-22T23:26:10.194Z,1534980370.194 [NAL9602] No Fault, FailCount= 5 2018-08-22T23:26:10.538Z,1534980370.538 [NAL9602](INFO): Powering up NAL9602 2018-08-22T23:26:21.742Z,1534980381.742 [NAL9602](INFO): NAL9602 initialized 2018-08-22T23:27:43.876Z,1534980463.876 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-22T23:22:43.7Z 2018-08-22T23:27:43.876Z,1534980463.876 [Default:CheckIn:Read_GPS] Stopped 2018-08-22T23:27:43.877Z,1534980463.877 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-08-22T23:27:48.850Z,1534980468.850 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20180822T215714/Courier0024.lzma 2018-08-22T23:27:49.647Z,1534980469.647 [DataOverHttps](INFO): Moved sent file to Logs/20180822T215714/Courier0024.lzma.bak 2018-08-22T23:27:49.647Z,1534980469.647 [DataOverHttps](INFO): SBD MOMSN=8436631 2018-08-22T23:28:01.014Z,1534980481.014 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-08-22T23:28:01.522Z,1534980481.522 [DataOverHttps](INFO): Sending 253 bytes from file Logs/20180822T215714/Express0025.lzma 2018-08-22T23:28:02.319Z,1534980482.319 [DataOverHttps](INFO): Moved sent file to Logs/20180822T215714/Express0025.lzma.bak 2018-08-22T23:28:02.319Z,1534980482.319 [DataOverHttps](INFO): SBD MOMSN=8436634 2018-08-22T23:28:03.827Z,1534980483.827 [Default:CheckIn:Read_Iridium] Stopped 2018-08-22T23:28:03.827Z,1534980483.827 [Default:CheckIn:C.Wait] Running Loop=1 2018-08-22T23:28:03.828Z,1534980483.828 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-08-22T23:28:31.210Z,1534980511.210 [NAL9602](INFO): Powering down 2018-08-22T23:32:47.218Z,1534980767.218 [CommandLine](IMPORTANT): got command get BPC1.loadAtStartup 2018-08-22T23:32:47.218Z,1534980767.218 [CommandLine](IMPORTANT): BPC1.loadAtStartup 1 bool 2018-08-22T23:32:56.039Z,1534980776.039 [BPC1](ERROR): Failed to receive data from both battery packs 2018-08-22T23:32:56.039Z,1534980776.039 [BPC1] Communications Fault, FailCount= 2 2018-08-22T23:32:56.040Z,1534980776.040 [BPC1](ERROR): Communications Fault 2018-08-22T23:32:56.135Z,1534980776.135 [CBIT](ERROR): Communications Fault in component: BPC1 2018-08-22T23:32:57.291Z,1534980777.291 [CBIT](INFO): Clearing failed state for component BPC1 2018-08-22T23:32:57.291Z,1534980777.291 [BPC1] No Fault, FailCount= 2 2018-08-22T23:33:04.073Z,1534980784.073 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-08-22T23:33:04.073Z,1534980784.073 [Default:CheckIn:C.Wait] Stopped 2018-08-22T23:33:04.073Z,1534980784.073 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-08-22T23:33:04.073Z,1534980784.073 [Default:CheckIn:D] Running Loop=1 2018-08-22T23:33:04.489Z,1534980784.489 [Default:CheckIn:D] Stopped 2018-08-22T23:33:04.489Z,1534980784.489 [Default:CheckIn:E] Running Loop=1 2018-08-22T23:33:04.859Z,1534980784.859 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 84.248397 min 2018-08-22T23:33:04.859Z,1534980784.859 [Default:CheckIn:E] Stopped 2018-08-22T23:33:04.859Z,1534980784.859 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-08-22T23:33:04.859Z,1534980784.859 [Default:CheckIn] Stopped 2018-08-22T23:33:04.860Z,1534980784.860 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-08-22T23:33:04.860Z,1534980784.860 [Default:CheckIn](INFO): Running loop #9 2018-08-22T23:33:04.860Z,1534980784.860 [Default:CheckIn] Running Loop=9 2018-08-22T23:33:04.860Z,1534980784.860 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-08-22T23:33:04.860Z,1534980784.860 [Default:CheckIn:Read_GPS] Running Loop=1 2018-08-22T23:33:08.558Z,1534980788.558 [NAL9602](INFO): Powering up 2018-08-22T23:33:11.024Z,1534980791.024 [CommandLine](IMPORTANT): got command configSet BPC1.loadAtStartup 0.000000 bool persist 2018-08-22T23:33:11.024Z,1534980791.024 [CommandLine](IMPORTANT): configSet BPC1.loadAtStartup requires a restart to take effect. 2018-08-22T23:33:19.734Z,1534980799.734 [NAL9602](INFO): NAL9602 initialized 2018-08-22T23:33:51.734Z,1534980831.734 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2018-08-22T23:33:51.809Z,1534980831.809 [NAL9602](FAULT): received: +CSQ:0 OK407, 2, 0, 0, 0 OK 2018-08-22T23:33:51.809Z,1534980831.809 [NAL9602] Data Fault, FailCount= 1 2018-08-22T23:33:51.809Z,1534980831.809 [NAL9602](ERROR): Data Fault 2018-08-22T23:33:51.894Z,1534980831.894 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-22T23:33:52.134Z,1534980832.134 [NAL9602](INFO): Powering down 2018-08-22T23:33:53.006Z,1534980833.006 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-22T23:33:53.006Z,1534980833.006 [NAL9602] No Fault, FailCount= 1 2018-08-22T23:34:22.209Z,1534980862.209 [NAL9602](INFO): Powering up NAL9602 2018-08-22T23:34:33.394Z,1534980873.394 [NAL9602](INFO): NAL9602 initialized 2018-08-22T23:38:05.138Z,1534981085.138 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-22T23:33:04.9Z 2018-08-22T23:38:05.138Z,1534981085.138 [Default:CheckIn:Read_GPS] Stopped 2018-08-22T23:38:05.138Z,1534981085.138 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-08-22T23:38:11.785Z,1534981091.785 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180822T215714/Courier0027.lzma 2018-08-22T23:38:12.583Z,1534981092.583 [DataOverHttps](INFO): Moved sent file to Logs/20180822T215714/Courier0027.lzma.bak 2018-08-22T23:38:12.583Z,1534981092.583 [DataOverHttps](INFO): SBD MOMSN=8436640 2018-08-22T23:38:24.335Z,1534981104.335 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-08-22T23:38:24.837Z,1534981104.837 [DataOverHttps](INFO): Sending 346 bytes from file Logs/20180822T215714/Express0028.lzma 2018-08-22T23:38:26.031Z,1534981106.031 [DataOverHttps](INFO): Moved sent file to Logs/20180822T215714/Express0028.lzma.bak 2018-08-22T23:38:26.032Z,1534981106.032 [DataOverHttps](INFO): SBD MOMSN=8436642 2018-08-22T23:38:27.770Z,1534981107.770 [Default:CheckIn:Read_Iridium] Stopped 2018-08-22T23:38:27.770Z,1534981107.770 [Default:CheckIn:C.Wait] Running Loop=1 2018-08-22T23:38:27.770Z,1534981107.770 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-08-22T23:38:54.462Z,1534981134.462 [NAL9602](INFO): Powering down 2018-08-22T23:38:58.092Z,1534981138.092 [BPC1](ERROR): Failed to receive data from both battery packs 2018-08-22T23:38:58.093Z,1534981138.093 [BPC1] Communications Fault, FailCount= 3 2018-08-22T23:38:58.093Z,1534981138.093 [BPC1](ERROR): Communications Fault 2018-08-22T23:38:58.132Z,1534981138.132 [CBIT](ERROR): Communications Fault in component: BPC1 2018-08-22T23:38:59.348Z,1534981139.348 [CBIT](INFO): Clearing failed state for component BPC1 2018-08-22T23:38:59.348Z,1534981139.348 [BPC1] No Fault, FailCount= 3 2018-08-22T23:40:35.862Z,1534981235.862 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.394975 seconds old. 2018-08-22T23:40:36.261Z,1534981236.261 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.793599 seconds old. 2018-08-22T23:40:36.662Z,1534981236.662 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.195040 seconds old. 2018-08-22T23:40:37.068Z,1534981237.068 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.600909 seconds old. 2018-08-22T23:42:01.500Z,1534981321.500 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:01.903Z,1534981321.903 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:02.300Z,1534981322.300 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:02.705Z,1534981322.705 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:03.118Z,1534981323.118 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:03.624Z,1534981323.624 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:03.917Z,1534981323.917 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:04.299Z,1534981324.299 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:04.699Z,1534981324.699 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:05.099Z,1534981325.099 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:05.521Z,1534981325.521 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:05.900Z,1534981325.900 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:06.299Z,1534981326.299 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:06.722Z,1534981326.722 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:07.105Z,1534981327.105 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:07.505Z,1534981327.505 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:07.920Z,1534981327.920 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:08.299Z,1534981328.299 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:08.698Z,1534981328.698 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:09.102Z,1534981329.102 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:09.503Z,1534981329.503 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:09.912Z,1534981329.912 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:10.311Z,1534981330.311 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:10.732Z,1534981330.732 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:11.110Z,1534981331.110 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:11.506Z,1534981331.506 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:11.907Z,1534981331.907 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:12.306Z,1534981332.306 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:12.715Z,1534981332.715 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:13.127Z,1534981333.127 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:13.499Z,1534981333.499 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:13.899Z,1534981333.899 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:14.303Z,1534981334.303 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:14.701Z,1534981334.701 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:15.102Z,1534981335.102 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:15.504Z,1534981335.504 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:15.904Z,1534981335.904 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:16.311Z,1534981336.311 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:16.705Z,1534981336.705 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:17.104Z,1534981337.104 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:17.505Z,1534981337.505 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:17.906Z,1534981337.906 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:18.309Z,1534981338.309 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:18.707Z,1534981338.707 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:19.116Z,1534981339.116 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:19.577Z,1534981339.577 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:19.899Z,1534981339.899 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:20.299Z,1534981340.299 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:20.699Z,1534981340.699 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:21.103Z,1534981341.103 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:21.503Z,1534981341.503 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:21.940Z,1534981341.940 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:22.323Z,1534981342.323 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:22.699Z,1534981342.699 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:23.098Z,1534981343.098 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:23.502Z,1534981343.502 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:23.916Z,1534981343.916 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:24.302Z,1534981344.302 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:24.702Z,1534981344.702 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:25.103Z,1534981345.103 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:25.509Z,1534981345.509 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:25.908Z,1534981345.908 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:26.375Z,1534981346.375 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:26.698Z,1534981346.698 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:27.099Z,1534981347.099 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:27.499Z,1534981347.499 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:27.898Z,1534981347.898 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:28.299Z,1534981348.299 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:28.805Z,1534981348.805 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:32.695Z,1534981352.695 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:32.831Z,1534981352.831 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:33.210Z,1534981353.210 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:33.575Z,1534981353.575 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:33.982Z,1534981353.982 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:34.381Z,1534981354.381 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:34.796Z,1534981354.796 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:35.192Z,1534981355.192 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:35.574Z,1534981355.574 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:35.975Z,1534981355.975 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:36.375Z,1534981356.375 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:36.775Z,1534981356.775 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:37.251Z,1534981357.251 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:37.582Z,1534981357.582 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:38.002Z,1534981358.002 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:38.375Z,1534981358.375 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:38.778Z,1534981358.778 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:39.178Z,1534981359.178 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:39.595Z,1534981359.595 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:39.980Z,1534981359.980 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:40.381Z,1534981360.381 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:40.791Z,1534981360.791 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:41.192Z,1534981361.192 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:41.585Z,1534981361.585 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:41.997Z,1534981361.997 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:42.382Z,1534981362.382 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:42.775Z,1534981362.775 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:43.175Z,1534981363.175 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:43.575Z,1534981363.575 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:44.014Z,1534981364.014 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:44.386Z,1534981364.386 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:44.781Z,1534981364.781 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:45.180Z,1534981365.180 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:45.585Z,1534981365.585 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:45.981Z,1534981365.981 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:46.383Z,1534981366.383 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:46.788Z,1534981366.788 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:47.202Z,1534981367.202 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:47.586Z,1534981367.586 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:47.984Z,1534981367.984 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:48.399Z,1534981368.399 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:48.775Z,1534981368.775 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:49.176Z,1534981369.176 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:49.575Z,1534981369.575 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:49.975Z,1534981369.975 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:50.391Z,1534981370.391 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:50.779Z,1534981370.779 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:51.181Z,1534981371.181 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:51.581Z,1534981371.581 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:51.981Z,1534981371.981 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:52.385Z,1534981372.385 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:52.803Z,1534981372.803 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:53.182Z,1534981373.182 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:53.600Z,1534981373.600 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:53.975Z,1534981373.975 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:54.375Z,1534981374.375 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:54.774Z,1534981374.774 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:55.204Z,1534981375.204 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:55.580Z,1534981375.580 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:55.981Z,1534981375.981 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:56.434Z,1534981376.434 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:56.781Z,1534981376.781 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:57.181Z,1534981377.181 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:57.592Z,1534981377.592 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:57.982Z,1534981377.982 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:58.385Z,1534981378.385 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:58.785Z,1534981378.785 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:59.182Z,1534981379.182 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:59.655Z,1534981379.655 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:42:59.975Z,1534981379.975 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:00.375Z,1534981380.375 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:00.774Z,1534981380.774 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:01.175Z,1534981381.175 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:01.606Z,1534981381.606 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:01.974Z,1534981381.974 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:02.379Z,1534981382.379 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:02.791Z,1534981382.791 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:03.182Z,1534981383.182 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:03.583Z,1534981383.583 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:03.994Z,1534981383.994 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:04.383Z,1534981384.383 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:04.783Z,1534981384.783 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:05.182Z,1534981385.182 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:05.582Z,1534981385.582 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:06.006Z,1534981386.006 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:06.383Z,1534981386.383 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:06.782Z,1534981386.782 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:07.183Z,1534981387.183 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:07.587Z,1534981387.587 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:07.983Z,1534981387.983 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:08.395Z,1534981388.395 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:08.797Z,1534981388.797 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:09.181Z,1534981389.181 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:09.579Z,1534981389.579 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:09.986Z,1534981389.986 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:10.381Z,1534981390.381 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:10.805Z,1534981390.805 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:11.183Z,1534981391.183 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:11.585Z,1534981391.585 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:11.997Z,1534981391.997 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:12.386Z,1534981392.386 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:12.835Z,1534981392.835 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:13.185Z,1534981393.185 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:13.589Z,1534981393.589 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:13.974Z,1534981393.974 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:14.375Z,1534981394.375 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:14.775Z,1534981394.775 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:15.197Z,1534981395.197 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:15.575Z,1534981395.575 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:15.975Z,1534981395.975 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:16.392Z,1534981396.392 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:16.781Z,1534981396.781 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:17.198Z,1534981397.198 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:17.574Z,1534981397.574 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:17.975Z,1534981397.975 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:18.379Z,1534981398.379 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:18.780Z,1534981398.780 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:19.178Z,1534981399.178 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:19.586Z,1534981399.586 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:19.987Z,1534981399.987 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:20.402Z,1534981400.402 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:20.786Z,1534981400.786 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:21.174Z,1534981401.174 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:21.575Z,1534981401.575 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:22.009Z,1534981402.009 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:22.374Z,1534981402.374 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:22.775Z,1534981402.775 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:23.175Z,1534981403.175 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:23.574Z,1534981403.574 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:24.044Z,1534981404.044 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:24.403Z,1534981404.403 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:24.774Z,1534981404.774 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:25.179Z,1534981405.179 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:25.583Z,1534981405.583 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:26.016Z,1534981406.016 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:26.375Z,1534981406.375 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:26.776Z,1534981406.776 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:27.175Z,1534981407.175 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:27.575Z,1534981407.575 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:27.980Z,1534981407.980 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:27.994Z,1534981407.994 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-08-22T23:43:27.995Z,1534981407.995 [Default:CheckIn:C.Wait] Stopped 2018-08-22T23:43:27.995Z,1534981407.995 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-08-22T23:43:27.995Z,1534981407.995 [Default:CheckIn:D] Running Loop=1 2018-08-22T23:43:28.457Z,1534981408.457 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:28.524Z,1534981408.524 [Default:CheckIn:D] Stopped 2018-08-22T23:43:28.524Z,1534981408.524 [Default:CheckIn:E] Running Loop=1 2018-08-22T23:43:28.820Z,1534981408.820 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:28.851Z,1534981408.851 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 94.648983 min 2018-08-22T23:43:28.851Z,1534981408.851 [Default:CheckIn:E] Stopped 2018-08-22T23:43:28.851Z,1534981408.851 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-08-22T23:43:28.851Z,1534981408.851 [Default:CheckIn] Stopped 2018-08-22T23:43:28.851Z,1534981408.851 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-08-22T23:43:28.852Z,1534981408.852 [Default:CheckIn](INFO): Running loop #10 2018-08-22T23:43:28.852Z,1534981408.852 [Default:CheckIn] Running Loop=10 2018-08-22T23:43:28.852Z,1534981408.852 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-08-22T23:43:28.852Z,1534981408.852 [Default:CheckIn:Read_GPS] Running Loop=1 2018-08-22T23:43:32.520Z,1534981412.520 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:32.728Z,1534981412.728 [NAL9602](INFO): Powering up 2018-08-22T23:43:32.790Z,1534981412.790 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:33.103Z,1534981413.103 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:33.505Z,1534981413.505 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:33.901Z,1534981413.901 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:34.302Z,1534981414.302 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:34.701Z,1534981414.701 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:35.103Z,1534981415.103 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:35.503Z,1534981415.503 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:35.904Z,1534981415.904 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:36.304Z,1534981416.304 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:36.759Z,1534981416.759 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:37.095Z,1534981417.095 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:37.499Z,1534981417.499 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:37.900Z,1534981417.900 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:38.301Z,1534981418.301 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:38.704Z,1534981418.704 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:39.104Z,1534981419.104 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:39.504Z,1534981419.504 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:39.903Z,1534981419.903 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:40.303Z,1534981420.303 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:40.723Z,1534981420.723 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:41.144Z,1534981421.144 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:41.504Z,1534981421.504 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:41.901Z,1534981421.901 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:42.302Z,1534981422.302 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:42.706Z,1534981422.706 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:43.102Z,1534981423.102 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:43.512Z,1534981423.512 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:43.874Z,1534981423.874 [NAL9602](INFO): NAL9602 initialized 2018-08-22T23:43:43.912Z,1534981423.912 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:44.302Z,1534981424.302 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:44.670Z,1534981424.670 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-08-22T23:43:44.670Z,1534981424.670 [NAL9602] Data Fault, FailCount= 2 2018-08-22T23:43:44.670Z,1534981424.670 [NAL9602](ERROR): Data Fault 2018-08-22T23:43:44.731Z,1534981424.731 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:44.882Z,1534981424.882 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-22T23:43:45.074Z,1534981425.074 [NAL9602](INFO): Powering down 2018-08-22T23:43:45.113Z,1534981425.113 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:45.501Z,1534981425.501 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:45.900Z,1534981425.900 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:45.925Z,1534981425.925 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-22T23:43:45.925Z,1534981425.925 [NAL9602] No Fault, FailCount= 2 2018-08-22T23:43:46.306Z,1534981426.306 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:46.702Z,1534981426.702 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:47.101Z,1534981427.101 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:47.505Z,1534981427.505 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:47.905Z,1534981427.905 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:48.301Z,1534981428.301 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:48.754Z,1534981428.754 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:49.095Z,1534981429.095 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:49.501Z,1534981429.501 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:49.903Z,1534981429.903 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:50.301Z,1534981430.301 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:50.701Z,1534981430.701 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:51.103Z,1534981431.103 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:51.501Z,1534981431.501 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:51.905Z,1534981431.905 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:52.306Z,1534981432.306 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:52.739Z,1534981432.739 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:53.166Z,1534981433.166 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:53.509Z,1534981433.509 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:53.903Z,1534981433.903 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:54.305Z,1534981434.305 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:54.703Z,1534981434.703 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:55.103Z,1534981435.103 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:55.505Z,1534981435.505 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:55.907Z,1534981435.907 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:56.315Z,1534981436.315 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:56.705Z,1534981436.705 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:57.118Z,1534981437.118 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:57.503Z,1534981437.503 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:57.905Z,1534981437.905 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:58.305Z,1534981438.305 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:58.703Z,1534981438.703 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:59.104Z,1534981439.104 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:59.504Z,1534981439.504 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:43:59.902Z,1534981439.902 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:00.302Z,1534981440.302 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:00.703Z,1534981440.703 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:01.119Z,1534981441.119 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:01.513Z,1534981441.513 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:01.893Z,1534981441.893 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:02.311Z,1534981442.311 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:02.706Z,1534981442.706 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:03.108Z,1534981443.108 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:03.515Z,1534981443.515 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:03.925Z,1534981443.925 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:04.304Z,1534981444.304 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:04.702Z,1534981444.702 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:05.151Z,1534981445.151 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:05.510Z,1534981445.510 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:05.903Z,1534981445.903 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:06.309Z,1534981446.309 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:06.695Z,1534981446.695 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:07.095Z,1534981447.095 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:07.499Z,1534981447.499 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:07.896Z,1534981447.896 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:08.303Z,1534981448.303 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:08.695Z,1534981448.695 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:09.145Z,1534981449.145 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:09.513Z,1534981449.513 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:09.899Z,1534981449.899 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:10.295Z,1534981450.295 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:10.700Z,1534981450.700 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:11.098Z,1534981451.098 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:11.493Z,1534981451.493 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:11.928Z,1534981451.928 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:12.302Z,1534981452.302 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:12.702Z,1534981452.702 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:13.126Z,1534981453.126 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:13.517Z,1534981453.517 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:13.903Z,1534981453.903 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:14.303Z,1534981454.303 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:14.707Z,1534981454.707 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:15.102Z,1534981455.102 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:15.470Z,1534981455.470 [NAL9602](INFO): Powering up NAL9602 2018-08-22T23:44:15.509Z,1534981455.509 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:15.915Z,1534981455.915 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:16.298Z,1534981456.298 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:16.699Z,1534981456.699 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:17.098Z,1534981457.098 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:17.522Z,1534981457.522 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:17.940Z,1534981457.940 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:18.302Z,1534981458.302 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:18.734Z,1534981458.734 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:19.112Z,1534981459.112 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:19.502Z,1534981459.502 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:19.901Z,1534981459.901 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:20.306Z,1534981460.306 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:20.701Z,1534981460.701 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:21.101Z,1534981461.101 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:21.503Z,1534981461.503 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:21.959Z,1534981461.959 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:22.295Z,1534981462.295 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:22.695Z,1534981462.695 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:23.102Z,1534981463.102 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:23.498Z,1534981463.498 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:23.898Z,1534981463.898 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:24.297Z,1534981464.297 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:24.698Z,1534981464.698 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:25.123Z,1534981465.123 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:25.495Z,1534981465.495 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:25.900Z,1534981465.900 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:26.328Z,1534981466.328 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:26.673Z,1534981466.673 [NAL9602](INFO): NAL9602 initialized 2018-08-22T23:44:26.699Z,1534981466.699 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:27.102Z,1534981467.102 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:27.510Z,1534981467.510 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:27.910Z,1534981467.910 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:28.314Z,1534981468.314 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:28.708Z,1534981468.708 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:29.103Z,1534981469.103 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:33.151Z,1534981473.151 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:33.286Z,1534981473.286 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:33.634Z,1534981473.634 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:34.043Z,1534981474.043 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:34.576Z,1534981474.576 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:34.816Z,1534981474.816 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:35.216Z,1534981475.216 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:35.615Z,1534981475.615 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:36.019Z,1534981476.019 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:36.416Z,1534981476.416 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:36.819Z,1534981476.819 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:37.219Z,1534981477.219 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:37.639Z,1534981477.639 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:38.031Z,1534981478.031 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:38.440Z,1534981478.440 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:38.842Z,1534981478.842 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:39.226Z,1534981479.226 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:39.615Z,1534981479.615 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:40.019Z,1534981480.019 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:40.419Z,1534981480.419 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:40.837Z,1534981480.837 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:41.223Z,1534981481.223 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:41.626Z,1534981481.626 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:42.023Z,1534981482.023 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:42.442Z,1534981482.442 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:42.823Z,1534981482.823 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:43.241Z,1534981483.241 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:43.637Z,1534981483.637 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:44.057Z,1534981484.057 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:44.434Z,1534981484.434 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:44.816Z,1534981484.816 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:45.216Z,1534981485.216 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:45.615Z,1534981485.615 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:46.020Z,1534981486.020 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:46.432Z,1534981486.432 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:46.901Z,1534981486.901 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:47.218Z,1534981487.218 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:47.616Z,1534981487.616 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:48.016Z,1534981488.016 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:48.441Z,1534981488.441 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:48.827Z,1534981488.827 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:49.230Z,1534981489.230 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:49.630Z,1534981489.630 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:50.035Z,1534981490.035 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:50.421Z,1534981490.421 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:50.834Z,1534981490.834 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:51.216Z,1534981491.216 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:51.615Z,1534981491.615 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:52.016Z,1534981492.016 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:52.420Z,1534981492.420 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:52.821Z,1534981492.821 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:53.231Z,1534981493.231 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:53.640Z,1534981493.640 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:54.036Z,1534981494.036 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:54.437Z,1534981494.437 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:54.848Z,1534981494.848 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:55.230Z,1534981495.230 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:55.616Z,1534981495.616 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:56.015Z,1534981496.015 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:56.448Z,1534981496.448 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:56.817Z,1534981496.817 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:57.216Z,1534981497.216 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:57.615Z,1534981497.615 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:58.016Z,1534981498.016 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:58.419Z,1534981498.419 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:58.876Z,1534981498.876 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:59.237Z,1534981499.237 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:44:59.646Z,1534981499.646 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:45:00.037Z,1534981500.037 [BPC1](ERROR): Failed to parse Bank B battery data 2018-08-22T23:45:00.037Z,1534981500.037 [BPC1](ERROR): Failed to receive data from both battery packs 2018-08-22T23:45:00.037Z,1534981500.037 [BPC1] Communications Fault, FailCount= 4 2018-08-22T23:45:00.037Z,1534981500.037 [BPC1](ERROR): Communications Fault 2018-08-22T23:45:00.100Z,1534981500.100 [CBIT](ERROR): Communications Fault in component: BPC1 2018-08-22T23:45:01.258Z,1534981501.258 [CBIT](INFO): Clearing failed state for component BPC1 2018-08-22T23:45:01.258Z,1534981501.258 [BPC1] No Fault, FailCount= 4 2018-08-22T23:48:29.058Z,1534981709.058 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-22T23:43:28.9Z 2018-08-22T23:48:29.058Z,1534981709.058 [Default:CheckIn:Read_GPS] Stopped 2018-08-22T23:48:29.058Z,1534981709.058 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-08-22T23:48:35.533Z,1534981715.533 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180822T215714/Courier0030.lzma 2018-08-22T23:48:36.476Z,1534981716.476 [DataOverHttps](INFO): Moved sent file to Logs/20180822T215714/Courier0030.lzma.bak 2018-08-22T23:48:36.476Z,1534981716.476 [DataOverHttps](INFO): SBD MOMSN=8436651 2018-08-22T23:48:53.198Z,1534981733.198 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20180822T215714/Express0031.lzma 2018-08-22T23:48:53.995Z,1534981733.995 [DataOverHttps](INFO): Moved sent file to Logs/20180822T215714/Express0031.lzma.bak 2018-08-22T23:48:53.995Z,1534981733.995 [DataOverHttps](INFO): SBD MOMSN=8436653 2018-08-22T23:48:55.933Z,1534981735.933 [Default:CheckIn:Read_Iridium] Stopped 2018-08-22T23:48:55.933Z,1534981735.933 [Default:CheckIn:C.Wait] Running Loop=1 2018-08-22T23:48:55.933Z,1534981735.933 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-08-22T23:49:33.366Z,1534981773.366 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-08-22T23:50:03.822Z,1534981803.822 [NAL9602](INFO): Powering down 2018-08-22T23:51:03.229Z,1534981863.229 [BPC1](ERROR): Failed to receive data from both battery packs 2018-08-22T23:51:03.229Z,1534981863.229 [BPC1] Communications Fault, FailCount= 5 2018-08-22T23:51:03.229Z,1534981863.229 [BPC1](ERROR): Communications Fault 2018-08-22T23:51:03.256Z,1534981863.256 [CBIT](ERROR): Communications Fault in component: BPC1 2018-08-22T23:51:04.450Z,1534981864.450 [CBIT](INFO): Clearing failed state for component BPC1 2018-08-22T23:51:04.450Z,1534981864.450 [BPC1] No Fault, FailCount= 5 2018-08-22T23:53:56.209Z,1534982036.209 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-08-22T23:53:56.209Z,1534982036.209 [Default:CheckIn:C.Wait] Stopped 2018-08-22T23:53:56.209Z,1534982036.209 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-08-22T23:53:56.210Z,1534982036.210 [Default:CheckIn:D] Running Loop=1 2018-08-22T23:53:56.620Z,1534982036.620 [Default:CheckIn:D] Stopped 2018-08-22T23:53:56.620Z,1534982036.620 [Default:CheckIn:E] Running Loop=1 2018-08-22T23:53:57.014Z,1534982037.014 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 105.117244 min 2018-08-22T23:53:57.019Z,1534982037.019 [Default:CheckIn:E] Stopped 2018-08-22T23:53:57.020Z,1534982037.020 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-08-22T23:53:57.020Z,1534982037.020 [Default:CheckIn] Stopped 2018-08-22T23:53:57.020Z,1534982037.020 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-08-22T23:53:57.020Z,1534982037.020 [Default:CheckIn](INFO): Running loop #11 2018-08-22T23:53:57.020Z,1534982037.020 [Default:CheckIn] Running Loop=11 2018-08-22T23:53:57.020Z,1534982037.020 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-08-22T23:53:57.021Z,1534982037.021 [Default:CheckIn:Read_GPS] Running Loop=1 2018-08-22T23:53:58.155Z,1534982038.155 [CommandLine](IMPORTANT): got command restart application 2018-08-22T23:53:59.157Z,1534982039.157 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2018-08-22T23:53:59.157Z,1534982039.157 [CommandLine ThreadHandler](INFO): Thread cancelled. 2018-08-22T23:53:59.193Z,1534982039.193 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2018-08-22T23:53:59.193Z,1534982039.193 [CommandLine ThreadHandler](INFO): Thread cancelled. 2018-08-22T23:53:59.194Z,1534982039.194 [CommandLine](INFO): Join timeout helper Thread ID is 2075 2018-08-22T23:53:59.207Z,1534982039.207 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2018-08-22T23:53:59.208Z,1534982039.208 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2018-08-22T23:53:59.208Z,1534982039.208 [NavChartDb](INFO): Join timeout helper Thread ID is 2076 2018-08-22T23:53:59.441Z,1534982039.441 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2018-08-22T23:53:59.441Z,1534982039.441 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2018-08-22T23:53:59.449Z,1534982039.449 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2018-08-22T23:53:59.449Z,1534982039.449 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2018-08-22T23:53:59.449Z,1534982039.449 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 2077 2018-08-22T23:53:59.537Z,1534982039.537 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2018-08-22T23:53:59.537Z,1534982039.537 [WetLabsBB2FL](INFO): Powering down 2018-08-22T23:53:59.538Z,1534982039.538 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2018-08-22T23:53:59.561Z,1534982039.561 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2018-08-22T23:53:59.561Z,1534982039.561 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2018-08-22T23:53:59.561Z,1534982039.561 [CTD_Seabird](INFO): Join timeout helper Thread ID is 2078 2018-08-22T23:53:59.917Z,1534982039.917 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2018-08-22T23:54:00.088Z,1534982040.088 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface 2018-08-22T23:54:00.088Z,1534982040.088 [CTD_Seabird](INFO): Powering down 2018-08-22T23:54:00.089Z,1534982040.089 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2018-08-22T23:54:00.105Z,1534982040.105 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler 2018-08-22T23:54:00.105Z,1534982040.105 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled. 2018-08-22T23:54:00.106Z,1534982040.106 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 2080 2018-08-22T23:54:00.337Z,1534982040.337 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread. 2018-08-22T23:54:00.337Z,1534982040.337 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-08-22T23:54:00.509Z,1534982040.509 [Rowe_600LCM](INFO): Powering down 2018-08-22T23:54:00.510Z,1534982040.510 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled. 2018-08-22T23:54:00.518Z,1534982040.518 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2018-08-22T23:54:00.518Z,1534982040.518 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2018-08-22T23:54:00.519Z,1534982040.519 [Radio_Surface](INFO): Join timeout helper Thread ID is 2082 2018-08-22T23:54:00.565Z,1534982040.565 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2018-08-22T23:54:00.565Z,1534982040.565 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2018-08-22T23:54:00.570Z,1534982040.570 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2018-08-22T23:54:00.570Z,1534982040.570 [logger ThreadHandler](INFO): Thread cancelled. 2018-08-22T23:54:00.570Z,1534982040.570 [logger](INFO): Join timeout helper Thread ID is 2083 2018-08-22T23:54:00.605Z,1534982040.605 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2018-08-22T23:54:00.605Z,1534982040.605 [logger ThreadHandler](INFO): Thread cancelled. 2018-08-22T23:54:00.621Z,1534982040.621 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2018-08-22T23:54:00.622Z,1534982040.622 [CommandLine ThreadHandler](INFO): Thread cancelled. 2018-08-22T23:54:00.622Z,1534982040.622 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2018-08-22T23:54:00.622Z,1534982040.622 [controlThread ThreadHandler](INFO): Thread cancelled. 2018-08-22T23:54:00.622Z,1534982040.622 [controlThread](INFO): Join timeout helper Thread ID is 2084 2018-08-22T23:54:00.869Z,1534982040.869 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2018-08-22T23:54:00.869Z,1534982040.869 [controlThread](DEBUG): Uninitializing ControlThread 2018-08-22T23:54:00.876Z,1534982040.876 [NAL9602](INFO): Powering down 2018-08-22T23:54:00.878Z,1534982040.878 [PNI_TCM](INFO): Powering down 2018-08-22T23:54:00.968Z,1534982040.968 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2018-08-22T23:54:00.969Z,1534982040.969 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2018-08-22T23:54:00.970Z,1534982040.970 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2018-08-22T23:54:00.971Z,1534982040.971 [MissionManager](INFO): Uninitializing Mission Default 2018-08-22T23:54:00.971Z,1534982040.971 [Default] Stopped 2018-08-22T23:54:00.971Z,1534982040.971 [Default](DEBUG): Aggregate::uninitialize Default 2018-08-22T23:54:00.971Z,1534982040.971 [Default:B.GoToSurface] Stopped 2018-08-22T23:54:00.971Z,1534982040.971 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2018-08-22T23:54:00.971Z,1534982040.971 [Default:CheckIn] Stopped 2018-08-22T23:54:00.971Z,1534982040.971 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-08-22T23:54:00.971Z,1534982040.971 [Default:CheckIn:Read_GPS] Stopped 2018-08-22T23:54:00.976Z,1534982040.976 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2018-08-22T23:54:00.976Z,1534982040.976 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2018-08-22T23:54:00.976Z,1534982040.976 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2018-08-22T23:54:00.977Z,1534982040.977 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2018-08-22T23:54:00.977Z,1534982040.977 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2018-08-22T23:54:00.977Z,1534982040.977 [BuoyancyServo](INFO): Powering down 2018-08-22T23:54:00.989Z,1534982040.989 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2018-08-22T23:54:00.989Z,1534982040.989 [ElevatorServo](INFO): Powering down 2018-08-22T23:54:00.990Z,1534982040.990 [MassServo](DEBUG): Uninitialize Mass Servo. 2018-08-22T23:54:00.990Z,1534982040.990 [MassServo](INFO): Powering down 2018-08-22T23:54:00.991Z,1534982040.991 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2018-08-22T23:54:00.991Z,1534982040.991 [RudderServo](INFO): Powering down 2018-08-22T23:54:00.992Z,1534982040.992 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2018-08-22T23:54:00.993Z,1534982040.993 [ThrusterServo](INFO): Powering down 2018-08-22T23:54:00.994Z,1534982040.994 [SBIT](DEBUG): Uninitialize SBIT Component. 2018-08-22T23:54:00.994Z,1534982040.994 [IBIT](DEBUG): Uninitialize IBIT Component. 2018-08-22T23:54:00.994Z,1534982040.994 [CBIT](DEBUG): Uninitialize CBIT Component. 2018-08-22T23:54:00.995Z,1534982040.995 [controlThread ThreadHandler](INFO): Thread cancelled. 2018-08-22T23:54:01.104Z,1534982041.104 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled. 2018-08-22T23:54:01.111Z,1534982041.111 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2018-08-22T23:54:01.149Z,1534982041.149 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2018-08-22T23:54:01.226Z,1534982041.226 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2018-08-22T23:54:01.274Z,1534982041.274 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2018-08-22T23:54:01.343Z,1534982041.343 [logger ThreadHandler](INFO): Thread cancelled.