2025-08-22T04:30:00.962Z,1755837000.962 [CommandExec](IMPORTANT): got command restart logs 2025-08-22T04:30:06.980Z,1755837006.980 [CommandExec](IMPORTANT): got command configSet CBIT.runNavErrorCritical 0 bool persist 2025-08-22T04:30:31.435Z,1755837031.435 [DataOverHttps](IMPORTANT): Could not stat file Logs/20250821T130000/Courier0069.lzma 2025-08-22T04:30:31.435Z,1755837031.435 [DataOverHttps](FAULT): Could not open file Logs/20250821T130000/Courier0069.lzma 2025-08-22T04:30:44.485Z,1755837044.485 [DataOverHttps](IMPORTANT): SBD MTMSN=20250822T043042 2025-08-22T04:31:03.307Z,1755837063.307 [DataOverHttps](IMPORTANT): Could not stat file Logs/20250821T130000/Courier0069.lzma 2025-08-22T04:31:03.308Z,1755837063.308 [DataOverHttps](FAULT): Could not open file Logs/20250821T130000/Courier0069.lzma 2025-08-22T04:31:03.311Z,1755837063.311 [DataOverHttps](INFO): Received command: sched 20250822T13 "restart logs;configSet CBIT.runNavErrorCritical 1 bool persist" 2025-08-22T04:31:03.344Z,1755837063.344 [CommandExec](IMPORTANT): got command schedule 20250822T130000 "restart logs;configSet CBIT.runNavErrorCritical 1 bool persist" 2025-08-22T04:31:03.345Z,1755837063.345 [CommandExec](IMPORTANT): Scheduled #1: "restart logs;configSet CBIT.runNavErrorCritical 1 bool persist", AT TIME: 2025-08-22T13:00:00Z 2025-08-22T04:31:25.038Z,1755837085.037 [DataOverHttps](IMPORTANT): Could not stat file Logs/20250821T130000/Courier0069.lzma 2025-08-22T04:31:25.038Z,1755837085.038 [DataOverHttps](FAULT): Could not open file Logs/20250821T130000/Courier0069.lzma 2025-08-22T04:31:27.550Z,1755837087.550 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-22T04:31:27.551Z,1755837087.551 [Default:CheckIn:C.Wait] Stopped 2025-08-22T04:31:27.551Z,1755837087.551 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-22T04:31:27.551Z,1755837087.551 [Default:CheckIn:D] Running Loop=1 2025-08-22T04:31:27.936Z,1755837087.936 [Default:CheckIn:D] Stopped 2025-08-22T04:31:27.936Z,1755837087.936 [Default:CheckIn:E] Running Loop=1 2025-08-22T04:31:28.338Z,1755837088.338 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 7.042018 min 2025-08-22T04:31:28.338Z,1755837088.338 [Default:CheckIn:E] Stopped 2025-08-22T04:31:28.338Z,1755837088.338 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-22T04:31:28.338Z,1755837088.338 [Default:CheckIn] Stopped 2025-08-22T04:31:28.339Z,1755837088.339 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-22T04:31:28.339Z,1755837088.339 [Default:CheckIn](INFO): Running loop #2 2025-08-22T04:31:28.339Z,1755837088.339 [Default:CheckIn] Running Loop=2 2025-08-22T04:31:28.339Z,1755837088.339 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-22T04:31:28.339Z,1755837088.339 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-22T04:31:30.357Z,1755837090.357 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,043130.00,A,3646.70882,N,12201.93058,W,2.624,142.37,220825,,,A*72 2025-08-22T04:31:30.359Z,1755837090.359 [NAL9602](INFO): GPS fix at 20250822T043130: (36.778480, -122.032176) 2025-08-22T04:31:30.370Z,1755837090.370 [Default:CheckIn:Read_GPS] Stopped 2025-08-22T04:31:30.370Z,1755837090.370 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-22T04:31:43.887Z,1755837103.887 [DataOverHttps](INFO): Sending 40 bytes from file Logs/20250821T130000/Courier0072.lzma 2025-08-22T04:31:49.922Z,1755837109.922 [NAL9602](INFO): SBD MO Status=2, MOMSN=22219, MT Status=2, MTMSN=0 2025-08-22T04:31:49.923Z,1755837109.923 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-22T04:31:55.934Z,1755837115.934 [DataOverHttps](INFO): Moved sent file to Logs/20250821T130000/Courier0072.lzma.bak 2025-08-22T04:31:55.934Z,1755837115.934 [DataOverHttps](INFO): SBD MOMSN=25879548 2025-08-22T04:32:27.872Z,1755837147.872 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2025-08-22T04:33:02.705Z,1755837182.705 [DataOverHttps](INFO): Sending 40 bytes from file Logs/20250821T130000/Courier0075.lzma 2025-08-22T04:33:13.746Z,1755837193.746 [DataOverHttps](INFO): Moved sent file to Logs/20250821T130000/Courier0075.lzma.bak 2025-08-22T04:33:13.746Z,1755837193.746 [DataOverHttps](INFO): SBD MOMSN=25879550 2025-08-22T04:33:34.860Z,1755837214.860 [NAL9602](INFO): SBD MO Status=2, MOMSN=22219, MT Status=2, MTMSN=0 2025-08-22T04:33:34.860Z,1755837214.860 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-22T04:33:45.485Z,1755837225.485 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2025-08-22T04:33:54.651Z,1755837234.651 [NAL9602](INFO): SBD MO Status=0, MOMSN=22219, MT Status=0, MTMSN=0 2025-08-22T04:33:54.651Z,1755837234.651 [NAL9602](INFO): No messages in MT queue 2025-08-22T04:34:17.235Z,1755837257.235 [DataOverHttps](INFO): Sending 185 bytes from file Logs/20250822T041854/Courier0000.lzma 2025-08-22T04:34:25.360Z,1755837265.360 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-22T04:34:28.277Z,1755837268.277 [DataOverHttps](INFO): Moved sent file to Logs/20250822T041854/Courier0000.lzma.bak 2025-08-22T04:34:28.277Z,1755837268.277 [DataOverHttps](INFO): SBD MOMSN=25879556 2025-08-22T04:34:57.579Z,1755837297.579 [DataOverHttps](INFO): Sending 227 bytes from file Logs/20250822T041854/Courier0004.lzma 2025-08-22T04:35:08.621Z,1755837308.621 [DataOverHttps](INFO): Moved sent file to Logs/20250822T041854/Courier0004.lzma.bak 2025-08-22T04:35:08.622Z,1755837308.622 [DataOverHttps](INFO): SBD MOMSN=25879567 2025-08-22T04:35:35.238Z,1755837335.238 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20250822T041854/Courier0007.lzma 2025-08-22T04:35:46.278Z,1755837346.278 [DataOverHttps](INFO): Moved sent file to Logs/20250822T041854/Courier0007.lzma.bak 2025-08-22T04:35:46.279Z,1755837346.279 [DataOverHttps](INFO): SBD MOMSN=25879570 2025-08-22T04:36:17.780Z,1755837377.780 [DataOverHttps](INFO): Sending 273 bytes from file Logs/20250822T043000/Courier0000.lzma 2025-08-22T04:36:34.845Z,1755837394.845 [DataOverHttps](INFO): Moved sent file to Logs/20250822T043000/Courier0000.lzma.bak 2025-08-22T04:36:34.846Z,1755837394.846 [DataOverHttps](INFO): SBD MOMSN=25879572 2025-08-22T04:37:13.901Z,1755837433.901 [DataOverHttps](INFO): Sending 2077 bytes from file Logs/20250821T130000/Express0067.lzma 2025-08-22T04:37:25.942Z,1755837445.942 [DataOverHttps](INFO): Moved sent file to Logs/20250821T130000/Express0067.lzma.bak 2025-08-22T04:37:25.942Z,1755837445.942 [DataOverHttps](INFO): SBD MOMSN=25879579 2025-08-22T04:38:03.688Z,1755837483.688 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20250821T130000/Express0070.lzma 2025-08-22T04:38:14.733Z,1755837494.733 [DataOverHttps](INFO): Moved sent file to Logs/20250821T130000/Express0070.lzma.bak 2025-08-22T04:38:14.734Z,1755837494.734 [DataOverHttps](INFO): SBD MOMSN=25879604 2025-08-22T04:38:41.524Z,1755837521.524 [DataOverHttps](INFO): Sending 196 bytes from file Logs/20250821T130000/Express0073.lzma 2025-08-22T04:38:52.578Z,1755837532.578 [DataOverHttps](INFO): Moved sent file to Logs/20250821T130000/Express0073.lzma.bak 2025-08-22T04:38:52.578Z,1755837532.578 [DataOverHttps](INFO): SBD MOMSN=25879611 2025-08-22T04:39:20.187Z,1755837560.187 [DataOverHttps](INFO): Sending 84 bytes from file Logs/20250821T130000/Express0076.lzma 2025-08-22T04:39:31.229Z,1755837571.229 [DataOverHttps](INFO): Moved sent file to Logs/20250821T130000/Express0076.lzma.bak 2025-08-22T04:39:31.230Z,1755837571.230 [DataOverHttps](INFO): SBD MOMSN=25879621 2025-08-22T04:40:07.718Z,1755837607.718 [DataOverHttps](INFO): Sending 1099 bytes from file Logs/20250822T041854/Express0001.lzma 2025-08-22T04:40:18.757Z,1755837618.757 [DataOverHttps](INFO): Moved sent file to Logs/20250822T041854/Express0001.lzma.bak 2025-08-22T04:40:18.758Z,1755837618.758 [DataOverHttps](INFO): SBD MOMSN=25879623 2025-08-22T04:40:37.776Z,1755837637.776 [RudderServo](ERROR): getPosition uart error serial timeout 2025-08-22T04:40:37.776Z,1755837637.776 [RudderServo](FAULT): Rudder uart error - getPosition..serial timeout 2025-08-22T04:40:37.776Z,1755837637.776 [RudderServo] Communications Fault, FailCount= 1 2025-08-22T04:40:37.776Z,1755837637.776 [RudderServo](ERROR): Communications Fault 2025-08-22T04:40:37.796Z,1755837637.796 [CBIT](ERROR): Communications Fault in component: RudderServo 2025-08-22T04:40:38.130Z,1755837638.130 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2025-08-22T04:40:38.130Z,1755837638.130 [RudderServo](INFO): Powering down 2025-08-22T04:40:38.909Z,1755837638.909 [RudderServo](DEBUG): Initializing EZServoServo. 2025-08-22T04:40:39.024Z,1755837639.024 [RudderServo](DEBUG): Initializing RudderServo. 2025-08-22T04:40:39.031Z,1755837639.031 [CBIT](INFO): Clearing failed state for component RudderServo 2025-08-22T04:40:39.031Z,1755837639.031 [RudderServo] No Fault, FailCount= 1 2025-08-22T04:40:45.348Z,1755837645.348 [DataOverHttps](INFO): Sending 335 bytes from file Logs/20250822T041854/Express0005.lzma 2025-08-22T04:40:56.393Z,1755837656.393 [DataOverHttps](INFO): Moved sent file to Logs/20250822T041854/Express0005.lzma.bak 2025-08-22T04:40:56.393Z,1755837656.393 [DataOverHttps](INFO): SBD MOMSN=25879649 2025-08-22T04:41:22.965Z,1755837682.965 [DataOverHttps](INFO): Sending 468 bytes from file Logs/20250822T041854/Express0008.lzma 2025-08-22T04:41:34.006Z,1755837694.006 [DataOverHttps](INFO): Moved sent file to Logs/20250822T041854/Express0008.lzma.bak 2025-08-22T04:41:34.007Z,1755837694.007 [DataOverHttps](INFO): SBD MOMSN=25879658 2025-08-22T04:42:02.362Z,1755837722.362 [DataOverHttps](INFO): Sending 818 bytes from file Logs/20250822T043000/Express0001.lzma 2025-08-22T04:42:13.401Z,1755837733.401 [DataOverHttps](INFO): Moved sent file to Logs/20250822T043000/Express0001.lzma.bak 2025-08-22T04:42:13.402Z,1755837733.402 [DataOverHttps](INFO): SBD MOMSN=25879690 2025-08-22T04:42:14.638Z,1755837734.638 [Default:CheckIn:Read_Iridium] Stopped 2025-08-22T04:42:14.638Z,1755837734.638 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-22T04:42:14.638Z,1755837734.638 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-22T04:42:28.368Z,1755837748.368 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2025-08-22T04:42:32.806Z,1755837752.806 [DVL_micro](ERROR): Failed to parse: :SA,-03.37,+06.39,061.7 2025-08-22T04:44:35.078Z,1755837875.078 [DataOverHttps](IMPORTANT): SBD MTMSN=20250822T044434 2025-08-22T04:44:43.214Z,1755837883.214 [DataOverHttps](INFO): Received command: sched 20250822T13 "load Science/sci2_vtyoyo.tl;set sci2_vtyoyo.MissionTimeout 16 h;set sci2_vtyoyo.NeedCommsTime 90 min;set sci2_vtyoyo.Lat1 36.9691 degree;set sci2_vtyoyo.Lon1 -122.50305 degree;set sci2_vtyoyo.Lat2 37.00694 degree" 153ty 1 3 2025-08-22T04:44:43.222Z,1755837883.222 [CommandExec](IMPORTANT): got command schedule 20250822T130000 "load Science/sci2_vtyoyo.tl;set sci2_vtyoyo.MissionTimeout 16 h;set sci2_vtyoyo.NeedCommsTime 90 min;set sci2_vtyoyo.Lat1 36.9691 degree;set sci2_vtyoyo.Lon1 -122.50305 degree;set sci2_vtyoyo.Lat2 37.00694 degree" 153ty 1 3.000000 2025-08-22T04:44:43.222Z,1755837883.222 [CommandExec](IMPORTANT): Scheduling command #1 of 3 with id=153ty 2025-08-22T04:44:43.223Z,1755837883.223 [CommandExec](IMPORTANT): Scheduled #2 (#1 of 3 with id='153ty'): "load Science/sci2_vtyoyo.tl;set sci2_vtyoyo.MissionTimeout 16 h;set sci2_vtyoyo.NeedCommsTime 90 min;set sci2_vtyoyo.Lat1 36.9691 degree;set sci2_vtyoyo.Lon1 -122.50305 degree;set sci2_vtyoyo.Lat2 37.00694 degree", AT TIME: 2025-08-22T13:00:00Z 2025-08-22T04:45:02.290Z,1755837902.290 [DataOverHttps](IMPORTANT): SBD MTMSN=20250822T044454 2025-08-22T04:45:10.119Z,1755837910.119 [DataOverHttps](INFO): Received command: sched 20250822T13 "set sci2_vtyoyo.Lon2 -122.93152 degree;set sci2_vtyoyo.Speed .8 m/s;set sci2_vtyoyo.YoYoMinDepth 3 m;set sci2_vtyoyo.YoYoMaxDepth 120 m;set sci2_vtyoyo.YoYoMinAltitude 15 m;set sci2_vtyoyo.MaxDepth 140 m" 153ty 2 3 2025-08-22T04:45:10.169Z,1755837910.169 [CommandExec](IMPORTANT): got command schedule 20250822T130000 "set sci2_vtyoyo.Lon2 -122.93152 degree;set sci2_vtyoyo.Speed .8 m/s;set sci2_vtyoyo.YoYoMinDepth 3 m;set sci2_vtyoyo.YoYoMaxDepth 120 m;set sci2_vtyoyo.YoYoMinAltitude 15 m;set sci2_vtyoyo.MaxDepth 140 m" 153ty 2 3.000000 2025-08-22T04:45:10.169Z,1755837910.169 [CommandExec](IMPORTANT): Scheduling command #2 of 3 with id=153ty 2025-08-22T04:45:10.171Z,1755837910.171 [CommandExec](IMPORTANT): Scheduled #3 (#2 of 3 with id='153ty'): "set sci2_vtyoyo.Lon2 -122.93152 degree;set sci2_vtyoyo.Speed .8 m/s;set sci2_vtyoyo.YoYoMinDepth 3 m;set sci2_vtyoyo.YoYoMaxDepth 120 m;set sci2_vtyoyo.YoYoMinAltitude 15 m;set sci2_vtyoyo.MaxDepth 140 m", AT TIME: 2025-08-22T13:00:00Z 2025-08-22T04:45:21.161Z,1755837921.161 [DataOverHttps](IMPORTANT): SBD MTMSN=20250822T044520 2025-08-22T04:45:28.863Z,1755837928.863 [DataOverHttps](INFO): Received command: sched 20250822T13 "set sci2_vtyoyo.SinkOffSurface 1 bool;set sci2_vtyoyo.SinkDepthTimeout 3 min;set sci2_vtyoyo:BackseatDriver.EnableBackseat 1 bool;run" 153ty 3 3 2025-08-22T04:45:28.901Z,1755837928.901 [CommandExec](IMPORTANT): got command schedule 20250822T130000 "set sci2_vtyoyo.SinkOffSurface 1 bool;set sci2_vtyoyo.SinkDepthTimeout 3 min;set sci2_vtyoyo:BackseatDriver.EnableBackseat 1 bool;run" 153ty 3 3.000000 2025-08-22T04:45:28.901Z,1755837928.901 [CommandExec](IMPORTANT): Scheduling command #3 of 3 with id=153ty 2025-08-22T04:45:28.902Z,1755837928.902 [CommandExec](IMPORTANT): Scheduled #4 (#3 of 3 with id='153ty'): "set sci2_vtyoyo.SinkOffSurface 1 bool;set sci2_vtyoyo.SinkDepthTimeout 3 min;set sci2_vtyoyo:BackseatDriver.EnableBackseat 1 bool;run", AT TIME: 2025-08-22T13:00:00Z 2025-08-22T04:45:39.909Z,1755837939.909 [DataOverHttps](IMPORTANT): SBD MTMSN=20250822T044539 2025-08-22T04:45:47.775Z,1755837947.775 [DataOverHttps](INFO): Received command: sched asap "load Transport/keepstation.tl;set keepstation.MissionTimeout 11 h;set keepstation.NeedCommsTime 60 min;set keepstation.Latitude 36.84116 degree;set keepstation.Longitude -122.15578 degree;set keepstation.Depth 20 m" 153vi 1 2 2025-08-22T04:45:47.786Z,1755837947.786 [CommandExec](IMPORTANT): got command schedule asap "load Transport/keepstation.tl;set keepstation.MissionTimeout 11 h;set keepstation.NeedCommsTime 60 min;set keepstation.Latitude 36.84116 degree;set keepstation.Longitude -122.15578 degree;set keepstation.Depth 20 m" 153vi 1 2.000000 2025-08-22T04:45:47.787Z,1755837947.787 [CommandExec](IMPORTANT): Scheduling command #1 of 2 with id=153vi 2025-08-22T04:45:47.789Z,1755837947.789 [CommandExec](IMPORTANT): Scheduled #5 (#1 of 2 with id='153vi'): "load Transport/keepstation.tl;set keepstation.MissionTimeout 11 h;set keepstation.NeedCommsTime 60 min;set keepstation.Latitude 36.84116 degree;set keepstation.Longitude -122.15578 degree;set keepstation.Depth 20 m", ASAP 2025-08-22T04:45:58.822Z,1755837958.822 [DataOverHttps](IMPORTANT): SBD MTMSN=20250822T044558 2025-08-22T04:46:06.572Z,1755837966.572 [DataOverHttps](INFO): Received command: sched asap "set keepstation.Speed 1 m/s;set keepstation.SinkOffSurface 1 bool;set keepstation.SinkDepthTimeout 3 min;set keepstation.MaxDepth 45 m;set keepstation:NeedComms.SurfaceSpeed 1 m/s;set keepstation:NeedComms.CommsTimeout 10 min;run" 153vi 2 2 2025-08-22T04:46:06.636Z,1755837966.636 [CommandExec](IMPORTANT): got command schedule asap "set keepstation.Speed 1 m/s;set keepstation.SinkOffSurface 1 bool;set keepstation.SinkDepthTimeout 3 min;set keepstation.MaxDepth 45 m;set keepstation:NeedComms.SurfaceSpeed 1 m/s;set keepstation:NeedComms.CommsTimeout 10 min;run" 153vi 2 2.000000 2025-08-22T04:46:06.637Z,1755837966.637 [CommandExec](IMPORTANT): Scheduling command #2 of 2 with id=153vi 2025-08-22T04:46:06.638Z,1755837966.638 [CommandExec](IMPORTANT): Scheduled #6 (#2 of 2 with id='153vi'): "set keepstation.Speed 1 m/s;set keepstation.SinkOffSurface 1 bool;set keepstation.SinkDepthTimeout 3 min;set keepstation.MaxDepth 45 m;set keepstation:NeedComms.SurfaceSpeed 1 m/s;set keepstation:NeedComms.CommsTimeout 10 min;run", ASAP 2025-08-22T04:46:06.753Z,1755837966.753 [CommandExec](IMPORTANT): got command load ./Missions/Transport/keepstation.tl 2025-08-22T04:46:06.754Z,1755837966.754 [MissionManager](INFO): Loading Mission from file: ./Missions/Transport/keepstation.tl 2025-08-22T04:46:06.754Z,1755837966.754 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Transport/keepstation.tl 2025-08-22T04:46:06.758Z,1755837966.758 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Transport/keepstation.tl 2025-08-22T04:46:07.997Z,1755837967.997 [MissionManager](DEBUG): TethyslAPI: ./Missions/Transport/keepstation.tl translated into: 4 45 NaN NaN 30 15 4 0.75 200 10 10 45 2 0 0 1 2 3 NaN 0 Sinking to Timed out while trying to reach target sink depth at current depth of 2025-08-22T04:46:08.006Z,1755837968.006 [MissionManager](INFO): DefineArg keepstation.MissionTimeout = 4.000000 h 2025-08-22T04:46:08.009Z,1755837968.009 [MissionManager](INFO): DefineArg keepstation.NeedCommsTime = 45.000000 min 2025-08-22T04:46:08.012Z,1755837968.012 [MissionManager](INFO): DefineArg keepstation.Latitude = nan arcdeg 2025-08-22T04:46:08.015Z,1755837968.015 [MissionManager](INFO): DefineArg keepstation.Longitude = nan arcdeg 2025-08-22T04:46:08.018Z,1755837968.018 [MissionManager](INFO): DefineArg keepstation.Depth = 30.000000 m 2025-08-22T04:46:08.022Z,1755837968.022 [MissionManager](INFO): DefineArg keepstation.ApproachDepth = 15.000000 m 2025-08-22T04:46:08.025Z,1755837968.025 [MissionManager](INFO): DefineArg keepstation.DepthDeadband = 4.000000 m 2025-08-22T04:46:08.028Z,1755837968.028 [MissionManager](INFO): DefineArg keepstation.Speed = 0.750000 m/s 2025-08-22T04:46:08.031Z,1755837968.031 [MissionManager](INFO): DefineArg keepstation.Radius = 200.000000 m 2025-08-22T04:46:08.034Z,1755837968.034 [MissionManager](INFO): DefineArg keepstation.SinkOffSurface = 0 bool 2025-08-22T04:46:08.037Z,1755837968.037 [MissionManager](INFO): DefineArg keepstation.SinkDepth = 10.000000 m 2025-08-22T04:46:08.040Z,1755837968.040 [MissionManager](INFO): DefineArg keepstation.SinkDepthTimeout = 10.000000 min 2025-08-22T04:46:08.043Z,1755837968.043 [MissionManager](INFO): DefineArg keepstation.MaxDepth = 45.000000 m 2025-08-22T04:46:08.046Z,1755837968.046 [MissionManager](INFO): DefineArg keepstation.MinOffshore = 2.000000 km 2025-08-22T04:46:08.079Z,1755837968.079 [MissionManager](INFO): DefineOutput keepstation.DiveMode = 0.000000 count 2025-08-22T04:46:08.082Z,1755837968.082 [MissionManager](INFO): DefineOutput keepstation.DoingComms = 0.000000 count 2025-08-22T04:46:08.085Z,1755837968.085 [MissionManager](INFO): DefineOutput keepstation.SurfaceSink = 1.000000 count 2025-08-22T04:46:08.096Z,1755837968.096 [MissionManager](INFO): DefineOutput keepstation.TransitToStation = 2.000000 count 2025-08-22T04:46:08.102Z,1755837968.102 [MissionManager](INFO): DefineOutput keepstation.StationKeep = 3.000000 count 2025-08-22T04:46:08.105Z,1755837968.105 [MissionManager](INFO): DefineOutput keepstation.OnStation = 0 bool 2025-08-22T04:46:08.105Z,1755837968.105 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/NeedComms.tl 2025-08-22T04:46:08.105Z,1755837968.105 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/NeedComms.tl 2025-08-22T04:46:08.107Z,1755837968.107 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/NeedComms.tl 2025-08-22T04:46:08.560Z,1755837968.560 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/NeedComms.tl translated into: 1 10 20 NaN 1 1000 7 30 0 last time_fix was: first GPS update timeout Comms timed out after minutes second GPS update timeout 2025-08-22T04:46:08.570Z,1755837968.570 [MissionManager](INFO): DefineArg keepstation:NeedComms.DiveInterval = 1.000000 h 2025-08-22T04:46:08.590Z,1755837968.590 [MissionManager](INFO): DefineArg keepstation:NeedComms.WaitForPitchUp = 10.000000 min 2025-08-22T04:46:08.594Z,1755837968.594 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfacePitch = 20.000000 arcdeg 2025-08-22T04:46:08.606Z,1755837968.606 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfaceDepthRate = nan m/s 2025-08-22T04:46:08.610Z,1755837968.610 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfaceSpeed = 1.000000 m/s 2025-08-22T04:46:08.621Z,1755837968.621 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfacingTimeout = 1000.000000 s 2025-08-22T04:46:08.629Z,1755837968.629 [MissionManager](INFO): DefineArg keepstation:NeedComms.GPSTimeout = 7.000000 min 2025-08-22T04:46:08.636Z,1755837968.636 [MissionManager](INFO): DefineArg keepstation:NeedComms.CommsTimeout = 30.000000 min 2025-08-22T04:46:08.653Z,1755837968.653 [keepstation:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface. 2025-08-22T04:46:08.706Z,1755837968.706 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/StandardEnvelopes.tl 2025-08-22T04:46:08.707Z,1755837968.707 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/StandardEnvelopes.tl 2025-08-22T04:46:08.716Z,1755837968.716 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/StandardEnvelopes.tl 2025-08-22T04:46:08.859Z,1755837968.859 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/StandardEnvelopes.tl translated into: 5 1.5 200 2000 2025-08-22T04:46:08.877Z,1755837968.877 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MinAltitude = 5.000000 m 2025-08-22T04:46:08.880Z,1755837968.880 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MaxDepthIgnore = 1.500000 m 2025-08-22T04:46:08.883Z,1755837968.883 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MaxDepth = 200.000000 m 2025-08-22T04:46:08.894Z,1755837968.894 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MinOffshore = 2000.000000 m 2025-08-22T04:46:08.900Z,1755837968.900 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2025-08-22T04:46:08.944Z,1755837968.944 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2025-08-22T04:46:08.973Z,1755837968.973 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope. 2025-08-22T04:46:09.005Z,1755837969.005 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl 2025-08-22T04:46:09.005Z,1755837969.005 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl 2025-08-22T04:46:09.006Z,1755837969.006 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl 2025-08-22T04:46:09.041Z,1755837969.041 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into: 2025-08-22T04:46:09.051Z,1755837969.051 [MissionManager](INFO): DefineArg keepstation:BackseatDriver.EnableBackseat = 0 bool 2025-08-22T04:46:09.058Z,1755837969.058 [keepstation:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver. 2025-08-22T04:46:09.065Z,1755837969.065 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/PowerOnly.tl 2025-08-22T04:46:09.065Z,1755837969.065 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/PowerOnly.tl 2025-08-22T04:46:09.066Z,1755837969.066 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/PowerOnly.tl 2025-08-22T04:46:09.363Z,1755837969.363 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/PowerOnly.tl translated into: 99999 2025-08-22T04:46:09.387Z,1755837969.387 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleAll = 0 bool 2025-08-22T04:46:09.412Z,1755837969.412 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleLoad1 = 0 bool 2025-08-22T04:46:09.426Z,1755837969.426 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleLoad2 = 0 bool 2025-08-22T04:46:09.433Z,1755837969.433 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleLoad3 = 0 bool 2025-08-22T04:46:09.439Z,1755837969.439 [MissionManager](INFO): DefineArg keepstation:PowerOnly.EnabledPowerOnly = 1 bool 2025-08-22T04:46:09.459Z,1755837969.459 [keepstation:PowerOnly:E.Wait](DEBUG): Construct Wait. 2025-08-22T04:46:09.466Z,1755837969.466 [keepstation:H.Pitch](DEBUG): Construct. 2025-08-22T04:46:09.514Z,1755837969.514 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Construct Buoyancy. 2025-08-22T04:46:09.519Z,1755837969.519 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Construct. 2025-08-22T04:46:09.543Z,1755837969.543 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch](DEBUG): Construct. 2025-08-22T04:46:09.584Z,1755837969.584 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Construct Buoyancy. 2025-08-22T04:46:09.601Z,1755837969.601 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch](DEBUG): Construct. 2025-08-22T04:46:09.616Z,1755837969.616 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Construct. 2025-08-22T04:46:09.626Z,1755837969.626 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Construct. 2025-08-22T04:46:09.640Z,1755837969.640 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Construct KeepStation. 2025-08-22T04:46:09.659Z,1755837969.659 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Construct Waypoint. 2025-08-22T04:46:09.691Z,1755837969.691 [keepstation:KeepStation:B.Wait](DEBUG): Construct Wait. 2025-08-22T04:46:09.722Z,1755837969.722 [MissionManager](DEBUG): # Copyright (c) 2024 MBARI # MBARI Proprietary Information. Confidential. All Rights Reserved # Unauthorized copying or distribution of this file via any medium is strictly # prohibited. # # WARNING - This file contains information whose export is restricted by the # Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as # amended. Violations of these export laws are subject to severe civil and/or # criminal penalties. mission keepstation { """ Vehicle transits to desired waypoint (or stays put if none is commanded) and stays within the specified radius. """ arguments { MissionTimeout = 4 hour """ Maximum duration of mission """ NeedCommsTime = 45 minute """ How often to surface for communications """ Latitude = NaN degree """ Latitude of waypoint to hold. If NaN, hold the latitude at start of mission. """ Longitude = NaN degree """ Longitude of waypoint to hold. If NaN, hold the longitude at start of mission. """ Depth = 30 meter """ Depth held during drift mode """ ApproachDepth = 15 meter """ Depth for initial approach to station. """ DepthDeadband = 4 meter """ How much vertical drift from the specified depth is allowed in drift mode """ Speed = 0.75 meter_per_second """ Vehicle transit speed. """ Radius = 200 meter """ Radius of circle around waypoint to hold. """ SinkOffSurface = false """ If true, use buoyancy only to decend to SinkDepth before driving to first target depth """ SinkDepth = 10 meter """ Initial depth to decend using only buoyancy before driving """ SinkDepthTimeout = 10 minute """ Max wait time for the vehicle to reach the target depth """ MaxDepth = 45 meter """ Maximum allowable depth during the mission. """ MinOffshore = 2 kilometer """ Minimum distance from the shoreline to maintain """ } output { DiveMode = 0 count """ Mission variable (don't change). The mission sets this variable to switch between dive modes. Initialized to DoingComms. """ DoingComms = 0 count """ Mission variable (don't change). The mission will run in this mode when doing surface comms. """ SurfaceSink = 1 count """ Mission variable (don't change). The mission will run in this mode when sinking from the surface using only buoyancy. """ TransitToStation = 2 count """ Mission variable (don't change). The mission will run in this mode when performing the transit to station """ StationKeep = 3 count """ Mission variable (don't change). The mission will run in this mode when keeping station """ OnStation = false """ Mission variable (don't change). Determines last mode (Transit or StationKeep) to resume after needcomms """ } timeout duration=MissionTimeout insert id="NeedComms" Insert/NeedComms.tl assign in sequence NeedComms:DiveInterval = NeedCommsTime insert Insert/StandardEnvelopes.tl assign in sequence StandardEnvelopes:MaxDepth = MaxDepth assign in sequence StandardEnvelopes:MinOffshore = MinOffshore insert Insert/BackseatDriver.tl insert Insert/PowerOnly.tl behavior Guidance:Pitch { run in parallel set massPosition = Control:VerticalControl.massDefault } aggregate SurfaceComms { run when ( called or ( elapsed ( Universal:time_fix ) > NeedCommsTime ) ) assign in sequence DiveMode = DoingComms call priorityHere=false refId="NeedComms" aggregate setTransit { run in sequence break if ( SinkOffSurface or OnStation ) assign in sequence DiveMode = TransitToStation } aggregate setStation { run in sequence break if ( SinkOffSurface or not OnStation ) assign in sequence DiveMode = StationKeep } aggregate setSink { run in sequence break if ( not SinkOffSurface ) assign in sequence DiveMode = SurfaceSink } } call id="StartingMission" priorityHere=false refId="SurfaceComms" aggregate DiveCmd { run when ( called ) aggregate SurfaceSink { run while ( DiveMode == SurfaceSink ) aggregate sink { run in sequence behavior Guidance:Buoyancy id="BuoyancyHold" { run in parallel set position = NaN cc } behavior Guidance:SetSpeed { run in parallel set speed = 0 m/s } syslog info "Sinking to " + SinkDepth~meter behavior Guidance:Pitch { run in sequence timeout duration=SinkDepthTimeout { syslog important "Timed out while trying to reach target sink depth at current depth of " + Universal:depth~meter } set depth = SinkDepth } # Once we've sunk, either resume transit or station keeping depths and speeds aggregate sinkToTransit { run in sequence break if ( OnStation ) assign in sequence DiveMode = TransitToStation } aggregate sinkToStation { run in sequence break if ( not OnStation ) assign in sequence DiveMode = StationKeep } } } aggregate TransitToStation { run while ( DiveMode == TransitToStation ) aggregate dive { run in sequence behavior Guidance:Buoyancy { run in parallel set position = Control:VerticalControl.buoyancyNeutral } behavior Guidance:Pitch { run in parallel set depth = ApproachDepth } behavior Guidance:SetSpeed { run in parallel set speed = Speed } } } aggregate StationKeep { run while ( DiveMode == StationKeep ) assign in parallel Control:VerticalControl.depthDeadband = DepthDeadband behavior Guidance:Pitch { run in parallel set depth = Depth } behavior Guidance:KeepStation { run in parallel set latitude = Latitude set longitude = Longitude set radius = Radius set speed = Speed } } } aggregate TransitToStation { """ Need a separate aggregate for transit if we want to specify a different depth for the approach. """ run in sequence aggregate Dive { run while ( not ( DiveMode == DoingComms ) ) call priorityHere=false refId="DiveCmd" } behavior Guidance:Waypoint id="Wpt1" { run in sequence set latitude = Latitude set longitude = Longitude } assign in sequence DiveMode = StationKeep assign in sequence OnStation = true } call id="OnStation" priorityHere=false refId="NeedComms" aggregate KeepStation { run in sequence aggregate Dive { run while ( not ( DiveMode == DoingComms ) ) call priorityHere=false refId="DiveCmd" } behavior Guidance:Wait { """ Due to the way the KeepStation behavior is currently implemented, we must run it in parallel and use a Wait to keep from completing the mission before the timeout expires. However, this new version of the mission uses a top-level timeout so that the entire mission will not run for longer then MissionTimeout. """ run in sequence set duration = MissionTimeout } } } 2025-08-22T04:46:09.723Z,1755837969.723 [CommandExec](IMPORTANT): Loaded ./Missions/Transport/keepstation.tl id=keepstation 2025-08-22T04:46:25.846Z,1755837985.846 [CommandExec](IMPORTANT): got command set keepstation.MissionTimeout 11 hour 2025-08-22T04:46:25.847Z,1755837985.847 [CommandExec](IMPORTANT): got command set keepstation.NeedCommsTime 60 minute 2025-08-22T04:46:25.849Z,1755837985.849 [CommandExec](IMPORTANT): got command set keepstation.Latitude 36.84116 degree 2025-08-22T04:46:25.849Z,1755837985.849 [CommandExec](IMPORTANT): got command set keepstation.Longitude -122.15578 degree 2025-08-22T04:46:25.850Z,1755837985.850 [CommandExec](IMPORTANT): got command set keepstation.Depth 20 meter 2025-08-22T04:46:37.649Z,1755837997.649 [DVL_micro](ERROR): only read 2 of 4 data items for bottom velocity. Device response is::BI,+00000,+0000I 2025-08-22T04:46:37.649Z,1755837997.649 [DVL_micro](ERROR): Failed to parse: :BI,+00000,+0000I 2025-08-22T04:46:56.116Z,1755838016.116 [CommandExec](IMPORTANT): got command set keepstation.Speed 1 meter_per_second 2025-08-22T04:46:56.116Z,1755838016.116 [CommandExec](IMPORTANT): got command set keepstation.SinkOffSurface 1 bool 2025-08-22T04:46:56.117Z,1755838016.117 [CommandExec](IMPORTANT): got command set keepstation.SinkDepthTimeout 3 minute 2025-08-22T04:46:56.121Z,1755838016.121 [CommandExec](IMPORTANT): got command set keepstation.MaxDepth 45 meter 2025-08-22T04:46:56.124Z,1755838016.124 [CommandExec](IMPORTANT): got command set keepstation:NeedComms.SurfaceSpeed 1 meter_per_second 2025-08-22T04:46:56.125Z,1755838016.125 [CommandExec](IMPORTANT): got command set keepstation:NeedComms.CommsTimeout 10 minute 2025-08-22T04:46:56.125Z,1755838016.125 [CommandExec](IMPORTANT): got command run 2025-08-22T04:46:56.127Z,1755838016.127 [CommandExec](IMPORTANT): Running 2025-08-22T04:46:56.252Z,1755838016.252 [Default] Stopped 2025-08-22T04:46:56.252Z,1755838016.252 [Default](DEBUG): Aggregate::uninitialize Default 2025-08-22T04:46:56.252Z,1755838016.252 [Default:B.GoToSurface] Stopped 2025-08-22T04:46:56.252Z,1755838016.252 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-08-22T04:46:56.252Z,1755838016.252 [Default:CheckIn] Stopped 2025-08-22T04:46:56.252Z,1755838016.252 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-22T04:46:56.252Z,1755838016.252 [Default:CheckIn:C.Wait] Stopped 2025-08-22T04:46:56.252Z,1755838016.252 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-22T04:46:56.252Z,1755838016.252 [MissionManager](IMPORTANT): Started mission keepstation 2025-08-22T04:46:56.253Z,1755838016.253 [keepstation] Running Loop=1 2025-08-22T04:46:56.253Z,1755838016.253 [keepstation](DEBUG): Aggregate::initialize keepstation 2025-08-22T04:46:56.253Z,1755838016.253 [keepstation:StandardEnvelopes] Running Loop=1 2025-08-22T04:46:56.253Z,1755838016.253 [keepstation:StandardEnvelopes](DEBUG): Aggregate::initialize keepstation:StandardEnvelopes 2025-08-22T04:46:56.253Z,1755838016.253 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2025-08-22T04:46:56.253Z,1755838016.253 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2025-08-22T04:46:56.253Z,1755838016.253 [keepstation:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2025-08-22T04:46:56.254Z,1755838016.254 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2025-08-22T04:46:56.254Z,1755838016.254 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2025-08-22T04:46:56.254Z,1755838016.254 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent. 2025-08-22T04:46:56.254Z,1755838016.254 [keepstation:BackseatDriver] Running Loop=1 2025-08-22T04:46:56.254Z,1755838016.254 [keepstation:BackseatDriver](DEBUG): Aggregate::initialize keepstation:BackseatDriver 2025-08-22T04:46:56.254Z,1755838016.254 [keepstation:BackseatDriver:A.BackseatDriver] Running Loop=1 2025-08-22T04:46:56.254Z,1755838016.254 [keepstation:PowerOnly] Running Loop=1 2025-08-22T04:46:56.254Z,1755838016.254 [keepstation:PowerOnly](DEBUG): Aggregate::initialize keepstation:PowerOnly 2025-08-22T04:46:56.254Z,1755838016.254 [keepstation:PowerOnly:A] Running Loop=1 2025-08-22T04:46:56.254Z,1755838016.254 [keepstation:PowerOnly:B] Running Loop=1 2025-08-22T04:46:56.255Z,1755838016.255 [keepstation:PowerOnly:C] Running Loop=1 2025-08-22T04:46:56.255Z,1755838016.255 [keepstation:PowerOnly:D] Running Loop=1 2025-08-22T04:46:56.256Z,1755838016.256 [keepstation:PowerOnly:E.Wait] Running Loop=1 2025-08-22T04:46:56.256Z,1755838016.256 [keepstation:PowerOnly:E.Wait](DEBUG): Initialize Wait Component. 2025-08-22T04:46:56.256Z,1755838016.256 [keepstation:H.Pitch] Running Loop=1 2025-08-22T04:46:56.256Z,1755838016.256 [keepstation:H.Pitch](DEBUG): Initialize. 2025-08-22T04:46:56.256Z,1755838016.256 [keepstation:B] Running Loop=1 2025-08-22T04:46:56.257Z,1755838016.257 [keepstation:H.Pitch] Running Loop=1 2025-08-22T04:46:56.257Z,1755838016.257 [keepstation:PowerOnly] Running Loop=1 2025-08-22T04:46:56.258Z,1755838016.258 [keepstation:PowerOnly:D] Stopped 2025-08-22T04:46:56.258Z,1755838016.258 [keepstation:PowerOnly:C] Stopped 2025-08-22T04:46:56.258Z,1755838016.258 [keepstation:PowerOnly:B] Stopped 2025-08-22T04:46:56.258Z,1755838016.258 [keepstation:PowerOnly:A] Stopped 2025-08-22T04:46:56.258Z,1755838016.258 [keepstation:BackseatDriver] Running Loop=1 2025-08-22T04:46:56.258Z,1755838016.258 [keepstation:StandardEnvelopes] Running Loop=1 2025-08-22T04:46:56.258Z,1755838016.258 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2025-08-22T04:46:56.259Z,1755838016.259 [keepstation:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2025-08-22T04:46:56.260Z,1755838016.260 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2025-08-22T04:46:56.261Z,1755838016.261 [keepstation:B] Stopped 2025-08-22T04:46:56.261Z,1755838016.261 [keepstation:D] Running Loop=1 2025-08-22T04:46:56.648Z,1755838016.648 [keepstation:D] Stopped 2025-08-22T04:46:56.648Z,1755838016.648 [keepstation:E] Running Loop=1 2025-08-22T04:46:57.051Z,1755838017.051 [keepstation:E] Stopped 2025-08-22T04:46:57.051Z,1755838017.051 [keepstation:StartingMission] Running Loop=1 2025-08-22T04:46:57.051Z,1755838017.051 [keepstation:StartingMission](DEBUG): Aggregate::initialize keepstation:StartingMission 2025-08-22T04:46:57.464Z,1755838017.464 [keepstation:SurfaceComms] Running Loop=1 2025-08-22T04:46:57.464Z,1755838017.464 [keepstation:SurfaceComms](DEBUG): Aggregate::initialize keepstation:SurfaceComms 2025-08-22T04:46:57.464Z,1755838017.464 [keepstation:SurfaceComms:A] Running Loop=1 2025-08-22T04:46:57.465Z,1755838017.465 [keepstation:SurfaceComms:A] Stopped 2025-08-22T04:46:57.465Z,1755838017.465 [keepstation:SurfaceComms:B] Running Loop=1 2025-08-22T04:46:57.465Z,1755838017.465 [keepstation:SurfaceComms:B](DEBUG): Aggregate::initialize keepstation:SurfaceComms:B 2025-08-22T04:46:57.865Z,1755838017.865 [keepstation:NeedComms] Running Loop=1 2025-08-22T04:46:57.865Z,1755838017.865 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms 2025-08-22T04:46:57.865Z,1755838017.865 [keepstation:NeedComms:B.GoToSurface] Running Loop=1 2025-08-22T04:46:57.865Z,1755838017.865 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-08-22T04:46:57.866Z,1755838017.866 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2025-08-22T04:46:57.866Z,1755838017.866 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2025-08-22T04:46:57.866Z,1755838017.866 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2025-08-22T04:46:57.867Z,1755838017.867 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds. 2025-08-22T04:46:57.867Z,1755838017.867 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-08-22T04:46:57.868Z,1755838017.868 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-08-22T04:46:57.868Z,1755838017.868 [keepstation:NeedComms:A] Running Loop=1 2025-08-22T04:46:57.869Z,1755838017.869 [keepstation:NeedComms:A](INFO): last time_fix was: 1755837090.000000 second since 1970/01/01T00:00:00Z 2025-08-22T04:46:57.869Z,1755838017.869 [keepstation:NeedComms:A] Stopped 2025-08-22T04:46:58.280Z,1755838018.280 [keepstation:NeedComms:C] Running Loop=1 2025-08-22T04:46:58.665Z,1755838018.665 [keepstation:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-08-22T04:47:00.273Z,1755838020.273 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,044700.00,A,3646.60010,N,12201.95803,W,0.214,128.50,220825,,,A*7A 2025-08-22T04:47:00.276Z,1755838020.276 [NAL9602](INFO): GPS fix at 20250822T044700: (36.776668, -122.032634) 2025-08-22T04:47:00.289Z,1755838020.289 [UniversalFixResidualReporter](INFO): Fix residual: 32.3 %DT, over the last 1030.6 m. Residual distance 333.2 m at bearing -20.4 degrees. Fix at (36.7767, -122.0326) with 205.6 m made good. 2025-08-22T04:47:00.292Z,1755838020.292 [keepstation:NeedComms:C] Stopped 2025-08-22T04:47:00.292Z,1755838020.292 [keepstation:NeedComms:D] Running Loop=1 2025-08-22T04:47:00.707Z,1755838020.707 [keepstation:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-08-22T04:47:09.018Z,1755838029.018 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20250822T043000/Courier0005.lzma 2025-08-22T04:47:15.625Z,1755838035.625 [NAL9602](INFO): SBD MO Status=0, MOMSN=22220, MT Status=0, MTMSN=0 2025-08-22T04:47:15.625Z,1755838035.625 [NAL9602](INFO): No messages in MT queue 2025-08-22T04:47:20.085Z,1755838040.085 [DataOverHttps](INFO): Moved sent file to Logs/20250822T043000/Courier0005.lzma.bak 2025-08-22T04:47:20.085Z,1755838040.085 [DataOverHttps](INFO): SBD MOMSN=25879757 2025-08-22T04:47:46.328Z,1755838066.328 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-22T04:47:46.792Z,1755838066.792 [DataOverHttps](INFO): Sending 1206 bytes from file Logs/20250822T043000/Express0004.lzma 2025-08-22T04:47:57.841Z,1755838077.841 [DataOverHttps](INFO): Moved sent file to Logs/20250822T043000/Express0004.lzma.bak 2025-08-22T04:47:57.841Z,1755838077.841 [DataOverHttps](INFO): SBD MOMSN=25879771 2025-08-22T04:47:59.303Z,1755838079.303 [keepstation:NeedComms:D] Stopped 2025-08-22T04:47:59.303Z,1755838079.303 [keepstation:NeedComms:E] Running Loop=1 2025-08-22T04:47:59.676Z,1755838079.676 [keepstation:NeedComms:E](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-08-22T04:48:01.292Z,1755838081.292 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,044801.00,A,3646.59526,N,12201.96127,W,0.272,262.99,220825,,,A*7A 2025-08-22T04:48:01.294Z,1755838081.294 [NAL9602](INFO): GPS fix at 20250822T044801: (36.776588, -122.032688) 2025-08-22T04:48:01.343Z,1755838081.343 [keepstation:NeedComms:E] Stopped 2025-08-22T04:48:01.352Z,1755838081.352 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms 2025-08-22T04:48:01.352Z,1755838081.352 [keepstation:NeedComms] Stopped 2025-08-22T04:48:01.352Z,1755838081.352 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms 2025-08-22T04:48:01.352Z,1755838081.352 [keepstation:NeedComms:B.GoToSurface] Stopped 2025-08-22T04:48:01.352Z,1755838081.352 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-08-22T04:48:01.745Z,1755838081.745 [keepstation:SurfaceComms:B](INFO): Completed keepstation:SurfaceComms:B 2025-08-22T04:48:01.745Z,1755838081.745 [keepstation:SurfaceComms:B] Stopped 2025-08-22T04:48:01.745Z,1755838081.745 [keepstation:SurfaceComms:B](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:B 2025-08-22T04:48:01.745Z,1755838081.745 [keepstation:SurfaceComms:setTransit] Running Loop=1 2025-08-22T04:48:01.745Z,1755838081.745 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setTransit 2025-08-22T04:48:01.745Z,1755838081.745 [keepstation:SurfaceComms:setTransit:A] Running Loop=1 2025-08-22T04:48:02.121Z,1755838082.121 [keepstation:SurfaceComms:setTransit] Stopped 2025-08-22T04:48:02.121Z,1755838082.121 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setTransit 2025-08-22T04:48:02.121Z,1755838082.121 [keepstation:SurfaceComms:setTransit:A] Stopped 2025-08-22T04:48:02.121Z,1755838082.121 [keepstation:SurfaceComms:setStation] Running Loop=1 2025-08-22T04:48:02.122Z,1755838082.122 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setStation 2025-08-22T04:48:02.122Z,1755838082.122 [keepstation:SurfaceComms:setStation:A] Running Loop=1 2025-08-22T04:48:02.527Z,1755838082.527 [keepstation:SurfaceComms:setStation] Stopped 2025-08-22T04:48:02.528Z,1755838082.528 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setStation 2025-08-22T04:48:02.528Z,1755838082.528 [keepstation:SurfaceComms:setStation:A] Stopped 2025-08-22T04:48:02.528Z,1755838082.528 [keepstation:SurfaceComms:setSink] Running Loop=1 2025-08-22T04:48:02.528Z,1755838082.528 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setSink 2025-08-22T04:48:02.528Z,1755838082.528 [keepstation:SurfaceComms:setSink:A] Running Loop=1 2025-08-22T04:48:02.950Z,1755838082.950 [keepstation:SurfaceComms:setSink:A] Stopped 2025-08-22T04:48:02.950Z,1755838082.950 [keepstation:SurfaceComms:setSink](INFO): Completed keepstation:SurfaceComms:setSink 2025-08-22T04:48:02.950Z,1755838082.950 [keepstation:SurfaceComms:setSink] Stopped 2025-08-22T04:48:02.950Z,1755838082.950 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setSink 2025-08-22T04:48:02.950Z,1755838082.950 [keepstation:SurfaceComms](INFO): Completed keepstation:SurfaceComms 2025-08-22T04:48:02.951Z,1755838082.951 [keepstation:SurfaceComms] Stopped 2025-08-22T04:48:02.951Z,1755838082.951 [keepstation:SurfaceComms](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms 2025-08-22T04:48:03.336Z,1755838083.336 [keepstation:StartingMission](INFO): Completed keepstation:StartingMission 2025-08-22T04:48:03.336Z,1755838083.336 [keepstation:StartingMission] Stopped 2025-08-22T04:48:03.336Z,1755838083.336 [keepstation:StartingMission](DEBUG): Aggregate::uninitialize keepstation:StartingMission 2025-08-22T04:48:03.336Z,1755838083.336 [keepstation:TransitToStation] Running Loop=1 2025-08-22T04:48:03.337Z,1755838083.337 [keepstation:TransitToStation](DEBUG): Aggregate::initialize keepstation:TransitToStation 2025-08-22T04:48:03.337Z,1755838083.337 [keepstation:TransitToStation:Dive] Running Loop=1 2025-08-22T04:48:03.337Z,1755838083.337 [keepstation:TransitToStation:Dive](DEBUG): Aggregate::initialize keepstation:TransitToStation:Dive 2025-08-22T04:48:03.337Z,1755838083.337 [keepstation:TransitToStation:Dive:A] Running Loop=1 2025-08-22T04:48:03.337Z,1755838083.337 [keepstation:TransitToStation:Dive:A](DEBUG): Aggregate::initialize keepstation:TransitToStation:Dive:A 2025-08-22T04:48:03.337Z,1755838083.337 [keepstation:TransitToStation:Wpt1.Waypoint] Running Loop=1 2025-08-22T04:48:03.337Z,1755838083.337 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent. 2025-08-22T04:48:03.339Z,1755838083.339 [keepstation:TransitToStation:Wpt1.Waypoint](IMPORTANT): Navigating to waypoint: 36.841160,-122.155777 2025-08-22T04:48:03.736Z,1755838083.736 [keepstation:TransitToStation:Wpt1.Waypoint](INFO): Navigating to waypoint: 36.841160,-122.155777 2025-08-22T04:48:03.737Z,1755838083.737 [keepstation:TransitToStation:Dive] Running Loop=1 2025-08-22T04:48:03.737Z,1755838083.737 [keepstation:DiveCmd] Running Loop=1 2025-08-22T04:48:03.737Z,1755838083.737 [keepstation:DiveCmd](DEBUG): Aggregate::initialize keepstation:DiveCmd 2025-08-22T04:48:03.737Z,1755838083.737 [keepstation:DiveCmd:SurfaceSink] Running Loop=1 2025-08-22T04:48:03.737Z,1755838083.737 [keepstation:DiveCmd:SurfaceSink](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink 2025-08-22T04:48:03.738Z,1755838083.738 [keepstation:DiveCmd:SurfaceSink:sink] Running Loop=1 2025-08-22T04:48:03.738Z,1755838083.738 [keepstation:DiveCmd:SurfaceSink:sink](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink 2025-08-22T04:48:03.738Z,1755838083.738 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy] Running Loop=1 2025-08-22T04:48:03.738Z,1755838083.738 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Initialize Buoyancy Component. 2025-08-22T04:48:03.738Z,1755838083.738 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed] Running Loop=1 2025-08-22T04:48:03.738Z,1755838083.738 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Initialize. 2025-08-22T04:48:03.738Z,1755838083.738 [keepstation:DiveCmd:SurfaceSink:sink:C] Running Loop=1 2025-08-22T04:48:03.738Z,1755838083.738 [keepstation:DiveCmd:TransitToStation] Running Loop=1 2025-08-22T04:48:03.738Z,1755838083.738 [keepstation:DiveCmd:TransitToStation](DEBUG): Aggregate::initialize keepstation:DiveCmd:TransitToStation 2025-08-22T04:48:03.739Z,1755838083.739 [keepstation:DiveCmd:TransitToStation:dive] Running Loop=1 2025-08-22T04:48:03.739Z,1755838083.739 [keepstation:DiveCmd:TransitToStation:dive](DEBUG): Aggregate::initialize keepstation:DiveCmd:TransitToStation:dive 2025-08-22T04:48:03.739Z,1755838083.739 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy] Running Loop=1 2025-08-22T04:48:03.739Z,1755838083.739 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Initialize Buoyancy Component. 2025-08-22T04:48:03.739Z,1755838083.739 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch] Running Loop=1 2025-08-22T04:48:03.739Z,1755838083.739 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch](DEBUG): Initialize. 2025-08-22T04:48:03.743Z,1755838083.743 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed] Running Loop=1 2025-08-22T04:48:03.743Z,1755838083.743 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Initialize. 2025-08-22T04:48:03.744Z,1755838083.744 [keepstation:DiveCmd:StationKeep] Running Loop=1 2025-08-22T04:48:03.744Z,1755838083.744 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::initialize keepstation:DiveCmd:StationKeep 2025-08-22T04:48:03.744Z,1755838083.744 [keepstation:DiveCmd:StationKeep:A] Running Loop=1 2025-08-22T04:48:03.744Z,1755838083.744 [keepstation:DiveCmd:StationKeep:B.Pitch] Running Loop=1 2025-08-22T04:48:03.744Z,1755838083.744 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Initialize. 2025-08-22T04:48:03.744Z,1755838083.744 [keepstation:DiveCmd:StationKeep:C.KeepStation] Running Loop=1 2025-08-22T04:48:03.744Z,1755838083.744 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Initialize KeepStationComponent. 2025-08-22T04:48:03.745Z,1755838083.745 [keepstation:DiveCmd:StationKeep] Stopped 2025-08-22T04:48:03.745Z,1755838083.745 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:StationKeep 2025-08-22T04:48:03.745Z,1755838083.745 [keepstation:DiveCmd:StationKeep:A] Stopped 2025-08-22T04:48:03.745Z,1755838083.745 [keepstation:DiveCmd:StationKeep:B.Pitch] Stopped 2025-08-22T04:48:03.745Z,1755838083.745 [keepstation:DiveCmd:StationKeep:C.KeepStation] Stopped 2025-08-22T04:48:03.745Z,1755838083.745 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Uninitialize KeepStationComponent. 2025-08-22T04:48:03.745Z,1755838083.745 [keepstation:DiveCmd:TransitToStation] Stopped 2025-08-22T04:48:03.745Z,1755838083.745 [keepstation:DiveCmd:TransitToStation](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:TransitToStation 2025-08-22T04:48:03.746Z,1755838083.746 [keepstation:DiveCmd:TransitToStation:dive] Stopped 2025-08-22T04:48:03.746Z,1755838083.746 [keepstation:DiveCmd:TransitToStation:dive](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:TransitToStation:dive 2025-08-22T04:48:03.746Z,1755838083.746 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy] Stopped 2025-08-22T04:48:03.746Z,1755838083.746 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2025-08-22T04:48:03.746Z,1755838083.746 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch] Stopped 2025-08-22T04:48:03.746Z,1755838083.746 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed] Stopped 2025-08-22T04:48:03.746Z,1755838083.746 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Uninitialize. 2025-08-22T04:48:03.746Z,1755838083.746 [keepstation:DiveCmd:SurfaceSink] Running Loop=1 2025-08-22T04:48:03.747Z,1755838083.747 [keepstation:DiveCmd:SurfaceSink:sink:C](INFO): Sinking to 10.000000 m 2025-08-22T04:48:03.747Z,1755838083.747 [keepstation:DiveCmd:SurfaceSink:sink:C] Stopped 2025-08-22T04:48:03.747Z,1755838083.747 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch] Running Loop=1 2025-08-22T04:48:03.747Z,1755838083.747 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch](DEBUG): Initialize. 2025-08-22T04:48:03.747Z,1755838083.747 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed] Running Loop=1 2025-08-22T04:48:03.752Z,1755838083.752 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy] Running Loop=1 2025-08-22T04:48:03.778Z,1755838083.778 [HorizontalControl](DEBUG): kpHeading = 0.400000 2025-08-22T04:48:03.779Z,1755838083.779 [HorizontalControl](DEBUG): kiHeading = 0.001000 2025-08-22T04:48:03.779Z,1755838083.779 [HorizontalControl](DEBUG): kdHeading = 0.050000 2025-08-22T04:48:45.722Z,1755838125.722 [DVL_micro](ERROR): Failed to parse: :RD,+0000.30,+9999.99,+0000.30,+0000.68 2025-08-22T04:48:59.500Z,1755838139.500 [NAL9602](INFO): SBD MO Status=0, MOMSN=22221, MT Status=0, MTMSN=0 2025-08-22T04:48:59.500Z,1755838139.500 [NAL9602](INFO): No messages in MT queue 2025-08-22T04:49:30.153Z,1755838170.153 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-22T04:50:31.400Z,1755838231.400 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T04:51:02.524Z,1755838262.524 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T04:51:03.896Z,1755838263.896 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch](INFO): Timed out from 2025-08-22T04:48:03.7Z 2025-08-22T04:51:03.896Z,1755838263.896 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout] Running Loop=1 2025-08-22T04:51:03.896Z,1755838263.896 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout 2025-08-22T04:51:03.897Z,1755838263.897 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout:A] Running Loop=1 2025-08-22T04:51:03.898Z,1755838263.898 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout:A](IMPORTANT): Timed out while trying to reach target sink depth at current depth of 1.028336 m 2025-08-22T04:51:03.900Z,1755838263.900 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout:A] Stopped 2025-08-22T04:51:03.900Z,1755838263.900 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout](INFO): Completed keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout 2025-08-22T04:51:03.900Z,1755838263.900 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch] Stopped 2025-08-22T04:51:03.900Z,1755838263.900 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit] Running Loop=1 2025-08-22T04:51:03.900Z,1755838263.900 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit 2025-08-22T04:51:03.901Z,1755838263.901 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit:A] Running Loop=1 2025-08-22T04:51:04.302Z,1755838264.302 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit:A] Stopped 2025-08-22T04:51:04.302Z,1755838264.302 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit](INFO): Completed keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit 2025-08-22T04:51:04.302Z,1755838264.302 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit] Stopped 2025-08-22T04:51:04.302Z,1755838264.302 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit 2025-08-22T04:51:04.302Z,1755838264.302 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation] Running Loop=1 2025-08-22T04:51:04.302Z,1755838264.302 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink:sinkToStation 2025-08-22T04:51:04.303Z,1755838264.303 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation:A] Running Loop=1 2025-08-22T04:51:04.721Z,1755838264.721 [keepstation:DiveCmd:TransitToStation] Running Loop=1 2025-08-22T04:51:04.721Z,1755838264.721 [keepstation:DiveCmd:TransitToStation](DEBUG): Aggregate::initialize keepstation:DiveCmd:TransitToStation 2025-08-22T04:51:04.721Z,1755838264.721 [keepstation:DiveCmd:TransitToStation:dive] Running Loop=1 2025-08-22T04:51:04.722Z,1755838264.722 [keepstation:DiveCmd:TransitToStation:dive](DEBUG): Aggregate::initialize keepstation:DiveCmd:TransitToStation:dive 2025-08-22T04:51:04.722Z,1755838264.722 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy] Running Loop=1 2025-08-22T04:51:04.722Z,1755838264.722 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Initialize Buoyancy Component. 2025-08-22T04:51:04.722Z,1755838264.722 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch] Running Loop=1 2025-08-22T04:51:04.722Z,1755838264.722 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch](DEBUG): Initialize. 2025-08-22T04:51:04.722Z,1755838264.722 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed] Running Loop=1 2025-08-22T04:51:04.722Z,1755838264.722 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Initialize. 2025-08-22T04:51:04.722Z,1755838264.722 [keepstation:DiveCmd:TransitToStation] Running Loop=1 2025-08-22T04:51:04.722Z,1755838264.722 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed] Running Loop=1 2025-08-22T04:51:04.723Z,1755838264.723 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch] Running Loop=1 2025-08-22T04:51:04.723Z,1755838264.723 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy] Running Loop=1 2025-08-22T04:51:04.727Z,1755838264.727 [keepstation:DiveCmd:SurfaceSink] Stopped 2025-08-22T04:51:04.727Z,1755838264.727 [keepstation:DiveCmd:SurfaceSink](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink 2025-08-22T04:51:04.728Z,1755838264.728 [keepstation:DiveCmd:SurfaceSink:sink] Stopped 2025-08-22T04:51:04.728Z,1755838264.728 [keepstation:DiveCmd:SurfaceSink:sink](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink:sink 2025-08-22T04:51:04.728Z,1755838264.728 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy] Stopped 2025-08-22T04:51:04.728Z,1755838264.728 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2025-08-22T04:51:04.728Z,1755838264.728 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed] Stopped 2025-08-22T04:51:04.728Z,1755838264.728 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Uninitialize. 2025-08-22T04:51:04.728Z,1755838264.728 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation] Stopped 2025-08-22T04:51:04.728Z,1755838264.728 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink:sink:sinkToStation 2025-08-22T04:51:04.728Z,1755838264.728 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation:A] Stopped 2025-08-22T04:51:33.648Z,1755838293.648 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T04:52:04.008Z,1755838324.008 [Radio_Surface](INFO): Powering down 2025-08-22T04:52:04.772Z,1755838324.772 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T04:52:05.776Z,1755838325.776 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2025-08-22T04:52:18.831Z,1755838338.831 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.736877 2025-08-22T05:05:20.051Z,1755839120.051 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+9999.99,+9999.99 2025-08-22T05:06:41.725Z,1755839201.725 [DVL_micro](ERROR): only read 3 of 4 data items for bottom velocity. Device response is::BI,-00297,+02446,-00D,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2025-08-22T05:06:41.725Z,1755839201.725 [DVL_micro](ERROR): Failed to parse: :BI,-00297,+02446,-00D,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2025-08-22T05:18:48.855Z,1755839928.855 [DVL_micro](ERROR): Failed to parse: :WI,-00292,+00883,-00104,+00000,A 2025-08-22T05:34:22.089Z,1755840862.089 [BPC1](ERROR): Battery stick #2 (s/n: 0124) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-08-22T05:34:22.090Z,1755840862.090 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6. 2025-08-22T05:34:22.093Z,1755840862.093 [BPC1](INFO): Received data from all battery sticks. 2025-08-22T05:48:01.666Z,1755841681.666 [keepstation:SurfaceComms] Running Loop=1 2025-08-22T05:48:01.667Z,1755841681.667 [keepstation:SurfaceComms](DEBUG): Aggregate::initialize keepstation:SurfaceComms 2025-08-22T05:48:01.667Z,1755841681.667 [keepstation:SurfaceComms:A] Running Loop=1 2025-08-22T05:48:01.669Z,1755841681.669 [keepstation:SurfaceComms:A] Stopped 2025-08-22T05:48:01.669Z,1755841681.669 [keepstation:SurfaceComms:B] Running Loop=1 2025-08-22T05:48:01.669Z,1755841681.669 [keepstation:SurfaceComms:B](DEBUG): Aggregate::initialize keepstation:SurfaceComms:B 2025-08-22T05:48:01.670Z,1755841681.670 [keepstation:NeedComms] Running Loop=1 2025-08-22T05:48:01.671Z,1755841681.671 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms 2025-08-22T05:48:01.671Z,1755841681.671 [keepstation:NeedComms:B.GoToSurface] Running Loop=1 2025-08-22T05:48:01.671Z,1755841681.671 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-08-22T05:48:01.671Z,1755841681.671 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2025-08-22T05:48:01.672Z,1755841681.672 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2025-08-22T05:48:01.672Z,1755841681.672 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2025-08-22T05:48:01.672Z,1755841681.672 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds. 2025-08-22T05:48:01.673Z,1755841681.673 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-08-22T05:48:01.673Z,1755841681.673 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-08-22T05:48:01.673Z,1755841681.673 [keepstation:NeedComms:A] Running Loop=1 2025-08-22T05:48:01.675Z,1755841681.675 [keepstation:NeedComms:A](INFO): last time_fix was: 1755838081.000000 second since 1970/01/01T00:00:00Z 2025-08-22T05:48:01.675Z,1755841681.675 [keepstation:NeedComms:A] Stopped 2025-08-22T05:48:02.088Z,1755841682.088 [keepstation:TransitToStation:Dive] Stopped 2025-08-22T05:48:02.088Z,1755841682.088 [keepstation:TransitToStation:Dive](DEBUG): Aggregate::uninitialize keepstation:TransitToStation:Dive 2025-08-22T05:48:02.088Z,1755841682.088 [keepstation:TransitToStation:Dive:A] Stopped 2025-08-22T05:48:02.088Z,1755841682.088 [keepstation:TransitToStation:Dive:A](DEBUG): Aggregate::uninitialize keepstation:TransitToStation:Dive:A 2025-08-22T05:48:02.089Z,1755841682.089 [keepstation:DiveCmd:TransitToStation] Stopped 2025-08-22T05:48:02.089Z,1755841682.089 [keepstation:DiveCmd:TransitToStation](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:TransitToStation 2025-08-22T05:48:02.089Z,1755841682.089 [keepstation:DiveCmd:TransitToStation:dive] Stopped 2025-08-22T05:48:02.089Z,1755841682.089 [keepstation:DiveCmd:TransitToStation:dive](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:TransitToStation:dive 2025-08-22T05:48:02.089Z,1755841682.089 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy] Stopped 2025-08-22T05:48:02.089Z,1755841682.089 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2025-08-22T05:48:02.089Z,1755841682.089 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch] Stopped 2025-08-22T05:48:02.089Z,1755841682.089 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed] Stopped 2025-08-22T05:48:02.089Z,1755841682.089 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Uninitialize. 2025-08-22T05:48:37.963Z,1755841717.963 [DVL_micro](ERROR): only read 1 of 4 data items for bottom velocity. Device response is::BI,-00,I 2025-08-22T05:48:37.963Z,1755841717.963 [DVL_micro](ERROR): Failed to parse: :BI,-00,I 2025-08-22T05:49:04.459Z,1755841744.459 [keepstation:NeedComms:C] Running Loop=1 2025-08-22T05:49:04.984Z,1755841744.984 [Radio_Surface](INFO): Powering up 2025-08-22T05:49:10.892Z,1755841750.892 [DataOverHttps](INFO): Radio surface powered ON. 2025-08-22T05:49:41.012Z,1755841781.012 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T05:49:43.821Z,1755841783.821 [NAL9602](INFO): SBD MO Status=2, MOMSN=22222, MT Status=2, MTMSN=0 2025-08-22T05:49:43.821Z,1755841783.821 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-22T05:50:01.598Z,1755841801.598 [NAL9602](INFO): SBD MO Status=0, MOMSN=22222, MT Status=0, MTMSN=0 2025-08-22T05:50:01.598Z,1755841801.598 [NAL9602](INFO): No messages in MT queue 2025-08-22T05:50:02.802Z,1755841802.802 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,055002.00,A,3647.36164,N,12203.76903,W,1.186,141.16,220825,,,A*75 2025-08-22T05:50:02.804Z,1755841802.804 [NAL9602](INFO): GPS fix at 20250822T055002: (36.789361, -122.062817) 2025-08-22T05:50:02.816Z,1755841802.816 [UniversalFixResidualReporter](INFO): Fix residual: 8.1 %DT, over the last 3760.2 m. Residual distance 304.3 m at bearing 8.4 degrees. Fix at (36.7894, -122.0628) with 3035.9 m made good. 2025-08-22T05:50:02.818Z,1755841802.818 [keepstation:TransitToStation:Wpt1.Waypoint](INFO): Navigating to waypoint: 36.841160,-122.155777 2025-08-22T05:50:02.821Z,1755841802.821 [keepstation:NeedComms:C] Stopped 2025-08-22T05:50:02.821Z,1755841802.821 [keepstation:NeedComms:D] Running Loop=1 2025-08-22T05:50:12.136Z,1755841812.136 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T05:50:31.453Z,1755841831.453 [NAL9602](INFO): SBD MO Status=1, MOMSN=22223, MT Status=0, MTMSN=0 2025-08-22T05:50:31.512Z,1755841831.512 [NAL9602](INFO): Sent 216 bytes from file Logs/20250822T043000/Courier0009.lzma 2025-08-22T05:50:31.512Z,1755841831.512 [NAL9602](INFO): Packets left to send: 0 2025-08-22T05:50:43.260Z,1755841843.260 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T05:50:44.318Z,1755841844.318 [NAL9602](INFO): SBD MO Status=1, MOMSN=22224, MT Status=0, MTMSN=0 2025-08-22T05:50:44.372Z,1755841844.372 [NAL9602](INFO): Sent 332 bytes from file Logs/20250822T043000/Express0011.lzma 2025-08-22T05:50:44.372Z,1755841844.372 [NAL9602](INFO): Packets left to send: 2 2025-08-22T05:50:56.720Z,1755841856.720 [NAL9602](INFO): SBD MO Status=1, MOMSN=22225, MT Status=0, MTMSN=0 2025-08-22T05:50:56.772Z,1755841856.772 [NAL9602](INFO): Sent 332 bytes from file Logs/20250822T043000/Express0011.lzma 2025-08-22T05:50:56.772Z,1755841856.772 [NAL9602](INFO): Packets left to send: 1 2025-08-22T05:51:07.879Z,1755841867.879 [NAL9602](INFO): SBD MO Status=1, MOMSN=22226, MT Status=0, MTMSN=0 2025-08-22T05:51:07.936Z,1755841867.936 [NAL9602](INFO): Sent 222 bytes from file Logs/20250822T043000/Express0011.lzma 2025-08-22T05:51:07.936Z,1755841867.936 [NAL9602](INFO): Packets left to send: 0 2025-08-22T05:51:14.396Z,1755841874.396 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T05:51:19.182Z,1755841879.182 [NAL9602](INFO): SBD MO Status=0, MOMSN=22227, MT Status=0, MTMSN=0 2025-08-22T05:51:19.290Z,1755841879.290 [keepstation:NeedComms:D] Stopped 2025-08-22T05:51:19.290Z,1755841879.290 [keepstation:NeedComms:E] Running Loop=1 2025-08-22T05:51:21.614Z,1755841881.614 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,055121.00,A,3647.35533,N,12203.76981,W,0.914,204.87,220825,,,A*72 2025-08-22T05:51:21.618Z,1755841881.618 [NAL9602](INFO): GPS fix at 20250822T055121: (36.789256, -122.062830) 2025-08-22T05:51:21.681Z,1755841881.681 [keepstation:TransitToStation:Wpt1.Waypoint](INFO): Navigating to waypoint: 36.841160,-122.155777 2025-08-22T05:51:21.691Z,1755841881.691 [keepstation:NeedComms:E] Stopped 2025-08-22T05:51:21.696Z,1755841881.696 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms 2025-08-22T05:51:21.696Z,1755841881.696 [keepstation:NeedComms] Stopped 2025-08-22T05:51:21.697Z,1755841881.697 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms 2025-08-22T05:51:21.697Z,1755841881.697 [keepstation:NeedComms:B.GoToSurface] Stopped 2025-08-22T05:51:21.697Z,1755841881.697 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-08-22T05:51:22.064Z,1755841882.064 [keepstation:SurfaceComms:B](INFO): Completed keepstation:SurfaceComms:B 2025-08-22T05:51:22.064Z,1755841882.064 [keepstation:SurfaceComms:B] Stopped 2025-08-22T05:51:22.064Z,1755841882.064 [keepstation:SurfaceComms:B](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:B 2025-08-22T05:51:22.064Z,1755841882.064 [keepstation:SurfaceComms:setTransit] Running Loop=1 2025-08-22T05:51:22.064Z,1755841882.064 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setTransit 2025-08-22T05:51:22.064Z,1755841882.064 [keepstation:SurfaceComms:setTransit:A] Running Loop=1 2025-08-22T05:51:22.429Z,1755841882.429 [keepstation:SurfaceComms:setTransit] Stopped 2025-08-22T05:51:22.429Z,1755841882.429 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setTransit 2025-08-22T05:51:22.429Z,1755841882.429 [keepstation:SurfaceComms:setTransit:A] Stopped 2025-08-22T05:51:22.429Z,1755841882.429 [keepstation:SurfaceComms:setStation] Running Loop=1 2025-08-22T05:51:22.429Z,1755841882.429 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setStation 2025-08-22T05:51:22.429Z,1755841882.429 [keepstation:SurfaceComms:setStation:A] Running Loop=1 2025-08-22T05:51:22.843Z,1755841882.843 [keepstation:SurfaceComms:setStation] Stopped 2025-08-22T05:51:22.843Z,1755841882.843 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setStation 2025-08-22T05:51:22.843Z,1755841882.843 [keepstation:SurfaceComms:setStation:A] Stopped 2025-08-22T05:51:22.843Z,1755841882.843 [keepstation:SurfaceComms:setSink] Running Loop=1 2025-08-22T05:51:22.843Z,1755841882.843 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setSink 2025-08-22T05:51:22.844Z,1755841882.844 [keepstation:SurfaceComms:setSink:A] Running Loop=1 2025-08-22T05:51:23.233Z,1755841883.233 [keepstation:SurfaceComms:setSink:A] Stopped 2025-08-22T05:51:23.233Z,1755841883.233 [keepstation:SurfaceComms:setSink](INFO): Completed keepstation:SurfaceComms:setSink 2025-08-22T05:51:23.233Z,1755841883.233 [keepstation:SurfaceComms:setSink] Stopped 2025-08-22T05:51:23.233Z,1755841883.233 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setSink 2025-08-22T05:51:23.233Z,1755841883.233 [keepstation:SurfaceComms](INFO): Completed keepstation:SurfaceComms 2025-08-22T05:51:23.233Z,1755841883.233 [keepstation:SurfaceComms] Stopped 2025-08-22T05:51:23.233Z,1755841883.233 [keepstation:SurfaceComms](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms 2025-08-22T05:51:23.676Z,1755841883.676 [keepstation:TransitToStation:Dive] Running Loop=1 2025-08-22T05:51:23.676Z,1755841883.676 [keepstation:TransitToStation:Dive](DEBUG): Aggregate::initialize keepstation:TransitToStation:Dive 2025-08-22T05:51:23.676Z,1755841883.676 [keepstation:TransitToStation:Dive:A] Running Loop=1 2025-08-22T05:51:23.676Z,1755841883.676 [keepstation:TransitToStation:Dive:A](DEBUG): Aggregate::initialize keepstation:TransitToStation:Dive:A 2025-08-22T05:51:23.677Z,1755841883.677 [keepstation:DiveCmd:SurfaceSink] Running Loop=1 2025-08-22T05:51:23.677Z,1755841883.677 [keepstation:DiveCmd:SurfaceSink](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink 2025-08-22T05:51:23.677Z,1755841883.677 [keepstation:DiveCmd:SurfaceSink:sink] Running Loop=1 2025-08-22T05:51:23.678Z,1755841883.678 [keepstation:DiveCmd:SurfaceSink:sink](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink 2025-08-22T05:51:23.678Z,1755841883.678 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy] Running Loop=1 2025-08-22T05:51:23.678Z,1755841883.678 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Initialize Buoyancy Component. 2025-08-22T05:51:23.678Z,1755841883.678 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed] Running Loop=1 2025-08-22T05:51:23.678Z,1755841883.678 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Initialize. 2025-08-22T05:51:23.678Z,1755841883.678 [keepstation:DiveCmd:SurfaceSink:sink:C] Running Loop=1 2025-08-22T05:51:23.684Z,1755841883.684 [keepstation:DiveCmd:SurfaceSink:sink:C](INFO): Sinking to 10.000000 m 2025-08-22T05:51:23.684Z,1755841883.684 [keepstation:DiveCmd:SurfaceSink:sink:C] Stopped 2025-08-22T05:51:23.685Z,1755841883.685 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch] Running Loop=1 2025-08-22T05:51:23.685Z,1755841883.685 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch](DEBUG): Initialize. 2025-08-22T05:51:33.493Z,1755841893.493 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003610 2025-08-22T05:51:53.266Z,1755841913.266 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-22T05:53:16.104Z,1755841996.104 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T05:53:47.232Z,1755842027.232 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T05:54:11.652Z,1755842051.652 [Radio_Surface](INFO): Powering down 2025-08-22T05:54:18.368Z,1755842058.368 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T05:54:19.372Z,1755842059.372 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2025-08-22T05:54:23.971Z,1755842063.971 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch](INFO): Timed out from 2025-08-22T05:51:23.7Z 2025-08-22T05:54:23.971Z,1755842063.971 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout] Running Loop=1 2025-08-22T05:54:23.971Z,1755842063.971 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout 2025-08-22T05:54:23.972Z,1755842063.972 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout:A] Running Loop=1 2025-08-22T05:54:23.973Z,1755842063.973 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout:A](IMPORTANT): Timed out while trying to reach target sink depth at current depth of 6.436757 m 2025-08-22T05:54:23.996Z,1755842063.996 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout:A] Stopped 2025-08-22T05:54:23.996Z,1755842063.996 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout](INFO): Completed keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout 2025-08-22T05:54:23.996Z,1755842063.996 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch] Stopped 2025-08-22T05:54:23.996Z,1755842063.996 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit] Running Loop=1 2025-08-22T05:54:23.996Z,1755842063.996 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit 2025-08-22T05:54:23.996Z,1755842063.996 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit:A] Running Loop=1 2025-08-22T05:54:24.408Z,1755842064.408 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit:A] Stopped 2025-08-22T05:54:24.408Z,1755842064.408 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit](INFO): Completed keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit 2025-08-22T05:54:24.408Z,1755842064.408 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit] Stopped 2025-08-22T05:54:24.409Z,1755842064.409 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit 2025-08-22T05:54:24.409Z,1755842064.409 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation] Running Loop=1 2025-08-22T05:54:24.409Z,1755842064.409 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink:sinkToStation 2025-08-22T05:54:24.409Z,1755842064.409 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation:A] Running Loop=1 2025-08-22T05:54:24.767Z,1755842064.767 [keepstation:DiveCmd:TransitToStation] Running Loop=1 2025-08-22T05:54:24.768Z,1755842064.768 [keepstation:DiveCmd:TransitToStation](DEBUG): Aggregate::initialize keepstation:DiveCmd:TransitToStation 2025-08-22T05:54:24.768Z,1755842064.768 [keepstation:DiveCmd:TransitToStation:dive] Running Loop=1 2025-08-22T05:54:24.768Z,1755842064.768 [keepstation:DiveCmd:TransitToStation:dive](DEBUG): Aggregate::initialize keepstation:DiveCmd:TransitToStation:dive 2025-08-22T05:54:24.768Z,1755842064.768 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy] Running Loop=1 2025-08-22T05:54:24.768Z,1755842064.768 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Initialize Buoyancy Component. 2025-08-22T05:54:24.768Z,1755842064.768 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch] Running Loop=1 2025-08-22T05:54:24.768Z,1755842064.768 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch](DEBUG): Initialize. 2025-08-22T05:54:24.768Z,1755842064.768 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed] Running Loop=1 2025-08-22T05:54:24.768Z,1755842064.768 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Initialize. 2025-08-22T05:54:24.769Z,1755842064.769 [keepstation:DiveCmd:SurfaceSink] Stopped 2025-08-22T05:54:24.769Z,1755842064.769 [keepstation:DiveCmd:SurfaceSink](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink 2025-08-22T05:54:24.770Z,1755842064.770 [keepstation:DiveCmd:SurfaceSink:sink] Stopped 2025-08-22T05:54:24.770Z,1755842064.770 [keepstation:DiveCmd:SurfaceSink:sink](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink:sink 2025-08-22T05:54:24.770Z,1755842064.770 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy] Stopped 2025-08-22T05:54:24.770Z,1755842064.770 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2025-08-22T05:54:24.770Z,1755842064.770 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed] Stopped 2025-08-22T05:54:24.770Z,1755842064.770 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Uninitialize. 2025-08-22T05:54:24.770Z,1755842064.770 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation] Stopped 2025-08-22T05:54:24.770Z,1755842064.770 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink:sink:sinkToStation 2025-08-22T05:54:24.770Z,1755842064.770 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation:A] Stopped 2025-08-22T05:54:25.169Z,1755842065.169 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 20.00 deg, mass-position 30.60 mm (1 active estimators). 2025-08-22T05:54:42.549Z,1755842082.549 [DVL_micro](ERROR): DVL BIT error. See manual. Result code: 52 Device respsone is::TS,00000000000000,35.0,+13.3,0000.0,14890,+00052,+00000,A 2025-08-22T05:54:42.551Z,1755842082.551 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2025-08-22T05:55:37.704Z,1755842137.704 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.755081 2025-08-22T06:07:00.886Z,1755842820.886 [DVL_micro](ERROR): Failed to parse: :WI,-00262,+00795,-00023,+00000,A 2025-08-22T06:07:02.897Z,1755842822.897 [DVL_micro](ERROR): Failed to parse: :BI,-00225,+00883,-00060,+00000,I 2025-08-22T06:18:58.479Z,1755843538.479 [RudderServo](ERROR): getPosition uart error serial timeout 2025-08-22T06:18:58.480Z,1755843538.480 [RudderServo](FAULT): Rudder uart error - getPosition..serial timeout 2025-08-22T06:18:58.480Z,1755843538.480 [RudderServo] Communications Fault, FailCount= 1 2025-08-22T06:18:58.480Z,1755843538.480 [RudderServo](ERROR): Communications Fault 2025-08-22T06:18:58.548Z,1755843538.548 [CBIT](ERROR): Communications Fault in component: RudderServo 2025-08-22T06:18:58.816Z,1755843538.816 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2025-08-22T06:18:58.817Z,1755843538.817 [RudderServo](INFO): Powering down 2025-08-22T06:18:59.588Z,1755843539.588 [RudderServo](DEBUG): Initializing EZServoServo. 2025-08-22T06:18:59.704Z,1755843539.704 [RudderServo](DEBUG): Initializing RudderServo. 2025-08-22T06:18:59.723Z,1755843539.723 [CBIT](INFO): Clearing failed state for component RudderServo 2025-08-22T06:18:59.723Z,1755843539.723 [RudderServo] No Fault, FailCount= 1 2025-08-22T06:21:02.515Z,1755843662.515 [DVL_micro](ERROR): only read 3 of 4 data items for bottom velocity. Device response is::BI,-00246,+00736,+00021,+00 2025-08-22T06:21:02.515Z,1755843662.515 [DVL_micro](ERROR): Failed to parse: :BI,-00246,+00736,+00021,+00 2025-08-22T06:24:21.094Z,1755843861.094 [DVL_micro](ERROR): Failed to parse: :BI,-00216,+00771,+00041,+00000,I 2025-08-22T06:41:59.664Z,1755844919.664 [BPC1](FAULT): Battery stick #2 (s/n: 0124) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-08-22T06:41:59.665Z,1755844919.665 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6. 2025-08-22T06:41:59.668Z,1755844919.668 [BPC1](INFO): Received data from all battery sticks. 2025-08-22T06:51:21.763Z,1755845481.763 [keepstation:SurfaceComms] Running Loop=1 2025-08-22T06:51:21.763Z,1755845481.763 [keepstation:SurfaceComms](DEBUG): Aggregate::initialize keepstation:SurfaceComms 2025-08-22T06:51:21.763Z,1755845481.763 [keepstation:SurfaceComms:A] Running Loop=1 2025-08-22T06:51:21.764Z,1755845481.764 [keepstation:SurfaceComms:A] Stopped 2025-08-22T06:51:21.764Z,1755845481.764 [keepstation:SurfaceComms:B] Running Loop=1 2025-08-22T06:51:21.764Z,1755845481.764 [keepstation:SurfaceComms:B](DEBUG): Aggregate::initialize keepstation:SurfaceComms:B 2025-08-22T06:51:21.766Z,1755845481.766 [keepstation:NeedComms] Running Loop=1 2025-08-22T06:51:21.766Z,1755845481.766 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms 2025-08-22T06:51:21.766Z,1755845481.766 [keepstation:NeedComms:B.GoToSurface] Running Loop=1 2025-08-22T06:51:21.766Z,1755845481.766 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-08-22T06:51:21.766Z,1755845481.766 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2025-08-22T06:51:21.767Z,1755845481.767 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2025-08-22T06:51:21.767Z,1755845481.767 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2025-08-22T06:51:21.768Z,1755845481.768 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds. 2025-08-22T06:51:21.768Z,1755845481.768 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-08-22T06:51:21.768Z,1755845481.768 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-08-22T06:51:21.768Z,1755845481.768 [keepstation:NeedComms:A] Running Loop=1 2025-08-22T06:51:21.770Z,1755845481.770 [keepstation:NeedComms:A](INFO): last time_fix was: 1755841881.000000 second since 1970/01/01T00:00:00Z 2025-08-22T06:51:21.770Z,1755845481.770 [keepstation:NeedComms:A] Stopped 2025-08-22T06:51:22.158Z,1755845482.158 [keepstation:TransitToStation:Dive] Stopped 2025-08-22T06:51:22.158Z,1755845482.158 [keepstation:TransitToStation:Dive](DEBUG): Aggregate::uninitialize keepstation:TransitToStation:Dive 2025-08-22T06:51:22.158Z,1755845482.158 [keepstation:TransitToStation:Dive:A] Stopped 2025-08-22T06:51:22.158Z,1755845482.158 [keepstation:TransitToStation:Dive:A](DEBUG): Aggregate::uninitialize keepstation:TransitToStation:Dive:A 2025-08-22T06:51:22.159Z,1755845482.159 [keepstation:DiveCmd:TransitToStation] Stopped 2025-08-22T06:51:22.159Z,1755845482.159 [keepstation:DiveCmd:TransitToStation](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:TransitToStation 2025-08-22T06:51:22.159Z,1755845482.159 [keepstation:DiveCmd:TransitToStation:dive] Stopped 2025-08-22T06:51:22.159Z,1755845482.159 [keepstation:DiveCmd:TransitToStation:dive](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:TransitToStation:dive 2025-08-22T06:51:22.159Z,1755845482.159 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy] Stopped 2025-08-22T06:51:22.159Z,1755845482.159 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2025-08-22T06:51:22.159Z,1755845482.159 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch] Stopped 2025-08-22T06:51:22.159Z,1755845482.159 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed] Stopped 2025-08-22T06:51:22.159Z,1755845482.159 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Uninitialize. 2025-08-22T06:52:22.943Z,1755845542.943 [keepstation:NeedComms:C] Running Loop=1 2025-08-22T06:52:23.637Z,1755845543.637 [Radio_Surface](INFO): Powering up 2025-08-22T06:52:29.836Z,1755845549.836 [DataOverHttps](INFO): Radio surface powered ON. 2025-08-22T06:52:59.958Z,1755845579.958 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T06:53:14.397Z,1755845594.397 [NAL9602](INFO): SBD MO Status=2, MOMSN=22228, MT Status=2, MTMSN=0 2025-08-22T06:53:14.397Z,1755845594.397 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-22T06:53:31.096Z,1755845611.096 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T06:53:40.253Z,1755845620.253 [NAL9602](INFO): SBD MO Status=2, MOMSN=22228, MT Status=2, MTMSN=0 2025-08-22T06:53:40.253Z,1755845620.253 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-22T06:54:02.221Z,1755845642.221 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T06:54:12.169Z,1755845652.169 [NAL9602](INFO): SBD MO Status=0, MOMSN=22228, MT Status=0, MTMSN=0 2025-08-22T06:54:12.169Z,1755845652.169 [NAL9602](INFO): No messages in MT queue 2025-08-22T06:54:13.393Z,1755845653.393 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,065413.00,A,3648.18985,N,12205.61349,W,1.458,156.27,220825,,,A*70 2025-08-22T06:54:13.395Z,1755845653.395 [NAL9602](INFO): GPS fix at 20250822T065413: (36.803164, -122.093558) 2025-08-22T06:54:13.409Z,1755845653.409 [UniversalFixResidualReporter](INFO): Fix residual: 12.5 %DT, over the last 3827.6 m. Residual distance 479.2 m at bearing -4.1 degrees. Fix at (36.8032, -122.0936) with 3142.9 m made good. 2025-08-22T06:54:13.410Z,1755845653.410 [keepstation:TransitToStation:Wpt1.Waypoint](INFO): Navigating to waypoint: 36.841160,-122.155777 2025-08-22T06:54:13.413Z,1755845653.413 [keepstation:NeedComms:C] Stopped 2025-08-22T06:54:13.413Z,1755845653.413 [keepstation:NeedComms:D] Running Loop=1 2025-08-22T06:54:22.105Z,1755845662.105 [NAL9602](INFO): SBD MO Status=1, MOMSN=22229, MT Status=0, MTMSN=0 2025-08-22T06:54:22.164Z,1755845662.164 [NAL9602](INFO): Sent 99 bytes from file Logs/20250822T043000/Courier0015.lzma 2025-08-22T06:54:22.164Z,1755845662.164 [NAL9602](INFO): Packets left to send: 0 2025-08-22T06:54:33.348Z,1755845673.348 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T06:54:42.607Z,1755845682.607 [NAL9602](INFO): SBD MO Status=1, MOMSN=22230, MT Status=0, MTMSN=0 2025-08-22T06:54:42.669Z,1755845682.669 [NAL9602](INFO): Sent 332 bytes from file Logs/20250822T043000/Express0016.lzma 2025-08-22T06:54:42.669Z,1755845682.669 [NAL9602](INFO): Packets left to send: 2 2025-08-22T06:54:52.544Z,1755845692.544 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003140 2025-08-22T06:54:55.432Z,1755845695.432 [NAL9602](INFO): SBD MO Status=1, MOMSN=22231, MT Status=0, MTMSN=0 2025-08-22T06:54:55.492Z,1755845695.492 [NAL9602](INFO): Sent 332 bytes from file Logs/20250822T043000/Express0016.lzma 2025-08-22T06:54:55.492Z,1755845695.492 [NAL9602](INFO): Packets left to send: 1 2025-08-22T06:55:00.413Z,1755845700.413 [DataOverHttps](INFO): Sending 826 bytes from file Logs/20250822T043000/Express0016.lzma 2025-08-22T06:55:11.453Z,1755845711.453 [DataOverHttps](INFO): Moved sent file to Logs/20250822T043000/Express0016.lzma.bak 2025-08-22T06:55:11.453Z,1755845711.453 [DataOverHttps](INFO): SBD MOMSN=25880278 2025-08-22T06:55:12.818Z,1755845712.818 [keepstation:NeedComms:D] Stopped 2025-08-22T06:55:12.819Z,1755845712.819 [keepstation:NeedComms:E] Running Loop=1 2025-08-22T06:55:14.823Z,1755845714.823 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,065514.00,A,3648.18311,N,12205.61942,W,1.400,216.23,220825,,,A*7E 2025-08-22T06:55:14.825Z,1755845714.825 [NAL9602](INFO): GPS fix at 20250822T065514: (36.803052, -122.093657) 2025-08-22T06:55:14.869Z,1755845714.869 [keepstation:TransitToStation:Wpt1.Waypoint](INFO): Navigating to waypoint: 36.841160,-122.155777 2025-08-22T06:55:14.876Z,1755845714.876 [keepstation:NeedComms:E] Stopped 2025-08-22T06:55:14.877Z,1755845714.877 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms 2025-08-22T06:55:14.877Z,1755845714.877 [keepstation:NeedComms] Stopped 2025-08-22T06:55:14.877Z,1755845714.877 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms 2025-08-22T06:55:14.877Z,1755845714.877 [keepstation:NeedComms:B.GoToSurface] Stopped 2025-08-22T06:55:14.877Z,1755845714.877 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-08-22T06:55:15.281Z,1755845715.281 [keepstation:SurfaceComms:B](INFO): Completed keepstation:SurfaceComms:B 2025-08-22T06:55:15.281Z,1755845715.281 [keepstation:SurfaceComms:B] Stopped 2025-08-22T06:55:15.281Z,1755845715.281 [keepstation:SurfaceComms:B](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:B 2025-08-22T06:55:15.281Z,1755845715.281 [keepstation:SurfaceComms:setTransit] Running Loop=1 2025-08-22T06:55:15.282Z,1755845715.282 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setTransit 2025-08-22T06:55:15.282Z,1755845715.282 [keepstation:SurfaceComms:setTransit:A] Running Loop=1 2025-08-22T06:55:15.666Z,1755845715.666 [keepstation:SurfaceComms:setTransit] Stopped 2025-08-22T06:55:15.666Z,1755845715.666 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setTransit 2025-08-22T06:55:15.666Z,1755845715.666 [keepstation:SurfaceComms:setTransit:A] Stopped 2025-08-22T06:55:15.666Z,1755845715.666 [keepstation:SurfaceComms:setStation] Running Loop=1 2025-08-22T06:55:15.666Z,1755845715.666 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setStation 2025-08-22T06:55:15.666Z,1755845715.666 [keepstation:SurfaceComms:setStation:A] Running Loop=1 2025-08-22T06:55:16.119Z,1755845716.119 [keepstation:SurfaceComms:setStation] Stopped 2025-08-22T06:55:16.128Z,1755845716.128 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setStation 2025-08-22T06:55:16.128Z,1755845716.128 [keepstation:SurfaceComms:setStation:A] Stopped 2025-08-22T06:55:16.128Z,1755845716.128 [keepstation:SurfaceComms:setSink] Running Loop=1 2025-08-22T06:55:16.128Z,1755845716.128 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setSink 2025-08-22T06:55:16.128Z,1755845716.128 [keepstation:SurfaceComms:setSink:A] Running Loop=1 2025-08-22T06:55:16.510Z,1755845716.510 [keepstation:SurfaceComms:setSink:A] Stopped 2025-08-22T06:55:16.510Z,1755845716.510 [keepstation:SurfaceComms:setSink](INFO): Completed keepstation:SurfaceComms:setSink 2025-08-22T06:55:16.510Z,1755845716.510 [keepstation:SurfaceComms:setSink] Stopped 2025-08-22T06:55:16.510Z,1755845716.510 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setSink 2025-08-22T06:55:16.511Z,1755845716.511 [keepstation:SurfaceComms](INFO): Completed keepstation:SurfaceComms 2025-08-22T06:55:16.511Z,1755845716.511 [keepstation:SurfaceComms] Stopped 2025-08-22T06:55:16.511Z,1755845716.511 [keepstation:SurfaceComms](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms 2025-08-22T06:55:16.869Z,1755845716.869 [keepstation:TransitToStation:Dive] Running Loop=1 2025-08-22T06:55:16.869Z,1755845716.869 [keepstation:TransitToStation:Dive](DEBUG): Aggregate::initialize keepstation:TransitToStation:Dive 2025-08-22T06:55:16.869Z,1755845716.869 [keepstation:TransitToStation:Dive:A] Running Loop=1 2025-08-22T06:55:16.869Z,1755845716.869 [keepstation:TransitToStation:Dive:A](DEBUG): Aggregate::initialize keepstation:TransitToStation:Dive:A 2025-08-22T06:55:16.869Z,1755845716.869 [keepstation:DiveCmd:SurfaceSink] Running Loop=1 2025-08-22T06:55:16.870Z,1755845716.870 [keepstation:DiveCmd:SurfaceSink](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink 2025-08-22T06:55:16.870Z,1755845716.870 [keepstation:DiveCmd:SurfaceSink:sink] Running Loop=1 2025-08-22T06:55:16.870Z,1755845716.870 [keepstation:DiveCmd:SurfaceSink:sink](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink 2025-08-22T06:55:16.870Z,1755845716.870 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy] Running Loop=1 2025-08-22T06:55:16.870Z,1755845716.870 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Initialize Buoyancy Component. 2025-08-22T06:55:16.870Z,1755845716.870 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed] Running Loop=1 2025-08-22T06:55:16.870Z,1755845716.870 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Initialize. 2025-08-22T06:55:16.870Z,1755845716.870 [keepstation:DiveCmd:SurfaceSink:sink:C] Running Loop=1 2025-08-22T06:55:16.871Z,1755845716.871 [keepstation:DiveCmd:SurfaceSink:sink:C](INFO): Sinking to 10.000000 m 2025-08-22T06:55:16.871Z,1755845716.871 [keepstation:DiveCmd:SurfaceSink:sink:C] Stopped 2025-08-22T06:55:16.871Z,1755845716.871 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch] Running Loop=1 2025-08-22T06:55:16.871Z,1755845716.871 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch](DEBUG): Initialize. 2025-08-22T06:55:46.785Z,1755845746.785 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-22T06:55:58.988Z,1755845758.988 [BuoyancyServo](ERROR): getPosition uart error serial timeout 2025-08-22T06:55:58.988Z,1755845758.988 [BuoyancyServo](FAULT): Buoyancy getPosition uart error.serial timeout 2025-08-22T06:55:58.988Z,1755845758.988 [BuoyancyServo] Communications Fault, FailCount= 1 2025-08-22T06:55:58.988Z,1755845758.988 [BuoyancyServo](ERROR): Communications Fault 2025-08-22T06:55:59.132Z,1755845759.132 [CBIT](ERROR): Communications Fault in component: BuoyancyServo 2025-08-22T06:56:00.912Z,1755845760.912 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2025-08-22T06:56:00.912Z,1755845760.912 [BuoyancyServo](INFO): Powering down 2025-08-22T06:56:01.871Z,1755845761.871 [CBIT](INFO): Clearing failed state for component BuoyancyServo 2025-08-22T06:56:01.871Z,1755845761.871 [BuoyancyServo] No Fault, FailCount= 1 2025-08-22T06:56:02.115Z,1755845762.115 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2025-08-22T06:56:02.116Z,1755845762.116 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2025-08-22T06:58:17.078Z,1755845897.078 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch](INFO): Timed out from 2025-08-22T06:55:16.9Z 2025-08-22T06:58:17.078Z,1755845897.078 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout] Running Loop=1 2025-08-22T06:58:17.078Z,1755845897.078 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout 2025-08-22T06:58:17.078Z,1755845897.078 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout:A] Running Loop=1 2025-08-22T06:58:17.079Z,1755845897.079 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout:A](IMPORTANT): Timed out while trying to reach target sink depth at current depth of 0.028488 m 2025-08-22T06:58:17.079Z,1755845897.079 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout:A] Stopped 2025-08-22T06:58:17.079Z,1755845897.079 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout](INFO): Completed keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout 2025-08-22T06:58:17.079Z,1755845897.079 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch] Stopped 2025-08-22T06:58:17.079Z,1755845897.079 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit] Running Loop=1 2025-08-22T06:58:17.083Z,1755845897.083 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit 2025-08-22T06:58:17.084Z,1755845897.084 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit:A] Running Loop=1 2025-08-22T06:58:17.492Z,1755845897.492 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit:A] Stopped 2025-08-22T06:58:17.493Z,1755845897.493 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit](INFO): Completed keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit 2025-08-22T06:58:17.493Z,1755845897.493 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit] Stopped 2025-08-22T06:58:17.493Z,1755845897.493 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit 2025-08-22T06:58:17.493Z,1755845897.493 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation] Running Loop=1 2025-08-22T06:58:17.493Z,1755845897.493 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink:sinkToStation 2025-08-22T06:58:17.493Z,1755845897.493 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation:A] Running Loop=1 2025-08-22T06:58:17.921Z,1755845897.921 [keepstation:DiveCmd:TransitToStation] Running Loop=1 2025-08-22T06:58:17.921Z,1755845897.921 [keepstation:DiveCmd:TransitToStation](DEBUG): Aggregate::initialize keepstation:DiveCmd:TransitToStation 2025-08-22T06:58:17.921Z,1755845897.921 [keepstation:DiveCmd:TransitToStation:dive] Running Loop=1 2025-08-22T06:58:17.922Z,1755845897.922 [keepstation:DiveCmd:TransitToStation:dive](DEBUG): Aggregate::initialize keepstation:DiveCmd:TransitToStation:dive 2025-08-22T06:58:17.922Z,1755845897.922 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy] Running Loop=1 2025-08-22T06:58:17.922Z,1755845897.922 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Initialize Buoyancy Component. 2025-08-22T06:58:17.922Z,1755845897.922 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch] Running Loop=1 2025-08-22T06:58:17.922Z,1755845897.922 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch](DEBUG): Initialize. 2025-08-22T06:58:17.922Z,1755845897.922 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed] Running Loop=1 2025-08-22T06:58:17.923Z,1755845897.923 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Initialize. 2025-08-22T06:58:17.945Z,1755845897.945 [keepstation:DiveCmd:SurfaceSink] Stopped 2025-08-22T06:58:17.945Z,1755845897.945 [keepstation:DiveCmd:SurfaceSink](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink 2025-08-22T06:58:17.945Z,1755845897.945 [keepstation:DiveCmd:SurfaceSink:sink] Stopped 2025-08-22T06:58:17.945Z,1755845897.945 [keepstation:DiveCmd:SurfaceSink:sink](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink:sink 2025-08-22T06:58:17.945Z,1755845897.945 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy] Stopped 2025-08-22T06:58:17.945Z,1755845897.945 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2025-08-22T06:58:17.945Z,1755845897.945 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed] Stopped 2025-08-22T06:58:17.946Z,1755845897.946 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Uninitialize. 2025-08-22T06:58:17.946Z,1755845897.946 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation] Stopped 2025-08-22T06:58:17.946Z,1755845897.946 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink:sink:sinkToStation 2025-08-22T06:58:17.946Z,1755845897.946 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation:A] Stopped 2025-08-22T06:59:15.456Z,1755845955.456 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T06:59:46.584Z,1755845986.584 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T06:59:59.852Z,1755845999.852 [Radio_Surface](INFO): Powering down 2025-08-22T07:00:17.729Z,1755846017.729 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T07:00:18.732Z,1755846018.732 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2025-08-22T07:01:34.032Z,1755846094.032 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.742996 2025-08-22T07:35:06.409Z,1755848106.409 [DVL_micro](ERROR): Failed to parse: :WI,-00194,+01118,+00055,+00000,A 2025-08-22T07:37:44.243Z,1755848264.243 [DVL_micro](ERROR): DVL uart error: serial timeout 2025-08-22T07:37:44.243Z,1755848264.243 [DVL_micro] Communications Fault, FailCount= 1 2025-08-22T07:37:44.243Z,1755848264.243 [DVL_micro](ERROR): Communications Fault 2025-08-22T07:37:44.244Z,1755848264.244 [DVL_micro](ERROR): Failed to parse: 2025-08-22T07:37:44.527Z,1755848264.527 [CBIT](ERROR): Communications Fault in component: DVL_micro 2025-08-22T07:37:44.668Z,1755848264.668 [DVL_micro](INFO): Powering down 2025-08-22T07:37:45.727Z,1755848265.727 [CBIT](INFO): Clearing failed state for component DVL_micro 2025-08-22T07:37:45.727Z,1755848265.727 [DVL_micro] No Fault, FailCount= 1 2025-08-22T07:49:33.634Z,1755848973.634 [BPC1](ERROR): Battery stick #2 (s/n: 0124) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-08-22T07:49:33.635Z,1755848973.635 [BPC1](INFO): Calculating totals. Valid battery stick count: 53. Valid reserve battery stick count: 6. 2025-08-22T07:49:33.638Z,1755848973.638 [BPC1](INFO): Received data from all battery sticks. 2025-08-22T07:53:11.211Z,1755849191.211 [DVL_micro](ERROR): DVL uart error: serial timeout 2025-08-22T07:53:11.212Z,1755849191.212 [DVL_micro] Communications Fault, FailCount= 1 2025-08-22T07:53:11.212Z,1755849191.212 [DVL_micro](ERROR): Communications Fault 2025-08-22T07:53:11.212Z,1755849191.212 [DVL_micro](ERROR): Failed to parse: 2025-08-22T07:53:11.467Z,1755849191.467 [CBIT](ERROR): Communications Fault in component: DVL_micro 2025-08-22T07:53:11.640Z,1755849191.640 [DVL_micro](INFO): Powering down 2025-08-22T07:53:12.607Z,1755849192.607 [CBIT](INFO): Clearing failed state for component DVL_micro 2025-08-22T07:53:12.607Z,1755849192.607 [DVL_micro] No Fault, FailCount= 1 2025-08-22T07:54:27.161Z,1755849267.161 [DVL_micro](ERROR): Failed to parse: 21.99 2025-08-22T07:55:14.923Z,1755849314.923 [keepstation:SurfaceComms] Running Loop=1 2025-08-22T07:55:14.923Z,1755849314.923 [keepstation:SurfaceComms](DEBUG): Aggregate::initialize keepstation:SurfaceComms 2025-08-22T07:55:14.924Z,1755849314.924 [keepstation:SurfaceComms:A] Running Loop=1 2025-08-22T07:55:14.924Z,1755849314.924 [keepstation:SurfaceComms:A] Stopped 2025-08-22T07:55:14.924Z,1755849314.924 [keepstation:SurfaceComms:B] Running Loop=1 2025-08-22T07:55:14.924Z,1755849314.924 [keepstation:SurfaceComms:B](DEBUG): Aggregate::initialize keepstation:SurfaceComms:B 2025-08-22T07:55:14.926Z,1755849314.926 [keepstation:NeedComms] Running Loop=1 2025-08-22T07:55:14.926Z,1755849314.926 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms 2025-08-22T07:55:14.926Z,1755849314.926 [keepstation:NeedComms:B.GoToSurface] Running Loop=1 2025-08-22T07:55:14.926Z,1755849314.926 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-08-22T07:55:14.927Z,1755849314.927 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2025-08-22T07:55:14.927Z,1755849314.927 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2025-08-22T07:55:14.927Z,1755849314.927 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2025-08-22T07:55:14.928Z,1755849314.928 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds. 2025-08-22T07:55:14.928Z,1755849314.928 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-08-22T07:55:14.928Z,1755849314.928 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-08-22T07:55:14.929Z,1755849314.929 [keepstation:NeedComms:A] Running Loop=1 2025-08-22T07:55:14.930Z,1755849314.930 [keepstation:NeedComms:A](INFO): last time_fix was: 1755845714.000000 second since 1970/01/01T00:00:00Z 2025-08-22T07:55:14.930Z,1755849314.930 [keepstation:NeedComms:A] Stopped 2025-08-22T07:55:15.310Z,1755849315.310 [keepstation:TransitToStation:Dive] Stopped 2025-08-22T07:55:15.310Z,1755849315.310 [keepstation:TransitToStation:Dive](DEBUG): Aggregate::uninitialize keepstation:TransitToStation:Dive 2025-08-22T07:55:15.310Z,1755849315.310 [keepstation:TransitToStation:Dive:A] Stopped 2025-08-22T07:55:15.310Z,1755849315.310 [keepstation:TransitToStation:Dive:A](DEBUG): Aggregate::uninitialize keepstation:TransitToStation:Dive:A 2025-08-22T07:55:15.311Z,1755849315.311 [keepstation:DiveCmd:TransitToStation] Stopped 2025-08-22T07:55:15.311Z,1755849315.311 [keepstation:DiveCmd:TransitToStation](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:TransitToStation 2025-08-22T07:55:15.311Z,1755849315.311 [keepstation:DiveCmd:TransitToStation:dive] Stopped 2025-08-22T07:55:15.311Z,1755849315.311 [keepstation:DiveCmd:TransitToStation:dive](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:TransitToStation:dive 2025-08-22T07:55:15.311Z,1755849315.311 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy] Stopped 2025-08-22T07:55:15.311Z,1755849315.311 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2025-08-22T07:55:15.311Z,1755849315.311 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch] Stopped 2025-08-22T07:55:15.311Z,1755849315.311 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed] Stopped 2025-08-22T07:55:15.311Z,1755849315.311 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Uninitialize. 2025-08-22T07:56:21.557Z,1755849381.557 [keepstation:NeedComms:C] Running Loop=1 2025-08-22T07:56:22.288Z,1755849382.288 [Radio_Surface](INFO): Powering up 2025-08-22T07:56:27.628Z,1755849387.628 [DataOverHttps](INFO): Radio surface powered ON. 2025-08-22T07:56:57.748Z,1755849417.748 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T07:57:28.872Z,1755849448.872 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T07:58:00.012Z,1755849480.012 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T07:58:31.136Z,1755849511.136 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T07:58:49.863Z,1755849529.863 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002839 2025-08-22T07:59:08.152Z,1755849548.152 [NAL9602](INFO): SBD MO Status=2, MOMSN=22232, MT Status=2, MTMSN=0 2025-08-22T07:59:08.153Z,1755849548.153 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-22T07:59:19.064Z,1755849559.064 [NAL9602](INFO): SBD MO Status=0, MOMSN=22232, MT Status=0, MTMSN=0 2025-08-22T07:59:19.064Z,1755849559.064 [NAL9602](INFO): No messages in MT queue 2025-08-22T07:59:20.269Z,1755849560.269 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,075920.00,A,3649.15635,N,12207.48928,W,0.117,263.92,220825,,,A*74 2025-08-22T07:59:20.272Z,1755849560.272 [NAL9602](INFO): GPS fix at 20250822T075920: (36.819272, -122.124821) 2025-08-22T07:59:20.284Z,1755849560.284 [UniversalFixResidualReporter](INFO): Fix residual: 6.4 %DT, over the last 3868.6 m. Residual distance 247.8 m at bearing 23.0 degrees. Fix at (36.8193, -122.1248) with 3309.1 m made good. 2025-08-22T07:59:20.285Z,1755849560.285 [keepstation:TransitToStation:Wpt1.Waypoint](INFO): Navigating to waypoint: 36.841160,-122.155777 2025-08-22T07:59:20.304Z,1755849560.304 [keepstation:NeedComms:C] Stopped 2025-08-22T07:59:20.305Z,1755849560.305 [keepstation:NeedComms:D] Running Loop=1 2025-08-22T07:59:30.031Z,1755849570.031 [DataOverHttps](INFO): Sending 99 bytes from file Logs/20250822T043000/Courier0018.lzma 2025-08-22T07:59:41.085Z,1755849581.085 [DataOverHttps](INFO): Moved sent file to Logs/20250822T043000/Courier0018.lzma.bak 2025-08-22T07:59:41.085Z,1755849581.085 [DataOverHttps](INFO): SBD MOMSN=25880437 2025-08-22T07:59:50.990Z,1755849590.990 [DVL_micro](ERROR): Failed to parse: 2025-08-22T07:59:52.591Z,1755849592.591 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-22T08:00:07.933Z,1755849607.933 [DataOverHttps](INFO): Sending 806 bytes from file Logs/20250822T043000/Express0019.lzma 2025-08-22T08:00:18.975Z,1755849618.975 [DataOverHttps](INFO): Moved sent file to Logs/20250822T043000/Express0019.lzma.bak 2025-08-22T08:00:18.975Z,1755849618.975 [DataOverHttps](INFO): SBD MOMSN=25880441 2025-08-22T08:00:20.500Z,1755849620.500 [keepstation:NeedComms:D] Stopped 2025-08-22T08:00:20.501Z,1755849620.501 [keepstation:NeedComms:E] Running Loop=1 2025-08-22T08:00:22.516Z,1755849622.516 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,080022.00,A,3649.15412,N,12207.49716,W,0.836,235.36,220825,,,A*77 2025-08-22T08:00:22.518Z,1755849622.518 [NAL9602](INFO): GPS fix at 20250822T080022: (36.819235, -122.124953) 2025-08-22T08:00:22.542Z,1755849622.542 [keepstation:TransitToStation:Wpt1.Waypoint](INFO): Navigating to waypoint: 36.841160,-122.155777 2025-08-22T08:00:22.569Z,1755849622.569 [keepstation:NeedComms:E] Stopped 2025-08-22T08:00:22.570Z,1755849622.570 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms 2025-08-22T08:00:22.570Z,1755849622.570 [keepstation:NeedComms] Stopped 2025-08-22T08:00:22.570Z,1755849622.570 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms 2025-08-22T08:00:22.570Z,1755849622.570 [keepstation:NeedComms:B.GoToSurface] Stopped 2025-08-22T08:00:22.570Z,1755849622.570 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-08-22T08:00:22.989Z,1755849622.989 [keepstation:SurfaceComms:B](INFO): Completed keepstation:SurfaceComms:B 2025-08-22T08:00:22.989Z,1755849622.989 [keepstation:SurfaceComms:B] Stopped 2025-08-22T08:00:22.989Z,1755849622.989 [keepstation:SurfaceComms:B](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:B 2025-08-22T08:00:22.989Z,1755849622.989 [keepstation:SurfaceComms:setTransit] Running Loop=1 2025-08-22T08:00:22.989Z,1755849622.989 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setTransit 2025-08-22T08:00:22.990Z,1755849622.990 [keepstation:SurfaceComms:setTransit:A] Running Loop=1 2025-08-22T08:00:23.350Z,1755849623.350 [keepstation:SurfaceComms:setTransit] Stopped 2025-08-22T08:00:23.350Z,1755849623.350 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setTransit 2025-08-22T08:00:23.350Z,1755849623.350 [keepstation:SurfaceComms:setTransit:A] Stopped 2025-08-22T08:00:23.350Z,1755849623.350 [keepstation:SurfaceComms:setStation] Running Loop=1 2025-08-22T08:00:23.350Z,1755849623.350 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setStation 2025-08-22T08:00:23.350Z,1755849623.350 [keepstation:SurfaceComms:setStation:A] Running Loop=1 2025-08-22T08:00:23.762Z,1755849623.762 [keepstation:SurfaceComms:setStation] Stopped 2025-08-22T08:00:23.762Z,1755849623.762 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setStation 2025-08-22T08:00:23.762Z,1755849623.762 [keepstation:SurfaceComms:setStation:A] Stopped 2025-08-22T08:00:23.762Z,1755849623.762 [keepstation:SurfaceComms:setSink] Running Loop=1 2025-08-22T08:00:23.762Z,1755849623.762 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setSink 2025-08-22T08:00:23.762Z,1755849623.762 [keepstation:SurfaceComms:setSink:A] Running Loop=1 2025-08-22T08:00:24.187Z,1755849624.187 [keepstation:SurfaceComms:setSink:A] Stopped 2025-08-22T08:00:24.187Z,1755849624.187 [keepstation:SurfaceComms:setSink](INFO): Completed keepstation:SurfaceComms:setSink 2025-08-22T08:00:24.187Z,1755849624.187 [keepstation:SurfaceComms:setSink] Stopped 2025-08-22T08:00:24.187Z,1755849624.187 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setSink 2025-08-22T08:00:24.187Z,1755849624.187 [keepstation:SurfaceComms](INFO): Completed keepstation:SurfaceComms 2025-08-22T08:00:24.191Z,1755849624.191 [keepstation:SurfaceComms] Stopped 2025-08-22T08:00:24.191Z,1755849624.191 [keepstation:SurfaceComms](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms 2025-08-22T08:00:24.610Z,1755849624.610 [keepstation:TransitToStation:Dive] Running Loop=1 2025-08-22T08:00:24.610Z,1755849624.610 [keepstation:TransitToStation:Dive](DEBUG): Aggregate::initialize keepstation:TransitToStation:Dive 2025-08-22T08:00:24.610Z,1755849624.610 [keepstation:TransitToStation:Dive:A] Running Loop=1 2025-08-22T08:00:24.611Z,1755849624.611 [keepstation:TransitToStation:Dive:A](DEBUG): Aggregate::initialize keepstation:TransitToStation:Dive:A 2025-08-22T08:00:24.611Z,1755849624.611 [keepstation:DiveCmd:SurfaceSink] Running Loop=1 2025-08-22T08:00:24.616Z,1755849624.616 [keepstation:DiveCmd:SurfaceSink](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink 2025-08-22T08:00:24.616Z,1755849624.616 [keepstation:DiveCmd:SurfaceSink:sink] Running Loop=1 2025-08-22T08:00:24.616Z,1755849624.616 [keepstation:DiveCmd:SurfaceSink:sink](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink 2025-08-22T08:00:24.617Z,1755849624.617 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy] Running Loop=1 2025-08-22T08:00:24.617Z,1755849624.617 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Initialize Buoyancy Component. 2025-08-22T08:00:24.617Z,1755849624.617 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed] Running Loop=1 2025-08-22T08:00:24.617Z,1755849624.617 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Initialize. 2025-08-22T08:00:24.617Z,1755849624.617 [keepstation:DiveCmd:SurfaceSink:sink:C] Running Loop=1 2025-08-22T08:00:24.617Z,1755849624.617 [keepstation:DiveCmd:SurfaceSink:sink:C](INFO): Sinking to 10.000000 m 2025-08-22T08:00:24.618Z,1755849624.618 [keepstation:DiveCmd:SurfaceSink:sink:C] Stopped 2025-08-22T08:00:24.618Z,1755849624.618 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch] Running Loop=1 2025-08-22T08:00:24.618Z,1755849624.618 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch](DEBUG): Initialize. 2025-08-22T08:00:49.173Z,1755849649.173 [NAL9602](INFO): SBD MO Status=0, MOMSN=22233, MT Status=0, MTMSN=0 2025-08-22T08:00:49.173Z,1755849649.173 [NAL9602](INFO): No messages in MT queue 2025-08-22T08:01:19.872Z,1755849679.872 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-22T08:01:50.704Z,1755849710.704 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2025-08-22T08:01:56.655Z,1755849716.655 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](IMPORTANT): Altitude envelope ACTIVE. Altitude:0.420000m. At depth:2.192417m. 2025-08-22T08:02:21.828Z,1755849741.828 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T08:02:46.103Z,1755849766.103 [Radio_Surface](INFO): Powering down 2025-08-22T08:02:52.952Z,1755849772.952 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T08:02:53.956Z,1755849773.956 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2025-08-22T08:03:24.786Z,1755849804.786 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch](INFO): Timed out from 2025-08-22T08:00:24.6Z 2025-08-22T08:03:24.786Z,1755849804.786 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout] Running Loop=1 2025-08-22T08:03:24.786Z,1755849804.786 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout 2025-08-22T08:03:24.787Z,1755849804.787 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout:A] Running Loop=1 2025-08-22T08:03:24.787Z,1755849804.787 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout:A](IMPORTANT): Timed out while trying to reach target sink depth at current depth of 8.279748 m 2025-08-22T08:03:24.788Z,1755849804.788 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout:A] Stopped 2025-08-22T08:03:24.788Z,1755849804.788 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout](INFO): Completed keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout 2025-08-22T08:03:24.788Z,1755849804.788 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch] Stopped 2025-08-22T08:03:24.788Z,1755849804.788 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit] Running Loop=1 2025-08-22T08:03:24.788Z,1755849804.788 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit 2025-08-22T08:03:24.788Z,1755849804.788 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit:A] Running Loop=1 2025-08-22T08:03:25.176Z,1755849805.176 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit:A] Stopped 2025-08-22T08:03:25.177Z,1755849805.177 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit](INFO): Completed keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit 2025-08-22T08:03:25.177Z,1755849805.177 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit] Stopped 2025-08-22T08:03:25.177Z,1755849805.177 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit 2025-08-22T08:03:25.177Z,1755849805.177 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation] Running Loop=1 2025-08-22T08:03:25.177Z,1755849805.177 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink:sinkToStation 2025-08-22T08:03:25.177Z,1755849805.177 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation:A] Running Loop=1 2025-08-22T08:03:25.612Z,1755849805.612 [keepstation:DiveCmd:TransitToStation] Running Loop=1 2025-08-22T08:03:25.612Z,1755849805.612 [keepstation:DiveCmd:TransitToStation](DEBUG): Aggregate::initialize keepstation:DiveCmd:TransitToStation 2025-08-22T08:03:25.612Z,1755849805.612 [keepstation:DiveCmd:TransitToStation:dive] Running Loop=1 2025-08-22T08:03:25.612Z,1755849805.612 [keepstation:DiveCmd:TransitToStation:dive](DEBUG): Aggregate::initialize keepstation:DiveCmd:TransitToStation:dive 2025-08-22T08:03:25.612Z,1755849805.612 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy] Running Loop=1 2025-08-22T08:03:25.612Z,1755849805.612 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Initialize Buoyancy Component. 2025-08-22T08:03:25.612Z,1755849805.612 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch] Running Loop=1 2025-08-22T08:03:25.612Z,1755849805.612 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch](DEBUG): Initialize. 2025-08-22T08:03:25.612Z,1755849805.612 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed] Running Loop=1 2025-08-22T08:03:25.612Z,1755849805.612 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Initialize. 2025-08-22T08:03:25.613Z,1755849805.613 [keepstation:DiveCmd:SurfaceSink] Stopped 2025-08-22T08:03:25.613Z,1755849805.613 [keepstation:DiveCmd:SurfaceSink](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink 2025-08-22T08:03:25.614Z,1755849805.614 [keepstation:DiveCmd:SurfaceSink:sink] Stopped 2025-08-22T08:03:25.614Z,1755849805.614 [keepstation:DiveCmd:SurfaceSink:sink](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink:sink 2025-08-22T08:03:25.614Z,1755849805.614 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy] Stopped 2025-08-22T08:03:25.614Z,1755849805.614 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2025-08-22T08:03:25.614Z,1755849805.614 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed] Stopped 2025-08-22T08:03:25.614Z,1755849805.614 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Uninitialize. 2025-08-22T08:03:25.614Z,1755849805.614 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation] Stopped 2025-08-22T08:03:25.614Z,1755849805.614 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink:sink:sinkToStation 2025-08-22T08:03:25.614Z,1755849805.614 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation:A] Stopped 2025-08-22T08:04:09.265Z,1755849849.265 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.903168 2025-08-22T08:09:08.291Z,1755850148.291 [DVL_micro](ERROR): only read 3 of 4 data items for beam range. Device response is::RD,+0123.62,+0124.37,4 2025-08-22T08:09:08.292Z,1755850148.292 [DVL_micro](ERROR): Failed to parse: :RD,+0123.62,+0124.37,4 2025-08-22T08:11:04.011Z,1755850264.011 [DVL_micro](ERROR): Failed to parse: :SA,+04.40,-03.88,298.6 2025-08-22T08:15:09.410Z,1755850509.410 [DVL_micro](ERROR): Failed to parse: :WI,-00005,+00461,+00023,+00000,A 2025-08-22T08:19:06.470Z,1755850746.470 [DVL_micro](ERROR): Failed to parse: :WI,+00006,+00907,-00045,+00000,A 2025-08-22T08:19:08.489Z,1755850748.489 [DVL_micro](ERROR): Failed to parse: :BI,+00012,+01034,+00095,+00000,A 2025-08-22T08:19:10.515Z,1755850750.515 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,0104.40,000.00 2025-08-22T08:19:12.537Z,1755850752.537 [DVL_micro](ERROR): Failed to parse: :RD,+0113.39,+0118.52,+9999.99,+0113.20 2025-08-22T08:19:12.921Z,1755850752.921 [DVL_micro](ERROR): No DVL communication! Re-initializing 2025-08-22T08:19:12.921Z,1755850752.921 [DVL_micro] Communications Fault, FailCount= 1 2025-08-22T08:19:12.921Z,1755850752.921 [DVL_micro](ERROR): Communications Fault 2025-08-22T08:19:13.179Z,1755850753.179 [CBIT](ERROR): Communications Fault in component: DVL_micro 2025-08-22T08:19:13.412Z,1755850753.412 [DVL_micro](INFO): Powering down 2025-08-22T08:19:14.523Z,1755850754.523 [CBIT](INFO): Clearing failed state for component DVL_micro 2025-08-22T08:19:14.523Z,1755850754.523 [DVL_micro] No Fault, FailCount= 1 2025-08-22T08:21:51.369Z,1755850911.369 [DVL_micro](ERROR): only read 2 of 4 data items for beam range. Device response is::RD,+9,+0114.20 2025-08-22T08:21:51.369Z,1755850911.369 [DVL_micro](ERROR): Failed to parse: :RD,+9,+0114.20 2025-08-22T08:31:07.380Z,1755851467.380 [DVL_micro](ERROR): Failed to parse::SA,+04.02,-01.09,297.8 2025-08-22T08:45:38.592Z,1755852338.592 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+13.0,0000.0,1489.0,000 2025-08-22T08:56:29.602Z,1755852989.602 [DVL_micro](ERROR): Failed to parse: :WI,+00029,+00991,-00045,+00000,A 2025-08-22T08:57:09.247Z,1755853029.247 [BPC1](ERROR): Battery stick #2 (s/n: 0124) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-08-22T08:57:09.248Z,1755853029.248 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6. 2025-08-22T08:57:09.250Z,1755853029.250 [BPC1](INFO): Received data from all battery sticks. 2025-08-22T09:00:22.549Z,1755853222.549 [keepstation:SurfaceComms] Running Loop=1 2025-08-22T09:00:22.549Z,1755853222.549 [keepstation:SurfaceComms](DEBUG): Aggregate::initialize keepstation:SurfaceComms 2025-08-22T09:00:22.549Z,1755853222.549 [keepstation:SurfaceComms:A] Running Loop=1 2025-08-22T09:00:22.550Z,1755853222.550 [keepstation:SurfaceComms:A] Stopped 2025-08-22T09:00:22.550Z,1755853222.550 [keepstation:SurfaceComms:B] Running Loop=1 2025-08-22T09:00:22.550Z,1755853222.550 [keepstation:SurfaceComms:B](DEBUG): Aggregate::initialize keepstation:SurfaceComms:B 2025-08-22T09:00:22.970Z,1755853222.970 [keepstation:TransitToStation:Dive] Stopped 2025-08-22T09:00:22.970Z,1755853222.970 [keepstation:TransitToStation:Dive](DEBUG): Aggregate::uninitialize keepstation:TransitToStation:Dive 2025-08-22T09:00:22.970Z,1755853222.970 [keepstation:TransitToStation:Dive:A] Stopped 2025-08-22T09:00:22.971Z,1755853222.971 [keepstation:TransitToStation:Dive:A](DEBUG): Aggregate::uninitialize keepstation:TransitToStation:Dive:A 2025-08-22T09:00:22.972Z,1755853222.972 [keepstation:DiveCmd:TransitToStation] Stopped 2025-08-22T09:00:22.972Z,1755853222.972 [keepstation:DiveCmd:TransitToStation](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:TransitToStation 2025-08-22T09:00:22.972Z,1755853222.972 [keepstation:DiveCmd:TransitToStation:dive] Stopped 2025-08-22T09:00:22.972Z,1755853222.972 [keepstation:DiveCmd:TransitToStation:dive](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:TransitToStation:dive 2025-08-22T09:00:22.972Z,1755853222.972 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy] Stopped 2025-08-22T09:00:22.972Z,1755853222.972 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2025-08-22T09:00:22.973Z,1755853222.973 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch] Stopped 2025-08-22T09:00:22.973Z,1755853222.973 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed] Stopped 2025-08-22T09:00:22.973Z,1755853222.973 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Uninitialize. 2025-08-22T09:00:22.000Z,1755853223.000 [keepstation:NeedComms] Running Loop=1 2025-08-22T09:00:22.000Z,1755853223.000 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms 2025-08-22T09:00:22.000Z,1755853223.000 [keepstation:NeedComms:B.GoToSurface] Running Loop=1 2025-08-22T09:00:23.000Z,1755853223.000 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-08-22T09:00:23.000Z,1755853223.000 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2025-08-22T09:00:23.001Z,1755853223.001 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2025-08-22T09:00:23.001Z,1755853223.001 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2025-08-22T09:00:23.001Z,1755853223.001 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds. 2025-08-22T09:00:23.002Z,1755853223.002 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-08-22T09:00:23.002Z,1755853223.002 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-08-22T09:00:23.002Z,1755853223.002 [keepstation:NeedComms:A] Running Loop=1 2025-08-22T09:00:23.008Z,1755853223.008 [keepstation:NeedComms:A](INFO): last time_fix was: 1755849622.000000 second since 1970/01/01T00:00:00Z 2025-08-22T09:00:23.008Z,1755853223.008 [keepstation:NeedComms:A] Stopped 2025-08-22T09:01:25.577Z,1755853285.577 [keepstation:NeedComms:C] Running Loop=1 2025-08-22T09:01:26.348Z,1755853286.348 [Radio_Surface](INFO): Powering up 2025-08-22T09:01:32.412Z,1755853292.412 [DataOverHttps](INFO): Radio surface powered ON. 2025-08-22T09:02:02.533Z,1755853322.533 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T09:02:23.193Z,1755853343.193 [NAL9602](INFO): SBD MO Status=2, MOMSN=22234, MT Status=2, MTMSN=0 2025-08-22T09:02:23.194Z,1755853343.194 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-22T09:02:33.656Z,1755853353.656 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T09:03:04.788Z,1755853384.788 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T09:03:35.924Z,1755853415.924 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T09:03:54.836Z,1755853434.836 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002844 2025-08-22T09:04:48.630Z,1755853488.630 [NAL9602](INFO): SBD MO Status=0, MOMSN=22234, MT Status=0, MTMSN=0 2025-08-22T09:04:48.630Z,1755853488.630 [NAL9602](INFO): No messages in MT queue 2025-08-22T09:04:49.852Z,1755853489.852 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,090449.00,A,3650.37461,N,12209.23397,W,1.166,270.73,220825,,,A*71 2025-08-22T09:04:49.855Z,1755853489.855 [NAL9602](INFO): GPS fix at 20250822T090449: (36.839577, -122.153899) 2025-08-22T09:04:49.900Z,1755853489.900 [UniversalFixResidualReporter](INFO): Fix residual: 3.0 %DT, over the last 3825.4 m. Residual distance 112.9 m at bearing 114.7 degrees. Fix at (36.8396, -122.1539) with 3428.4 m made good. 2025-08-22T09:04:49.903Z,1755853489.903 [keepstation:TransitToStation:Wpt1.Waypoint](INFO): Navigating to waypoint: 36.841160,-122.155777 2025-08-22T09:04:49.908Z,1755853489.908 [keepstation:NeedComms:C] Stopped 2025-08-22T09:04:49.908Z,1755853489.908 [keepstation:NeedComms:D] Running Loop=1 2025-08-22T09:05:04.659Z,1755853504.659 [DataOverHttps](INFO): Sending 99 bytes from file Logs/20250822T043000/Courier0021.lzma 2025-08-22T09:05:15.703Z,1755853515.703 [DataOverHttps](INFO): Moved sent file to Logs/20250822T043000/Courier0021.lzma.bak 2025-08-22T09:05:15.703Z,1755853515.703 [DataOverHttps](INFO): SBD MOMSN=25880598 2025-08-22T09:05:21.789Z,1755853521.789 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-22T09:05:42.361Z,1755853542.361 [DataOverHttps](INFO): Sending 859 bytes from file Logs/20250822T043000/Express0022.lzma 2025-08-22T09:05:53.401Z,1755853553.401 [DataOverHttps](INFO): Moved sent file to Logs/20250822T043000/Express0022.lzma.bak 2025-08-22T09:05:53.402Z,1755853553.402 [DataOverHttps](INFO): SBD MOMSN=25880601 2025-08-22T09:05:54.898Z,1755853554.898 [keepstation:NeedComms:D] Stopped 2025-08-22T09:05:54.898Z,1755853554.898 [keepstation:NeedComms:E] Running Loop=1 2025-08-22T09:05:56.908Z,1755853556.908 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,090556.00,A,3650.36979,N,12209.23969,W,0.680,216.31,220825,,,A*78 2025-08-22T09:05:56.911Z,1755853556.911 [NAL9602](INFO): GPS fix at 20250822T090556: (36.839497, -122.153995) 2025-08-22T09:05:56.933Z,1755853556.933 [keepstation:TransitToStation:Wpt1.Waypoint](INFO): Navigating to waypoint: 36.841160,-122.155777 2025-08-22T09:05:56.940Z,1755853556.940 [keepstation:NeedComms:E] Stopped 2025-08-22T09:05:56.940Z,1755853556.940 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms 2025-08-22T09:05:56.940Z,1755853556.940 [keepstation:NeedComms] Stopped 2025-08-22T09:05:56.940Z,1755853556.940 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms 2025-08-22T09:05:56.941Z,1755853556.941 [keepstation:NeedComms:B.GoToSurface] Stopped 2025-08-22T09:05:56.941Z,1755853556.941 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-08-22T09:05:57.348Z,1755853557.348 [keepstation:SurfaceComms:B](INFO): Completed keepstation:SurfaceComms:B 2025-08-22T09:05:57.348Z,1755853557.348 [keepstation:SurfaceComms:B] Stopped 2025-08-22T09:05:57.348Z,1755853557.348 [keepstation:SurfaceComms:B](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:B 2025-08-22T09:05:57.348Z,1755853557.348 [keepstation:SurfaceComms:setTransit] Running Loop=1 2025-08-22T09:05:57.348Z,1755853557.348 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setTransit 2025-08-22T09:05:57.348Z,1755853557.348 [keepstation:SurfaceComms:setTransit:A] Running Loop=1 2025-08-22T09:05:57.792Z,1755853557.792 [keepstation:SurfaceComms:setTransit] Stopped 2025-08-22T09:05:57.792Z,1755853557.792 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setTransit 2025-08-22T09:05:57.792Z,1755853557.792 [keepstation:SurfaceComms:setTransit:A] Stopped 2025-08-22T09:05:57.792Z,1755853557.792 [keepstation:SurfaceComms:setStation] Running Loop=1 2025-08-22T09:05:57.793Z,1755853557.793 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setStation 2025-08-22T09:05:57.793Z,1755853557.793 [keepstation:SurfaceComms:setStation:A] Running Loop=1 2025-08-22T09:05:58.141Z,1755853558.141 [keepstation:SurfaceComms:setStation] Stopped 2025-08-22T09:05:58.141Z,1755853558.141 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setStation 2025-08-22T09:05:58.141Z,1755853558.141 [keepstation:SurfaceComms:setStation:A] Stopped 2025-08-22T09:05:58.141Z,1755853558.141 [keepstation:SurfaceComms:setSink] Running Loop=1 2025-08-22T09:05:58.141Z,1755853558.141 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setSink 2025-08-22T09:05:58.142Z,1755853558.142 [keepstation:SurfaceComms:setSink:A] Running Loop=1 2025-08-22T09:05:58.559Z,1755853558.559 [keepstation:SurfaceComms:setSink:A] Stopped 2025-08-22T09:05:58.563Z,1755853558.563 [keepstation:SurfaceComms:setSink](INFO): Completed keepstation:SurfaceComms:setSink 2025-08-22T09:05:58.563Z,1755853558.563 [keepstation:SurfaceComms:setSink] Stopped 2025-08-22T09:05:58.564Z,1755853558.564 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setSink 2025-08-22T09:05:58.564Z,1755853558.564 [keepstation:SurfaceComms](INFO): Completed keepstation:SurfaceComms 2025-08-22T09:05:58.564Z,1755853558.564 [keepstation:SurfaceComms] Stopped 2025-08-22T09:05:58.564Z,1755853558.564 [keepstation:SurfaceComms](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms 2025-08-22T09:05:58.949Z,1755853558.949 [keepstation:TransitToStation:Dive] Running Loop=1 2025-08-22T09:05:58.949Z,1755853558.949 [keepstation:TransitToStation:Dive](DEBUG): Aggregate::initialize keepstation:TransitToStation:Dive 2025-08-22T09:05:58.949Z,1755853558.949 [keepstation:TransitToStation:Dive:A] Running Loop=1 2025-08-22T09:05:58.949Z,1755853558.949 [keepstation:TransitToStation:Dive:A](DEBUG): Aggregate::initialize keepstation:TransitToStation:Dive:A 2025-08-22T09:05:58.950Z,1755853558.950 [keepstation:DiveCmd:SurfaceSink] Running Loop=1 2025-08-22T09:05:58.950Z,1755853558.950 [keepstation:DiveCmd:SurfaceSink](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink 2025-08-22T09:05:58.950Z,1755853558.950 [keepstation:DiveCmd:SurfaceSink:sink] Running Loop=1 2025-08-22T09:05:58.950Z,1755853558.950 [keepstation:DiveCmd:SurfaceSink:sink](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink 2025-08-22T09:05:58.950Z,1755853558.950 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy] Running Loop=1 2025-08-22T09:05:58.950Z,1755853558.950 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Initialize Buoyancy Component. 2025-08-22T09:05:58.950Z,1755853558.950 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed] Running Loop=1 2025-08-22T09:05:58.950Z,1755853558.950 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Initialize. 2025-08-22T09:05:58.950Z,1755853558.950 [keepstation:DiveCmd:SurfaceSink:sink:C] Running Loop=1 2025-08-22T09:05:58.951Z,1755853558.951 [keepstation:DiveCmd:SurfaceSink:sink:C](INFO): Sinking to 10.000000 m 2025-08-22T09:05:58.951Z,1755853558.951 [keepstation:DiveCmd:SurfaceSink:sink:C] Stopped 2025-08-22T09:05:58.984Z,1755853558.984 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch] Running Loop=1 2025-08-22T09:05:58.985Z,1755853558.985 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch](DEBUG): Initialize. 2025-08-22T09:06:26.398Z,1755853586.398 [NAL9602](INFO): SBD MO Status=0, MOMSN=22235, MT Status=0, MTMSN=0 2025-08-22T09:06:26.398Z,1755853586.398 [NAL9602](INFO): No messages in MT queue 2025-08-22T09:06:56.911Z,1755853616.911 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-22T09:07:41.408Z,1755853661.408 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](IMPORTANT): Altitude envelope ACTIVE. Altitude:0.680000m. At depth:1.768336m. 2025-08-22T09:07:57.708Z,1755853677.708 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T09:08:28.844Z,1755853708.844 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T09:08:32.984Z,1755853712.984 [Radio_Surface](INFO): Powering down 2025-08-22T09:08:59.339Z,1755853739.339 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch](INFO): Timed out from 2025-08-22T09:05:58.0Z 2025-08-22T09:08:59.339Z,1755853739.339 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout] Running Loop=1 2025-08-22T09:08:59.340Z,1755853739.340 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout 2025-08-22T09:08:59.340Z,1755853739.340 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout:A] Running Loop=1 2025-08-22T09:08:59.340Z,1755853739.340 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout:A](IMPORTANT): Timed out while trying to reach target sink depth at current depth of 8.190433 m 2025-08-22T09:08:59.340Z,1755853739.340 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout:A] Stopped 2025-08-22T09:08:59.341Z,1755853739.341 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout](INFO): Completed keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout 2025-08-22T09:08:59.341Z,1755853739.341 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch] Stopped 2025-08-22T09:08:59.341Z,1755853739.341 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit] Running Loop=1 2025-08-22T09:08:59.341Z,1755853739.341 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit 2025-08-22T09:08:59.341Z,1755853739.341 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit:A] Running Loop=1 2025-08-22T09:08:59.748Z,1755853739.748 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit:A] Stopped 2025-08-22T09:08:59.748Z,1755853739.748 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit](INFO): Completed keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit 2025-08-22T09:08:59.748Z,1755853739.748 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit] Stopped 2025-08-22T09:08:59.748Z,1755853739.748 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit 2025-08-22T09:08:59.748Z,1755853739.748 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation] Running Loop=1 2025-08-22T09:08:59.748Z,1755853739.748 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink:sinkToStation 2025-08-22T09:08:59.748Z,1755853739.748 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation:A] Running Loop=1 2025-08-22T09:08:59.968Z,1755853739.968 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T09:09:00.160Z,1755853740.160 [keepstation:DiveCmd:TransitToStation] Running Loop=1 2025-08-22T09:09:00.160Z,1755853740.160 [keepstation:DiveCmd:TransitToStation](DEBUG): Aggregate::initialize keepstation:DiveCmd:TransitToStation 2025-08-22T09:09:00.160Z,1755853740.160 [keepstation:DiveCmd:TransitToStation:dive] Running Loop=1 2025-08-22T09:09:00.160Z,1755853740.160 [keepstation:DiveCmd:TransitToStation:dive](DEBUG): Aggregate::initialize keepstation:DiveCmd:TransitToStation:dive 2025-08-22T09:09:00.160Z,1755853740.160 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy] Running Loop=1 2025-08-22T09:09:00.161Z,1755853740.161 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Initialize Buoyancy Component. 2025-08-22T09:09:00.161Z,1755853740.161 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch] Running Loop=1 2025-08-22T09:09:00.161Z,1755853740.161 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch](DEBUG): Initialize. 2025-08-22T09:09:00.161Z,1755853740.161 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed] Running Loop=1 2025-08-22T09:09:00.161Z,1755853740.161 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Initialize. 2025-08-22T09:09:00.162Z,1755853740.162 [keepstation:DiveCmd:SurfaceSink] Stopped 2025-08-22T09:09:00.162Z,1755853740.162 [keepstation:DiveCmd:SurfaceSink](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink 2025-08-22T09:09:00.162Z,1755853740.162 [keepstation:DiveCmd:SurfaceSink:sink] Stopped 2025-08-22T09:09:00.162Z,1755853740.162 [keepstation:DiveCmd:SurfaceSink:sink](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink:sink 2025-08-22T09:09:00.162Z,1755853740.162 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy] Stopped 2025-08-22T09:09:00.162Z,1755853740.162 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2025-08-22T09:09:00.162Z,1755853740.162 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed] Stopped 2025-08-22T09:09:00.162Z,1755853740.162 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Uninitialize. 2025-08-22T09:09:00.162Z,1755853740.162 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation] Stopped 2025-08-22T09:09:00.163Z,1755853740.163 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink:sink:sinkToStation 2025-08-22T09:09:00.163Z,1755853740.163 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation:A] Stopped 2025-08-22T09:09:00.972Z,1755853740.972 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2025-08-22T09:09:45.148Z,1755853785.148 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.751450 2025-08-22T09:10:12.116Z,1755853812.116 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+0142.33,+9999.99,+0135.30 2025-08-22T09:12:12.715Z,1755853932.715 [keepstation:TransitToStation:Wpt1.Waypoint](IMPORTANT): Reached waypoint: 36.841160,-122.155777 2025-08-22T09:12:12.715Z,1755853932.715 [keepstation:TransitToStation:Wpt1.Waypoint] Stopped 2025-08-22T09:12:12.715Z,1755853932.715 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Uninitialize WaypointComponent. 2025-08-22T09:12:12.715Z,1755853932.715 [keepstation:TransitToStation:C] Running Loop=1 2025-08-22T09:12:13.122Z,1755853933.122 [keepstation:TransitToStation:C] Stopped 2025-08-22T09:12:13.122Z,1755853933.122 [keepstation:TransitToStation:D] Running Loop=1 2025-08-22T09:12:13.122Z,1755853933.122 [keepstation:DiveCmd:StationKeep] Running Loop=1 2025-08-22T09:12:13.123Z,1755853933.123 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::initialize keepstation:DiveCmd:StationKeep 2025-08-22T09:12:13.123Z,1755853933.123 [keepstation:DiveCmd:StationKeep:A] Running Loop=1 2025-08-22T09:12:13.123Z,1755853933.123 [keepstation:DiveCmd:StationKeep:B.Pitch] Running Loop=1 2025-08-22T09:12:13.123Z,1755853933.123 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Initialize. 2025-08-22T09:12:13.123Z,1755853933.123 [keepstation:DiveCmd:StationKeep:C.KeepStation] Running Loop=1 2025-08-22T09:12:13.123Z,1755853933.123 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Initialize KeepStationComponent. 2025-08-22T09:12:13.124Z,1755853933.124 [keepstation:DiveCmd:StationKeep] Running Loop=1 2025-08-22T09:12:13.124Z,1755853933.124 [keepstation:DiveCmd:StationKeep:C.KeepStation] Running Loop=1 2025-08-22T09:12:13.124Z,1755853933.124 [keepstation:DiveCmd:StationKeep:B.Pitch] Running Loop=1 2025-08-22T09:12:13.125Z,1755853933.125 [keepstation:DiveCmd:StationKeep:A] Running Loop=1 2025-08-22T09:12:13.125Z,1755853933.125 [keepstation:DiveCmd:TransitToStation] Stopped 2025-08-22T09:12:13.125Z,1755853933.125 [keepstation:DiveCmd:TransitToStation](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:TransitToStation 2025-08-22T09:12:13.125Z,1755853933.125 [keepstation:DiveCmd:TransitToStation:dive] Stopped 2025-08-22T09:12:13.125Z,1755853933.125 [keepstation:DiveCmd:TransitToStation:dive](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:TransitToStation:dive 2025-08-22T09:12:13.125Z,1755853933.125 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy] Stopped 2025-08-22T09:12:13.125Z,1755853933.125 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2025-08-22T09:12:13.125Z,1755853933.125 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch] Stopped 2025-08-22T09:12:13.125Z,1755853933.125 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed] Stopped 2025-08-22T09:12:13.125Z,1755853933.125 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Uninitialize. 2025-08-22T09:12:13.548Z,1755853933.548 [keepstation:TransitToStation:D] Stopped 2025-08-22T09:12:13.548Z,1755853933.548 [keepstation:TransitToStation](INFO): Completed keepstation:TransitToStation 2025-08-22T09:12:13.548Z,1755853933.548 [keepstation:TransitToStation] Stopped 2025-08-22T09:12:13.548Z,1755853933.548 [keepstation:TransitToStation](DEBUG): Aggregate::uninitialize keepstation:TransitToStation 2025-08-22T09:12:13.548Z,1755853933.548 [keepstation:TransitToStation:Dive] Stopped 2025-08-22T09:12:13.548Z,1755853933.548 [keepstation:TransitToStation:Dive](DEBUG): Aggregate::uninitialize keepstation:TransitToStation:Dive 2025-08-22T09:12:13.548Z,1755853933.548 [keepstation:TransitToStation:Dive:A] Stopped 2025-08-22T09:12:13.548Z,1755853933.548 [keepstation:TransitToStation:Dive:A](DEBUG): Aggregate::uninitialize keepstation:TransitToStation:Dive:A 2025-08-22T09:12:13.549Z,1755853933.549 [keepstation:OnStation] Running Loop=1 2025-08-22T09:12:13.549Z,1755853933.549 [keepstation:OnStation](DEBUG): Aggregate::initialize keepstation:OnStation 2025-08-22T09:12:13.930Z,1755853933.930 [keepstation:NeedComms] Running Loop=1 2025-08-22T09:12:13.930Z,1755853933.930 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms 2025-08-22T09:12:13.930Z,1755853933.930 [keepstation:NeedComms:B.GoToSurface] Running Loop=1 2025-08-22T09:12:13.930Z,1755853933.930 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-08-22T09:12:13.930Z,1755853933.930 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2025-08-22T09:12:13.931Z,1755853933.931 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2025-08-22T09:12:13.931Z,1755853933.931 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2025-08-22T09:12:13.932Z,1755853933.932 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds. 2025-08-22T09:12:13.932Z,1755853933.932 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-08-22T09:12:13.932Z,1755853933.932 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-08-22T09:12:13.932Z,1755853933.932 [keepstation:NeedComms:A] Running Loop=1 2025-08-22T09:12:13.934Z,1755853933.934 [keepstation:NeedComms:A](INFO): last time_fix was: 1755853556.000000 second since 1970/01/01T00:00:00Z 2025-08-22T09:12:13.934Z,1755853933.934 [keepstation:NeedComms:A] Stopped 2025-08-22T09:13:09.985Z,1755853989.985 [keepstation:NeedComms:C] Running Loop=1 2025-08-22T09:13:10.568Z,1755853990.568 [Radio_Surface](INFO): Powering up 2025-08-22T09:13:16.016Z,1755853996.016 [DataOverHttps](INFO): Radio surface powered ON. 2025-08-22T09:13:34.619Z,1755854014.619 [NAL9602](INFO): SBD MO Status=2, MOMSN=22236, MT Status=2, MTMSN=0 2025-08-22T09:13:34.619Z,1755854014.619 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-22T09:13:46.140Z,1755854026.140 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T09:14:17.276Z,1755854057.276 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T09:14:29.150Z,1755854069.150 [NAL9602](INFO): SBD MO Status=2, MOMSN=22236, MT Status=2, MTMSN=0 2025-08-22T09:14:29.150Z,1755854069.150 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-22T09:14:48.408Z,1755854088.408 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T09:15:19.532Z,1755854119.532 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T09:15:38.396Z,1755854138.396 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002862 2025-08-22T09:18:14.589Z,1755854294.589 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-08-22T09:18:22.261Z,1755854302.261 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,091822.00,A,3650.42109,N,12209.38461,W,0.544,252.81,220825,,,A*74 2025-08-22T09:18:22.264Z,1755854302.264 [NAL9602](INFO): GPS fix at 20250822T091822: (36.840351, -122.156410) 2025-08-22T09:18:22.276Z,1755854302.276 [UniversalFixResidualReporter](INFO): Fix residual: 11.9 %DT, over the last 875.3 m. Residual distance 104.2 m at bearing 80.6 degrees. Fix at (36.8404, -122.1564) with 235.0 m made good. 2025-08-22T09:18:22.280Z,1755854302.280 [keepstation:NeedComms:C] Stopped 2025-08-22T09:18:22.295Z,1755854302.295 [keepstation:NeedComms:D] Running Loop=1 2025-08-22T09:18:29.803Z,1755854309.803 [DataOverHttps](INFO): Sending 87 bytes from file Logs/20250822T043000/Courier0024.lzma 2025-08-22T09:18:40.846Z,1755854320.846 [DataOverHttps](INFO): Moved sent file to Logs/20250822T043000/Courier0024.lzma.bak 2025-08-22T09:18:40.847Z,1755854320.847 [DataOverHttps](INFO): SBD MOMSN=25880641 2025-08-22T09:18:54.580Z,1755854334.580 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-22T09:19:07.092Z,1755854347.092 [DataOverHttps](INFO): Sending 621 bytes from file Logs/20250822T043000/Express0025.lzma 2025-08-22T09:19:18.134Z,1755854358.134 [DataOverHttps](INFO): Moved sent file to Logs/20250822T043000/Express0025.lzma.bak 2025-08-22T09:19:18.134Z,1755854358.134 [DataOverHttps](INFO): SBD MOMSN=25880644 2025-08-22T09:19:19.653Z,1755854359.653 [keepstation:NeedComms:D] Stopped 2025-08-22T09:19:19.654Z,1755854359.654 [keepstation:NeedComms:E] Running Loop=1 2025-08-22T09:19:21.666Z,1755854361.666 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,091921.00,A,3650.41970,N,12209.38797,W,1.652,328.24,220825,,,A*7F 2025-08-22T09:19:21.672Z,1755854361.672 [NAL9602](INFO): GPS fix at 20250822T091921: (36.840328, -122.156466) 2025-08-22T09:19:21.700Z,1755854361.700 [keepstation:NeedComms:E] Stopped 2025-08-22T09:19:21.701Z,1755854361.701 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms 2025-08-22T09:19:21.701Z,1755854361.701 [keepstation:NeedComms] Stopped 2025-08-22T09:19:21.701Z,1755854361.701 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms 2025-08-22T09:19:21.701Z,1755854361.701 [keepstation:NeedComms:B.GoToSurface] Stopped 2025-08-22T09:19:21.701Z,1755854361.701 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-08-22T09:19:22.104Z,1755854362.104 [keepstation:OnStation](INFO): Completed keepstation:OnStation 2025-08-22T09:19:22.104Z,1755854362.104 [keepstation:OnStation] Stopped 2025-08-22T09:19:22.104Z,1755854362.104 [keepstation:OnStation](DEBUG): Aggregate::uninitialize keepstation:OnStation 2025-08-22T09:19:22.104Z,1755854362.104 [keepstation:KeepStation] Running Loop=1 2025-08-22T09:19:22.104Z,1755854362.104 [keepstation:KeepStation](DEBUG): Aggregate::initialize keepstation:KeepStation 2025-08-22T09:19:22.105Z,1755854362.105 [keepstation:KeepStation:Dive] Running Loop=1 2025-08-22T09:19:22.105Z,1755854362.105 [keepstation:KeepStation:Dive](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive 2025-08-22T09:19:22.105Z,1755854362.105 [keepstation:KeepStation:Dive:A] Running Loop=1 2025-08-22T09:19:22.105Z,1755854362.105 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive:A 2025-08-22T09:19:22.105Z,1755854362.105 [keepstation:KeepStation:B.Wait] Running Loop=1 2025-08-22T09:19:22.105Z,1755854362.105 [keepstation:KeepStation:B.Wait](DEBUG): Initialize Wait Component. 2025-08-22T09:19:22.514Z,1755854362.514 [keepstation:KeepStation:Dive] Running Loop=1 2025-08-22T09:19:52.353Z,1755854392.353 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2025-08-22T09:19:52.427Z,1755854392.427 [NAL9602](ERROR): received: +CSQ:1 OK236, 2, 0, 0, 0 OK 2025-08-22T09:20:12.565Z,1755854412.565 [NAL9602](INFO): SBD MO Status=2, MOMSN=22236, MT Status=2, MTMSN=0 2025-08-22T09:20:12.565Z,1755854412.565 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-22T09:20:24.274Z,1755854424.274 [NAL9602](INFO): SBD MO Status=0, MOMSN=22236, MT Status=0, MTMSN=0 2025-08-22T09:20:24.275Z,1755854424.275 [NAL9602](INFO): No messages in MT queue 2025-08-22T09:20:54.977Z,1755854454.977 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-22T09:21:22.012Z,1755854482.012 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T09:21:43.668Z,1755854503.668 [Radio_Surface](INFO): Powering down 2025-08-22T09:21:53.144Z,1755854513.144 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T09:21:54.148Z,1755854514.148 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2025-08-22T09:23:08.448Z,1755854588.448 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.519318 2025-08-22T09:25:38.994Z,1755854738.994 [DVL_micro](ERROR): DVL BIT error. See manual. Result code: 9 Device respsone is::TS,00000000000000,35.0,+13.5,0000.0,1489.0,0009,+0127.89 2025-08-22T09:25:38.997Z,1755854738.997 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+13.5,0000.0,1489.0,000 2025-08-22T09:46:51.196Z,1755856011.196 [keepstation:DiveCmd:StationKeep:C.KeepStation](INFO): Rest->Waypoint 2025-08-22T09:55:21.448Z,1755856521.448 [keepstation:DiveCmd:StationKeep:C.KeepStation](INFO): Waypoint->Rest 2025-08-22T09:55:21.830Z,1755856521.830 [ElevatorOffsetCalculator](INFO): Removing expired estimator for commanded vars: speed 1.00 m/s, pitch 20.00 deg, mass-position 30.60 mm. 2025-08-22T10:00:32.949Z,1755856832.949 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file). 2025-08-22T10:04:46.675Z,1755857086.675 [BPC1](ERROR): Battery stick #2 (s/n: 0124) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-08-22T10:04:46.676Z,1755857086.676 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6. 2025-08-22T10:04:46.678Z,1755857086.678 [BPC1](INFO): Received data from all battery sticks. 2025-08-22T10:13:22.177Z,1755857602.177 [DVL_micro](ERROR): Failed to parse: :SA,-00.96,+00.05,209.2 2025-08-22T10:15:43.973Z,1755857743.973 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2025-08-22T10:16:05.787Z,1755857765.787 [DVL_micro](ERROR): Failed to parse: :BI,-00148,-00013,-00002,+00000,I 2025-08-22T10:19:07.765Z,1755857947.765 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-08-22T10:19:12.207Z,1755857952.207 [GFScanner](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.003948 CHAN A1 (24V): 0.003258 CHAN A2 (12V): -0.008315 CHAN A3 (5V): -0.082950 CHAN B0 (3.3V): -0.002947 CHAN B1 (3.15aV): -0.001920 CHAN B2 (3.15bV): -0.002085 CHAN B3 (GND): 0.004567 OPEN: 0.010794 Full Scale: +/- 1 mA 2025-08-22T10:19:21.749Z,1755857961.749 [keepstation:SurfaceComms] Running Loop=1 2025-08-22T10:19:21.749Z,1755857961.749 [keepstation:SurfaceComms](DEBUG): Aggregate::initialize keepstation:SurfaceComms 2025-08-22T10:19:21.749Z,1755857961.749 [keepstation:SurfaceComms:A] Running Loop=1 2025-08-22T10:19:21.750Z,1755857961.750 [keepstation:SurfaceComms:A] Stopped 2025-08-22T10:19:21.750Z,1755857961.750 [keepstation:SurfaceComms:B] Running Loop=1 2025-08-22T10:19:21.750Z,1755857961.750 [keepstation:SurfaceComms:B](DEBUG): Aggregate::initialize keepstation:SurfaceComms:B 2025-08-22T10:19:21.753Z,1755857961.753 [keepstation:NeedComms] Running Loop=1 2025-08-22T10:19:21.753Z,1755857961.753 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms 2025-08-22T10:19:21.753Z,1755857961.753 [keepstation:NeedComms:B.GoToSurface] Running Loop=1 2025-08-22T10:19:21.753Z,1755857961.753 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-08-22T10:19:21.753Z,1755857961.753 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2025-08-22T10:19:21.754Z,1755857961.754 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2025-08-22T10:19:21.754Z,1755857961.754 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2025-08-22T10:19:21.754Z,1755857961.754 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds. 2025-08-22T10:19:21.755Z,1755857961.755 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-08-22T10:19:21.755Z,1755857961.755 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-08-22T10:19:21.755Z,1755857961.755 [keepstation:NeedComms:A] Running Loop=1 2025-08-22T10:19:21.757Z,1755857961.757 [keepstation:NeedComms:A](INFO): last time_fix was: 1755854361.000000 second since 1970/01/01T00:00:00Z 2025-08-22T10:19:21.757Z,1755857961.757 [keepstation:NeedComms:A] Stopped 2025-08-22T10:19:22.138Z,1755857962.138 [keepstation:KeepStation:Dive] Stopped 2025-08-22T10:19:22.138Z,1755857962.138 [keepstation:KeepStation:Dive](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive 2025-08-22T10:19:22.138Z,1755857962.138 [keepstation:KeepStation:Dive:A] Stopped 2025-08-22T10:19:22.138Z,1755857962.138 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive:A 2025-08-22T10:19:22.139Z,1755857962.139 [keepstation:DiveCmd:StationKeep] Stopped 2025-08-22T10:19:22.139Z,1755857962.139 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:StationKeep 2025-08-22T10:19:22.139Z,1755857962.139 [keepstation:DiveCmd:StationKeep:A] Stopped 2025-08-22T10:19:22.139Z,1755857962.139 [keepstation:DiveCmd:StationKeep:B.Pitch] Stopped 2025-08-22T10:19:22.139Z,1755857962.139 [keepstation:DiveCmd:StationKeep:C.KeepStation] Stopped 2025-08-22T10:19:22.139Z,1755857962.139 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Uninitialize KeepStationComponent. 2025-08-22T10:20:56.336Z,1755858056.336 [keepstation:NeedComms:C] Running Loop=1 2025-08-22T10:20:56.840Z,1755858056.840 [Radio_Surface](INFO): Powering up 2025-08-22T10:21:02.748Z,1755858062.748 [DataOverHttps](INFO): Radio surface powered ON. 2025-08-22T10:21:32.868Z,1755858092.868 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T10:22:03.992Z,1755858123.992 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T10:22:35.116Z,1755858155.116 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T10:23:06.241Z,1755858186.241 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T10:23:25.167Z,1755858205.167 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002723 2025-08-22T10:23:28.819Z,1755858208.819 [NAL9602](INFO): SBD MO Status=2, MOMSN=22237, MT Status=2, MTMSN=0 2025-08-22T10:23:28.820Z,1755858208.820 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-22T10:23:44.170Z,1755858224.170 [NAL9602](INFO): SBD MO Status=0, MOMSN=22237, MT Status=0, MTMSN=0 2025-08-22T10:23:44.170Z,1755858224.170 [NAL9602](INFO): No messages in MT queue 2025-08-22T10:23:45.382Z,1755858225.382 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,102345.00,A,3650.41099,N,12209.50496,W,0.428,124.91,220825,,,A*70 2025-08-22T10:23:45.384Z,1755858225.384 [NAL9602](INFO): GPS fix at 20250822T102345: (36.840183, -122.158416) 2025-08-22T10:23:45.421Z,1755858225.421 [UniversalFixResidualReporter](INFO): Fix residual: 11.4 %DT, over the last 1223.1 m. Residual distance 139.6 m at bearing 99.8 degrees. Fix at (36.8402, -122.1584) with 174.3 m made good. 2025-08-22T10:23:45.428Z,1755858225.428 [keepstation:NeedComms:C] Stopped 2025-08-22T10:23:45.428Z,1755858225.428 [keepstation:NeedComms:D] Running Loop=1 2025-08-22T10:24:04.003Z,1755858244.003 [DataOverHttps](INFO): Sending 100 bytes from file Logs/20250822T043000/Courier0027.lzma 2025-08-22T10:24:15.045Z,1755858255.045 [DataOverHttps](INFO): Moved sent file to Logs/20250822T043000/Courier0027.lzma.bak 2025-08-22T10:24:15.046Z,1755858255.046 [DataOverHttps](INFO): SBD MOMSN=25880798 2025-08-22T10:24:17.773Z,1755858257.773 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-22T10:24:25.547Z,1755858265.547 [RudderServo](ERROR): getPosition uart error serial timeout 2025-08-22T10:24:25.548Z,1755858265.548 [RudderServo](FAULT): Rudder uart error - getPosition..serial timeout 2025-08-22T10:24:25.548Z,1755858265.548 [RudderServo] Communications Fault, FailCount= 1 2025-08-22T10:24:25.548Z,1755858265.548 [RudderServo](ERROR): Communications Fault 2025-08-22T10:24:25.572Z,1755858265.572 [CBIT](ERROR): Communications Fault in component: RudderServo 2025-08-22T10:24:25.872Z,1755858265.872 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2025-08-22T10:24:25.872Z,1755858265.872 [RudderServo](INFO): Powering down 2025-08-22T10:24:26.728Z,1755858266.728 [RudderServo](DEBUG): Initializing EZServoServo. 2025-08-22T10:24:26.848Z,1755858266.848 [RudderServo](DEBUG): Initializing RudderServo. 2025-08-22T10:24:26.852Z,1755858266.852 [CBIT](INFO): Clearing failed state for component RudderServo 2025-08-22T10:24:26.852Z,1755858266.852 [RudderServo] No Fault, FailCount= 1 2025-08-22T10:24:42.337Z,1755858282.337 [DataOverHttps](INFO): Sending 729 bytes from file Logs/20250822T043000/Express0028.lzma 2025-08-22T10:24:53.377Z,1755858293.377 [DataOverHttps](INFO): Moved sent file to Logs/20250822T043000/Express0028.lzma.bak 2025-08-22T10:24:53.378Z,1755858293.378 [DataOverHttps](INFO): SBD MOMSN=25880801 2025-08-22T10:24:54.588Z,1755858294.588 [keepstation:NeedComms:D] Stopped 2025-08-22T10:24:54.588Z,1755858294.588 [keepstation:NeedComms:E] Running Loop=1 2025-08-22T10:24:56.616Z,1755858296.616 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,102456.00,A,3650.40696,N,12209.49925,W,0.369,136.75,220825,,,A*7B 2025-08-22T10:24:56.619Z,1755858296.619 [NAL9602](INFO): GPS fix at 20250822T102456: (36.840116, -122.158321) 2025-08-22T10:24:56.645Z,1755858296.645 [keepstation:NeedComms:E] Stopped 2025-08-22T10:24:56.646Z,1755858296.646 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms 2025-08-22T10:24:56.646Z,1755858296.646 [keepstation:NeedComms] Stopped 2025-08-22T10:24:56.646Z,1755858296.646 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms 2025-08-22T10:24:56.646Z,1755858296.646 [keepstation:NeedComms:B.GoToSurface] Stopped 2025-08-22T10:24:56.646Z,1755858296.646 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-08-22T10:24:57.008Z,1755858297.008 [keepstation:SurfaceComms:B](INFO): Completed keepstation:SurfaceComms:B 2025-08-22T10:24:57.008Z,1755858297.008 [keepstation:SurfaceComms:B] Stopped 2025-08-22T10:24:57.008Z,1755858297.008 [keepstation:SurfaceComms:B](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:B 2025-08-22T10:24:57.008Z,1755858297.008 [keepstation:SurfaceComms:setTransit] Running Loop=1 2025-08-22T10:24:57.008Z,1755858297.008 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setTransit 2025-08-22T10:24:57.009Z,1755858297.009 [keepstation:SurfaceComms:setTransit:A] Running Loop=1 2025-08-22T10:24:57.387Z,1755858297.387 [keepstation:SurfaceComms:setTransit] Stopped 2025-08-22T10:24:57.387Z,1755858297.387 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setTransit 2025-08-22T10:24:57.387Z,1755858297.387 [keepstation:SurfaceComms:setTransit:A] Stopped 2025-08-22T10:24:57.387Z,1755858297.387 [keepstation:SurfaceComms:setStation] Running Loop=1 2025-08-22T10:24:57.387Z,1755858297.387 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setStation 2025-08-22T10:24:57.387Z,1755858297.387 [keepstation:SurfaceComms:setStation:A] Running Loop=1 2025-08-22T10:24:57.824Z,1755858297.824 [keepstation:SurfaceComms:setStation] Stopped 2025-08-22T10:24:57.824Z,1755858297.824 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setStation 2025-08-22T10:24:57.824Z,1755858297.824 [keepstation:SurfaceComms:setStation:A] Stopped 2025-08-22T10:24:57.824Z,1755858297.824 [keepstation:SurfaceComms:setSink] Running Loop=1 2025-08-22T10:24:57.824Z,1755858297.824 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setSink 2025-08-22T10:24:57.824Z,1755858297.824 [keepstation:SurfaceComms:setSink:A] Running Loop=1 2025-08-22T10:24:58.214Z,1755858298.214 [keepstation:SurfaceComms:setSink:A] Stopped 2025-08-22T10:24:58.215Z,1755858298.215 [keepstation:SurfaceComms:setSink](INFO): Completed keepstation:SurfaceComms:setSink 2025-08-22T10:24:58.215Z,1755858298.215 [keepstation:SurfaceComms:setSink] Stopped 2025-08-22T10:24:58.215Z,1755858298.215 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setSink 2025-08-22T10:24:58.215Z,1755858298.215 [keepstation:SurfaceComms](INFO): Completed keepstation:SurfaceComms 2025-08-22T10:24:58.215Z,1755858298.215 [keepstation:SurfaceComms] Stopped 2025-08-22T10:24:58.215Z,1755858298.215 [keepstation:SurfaceComms](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms 2025-08-22T10:24:58.664Z,1755858298.664 [keepstation:KeepStation:Dive] Running Loop=1 2025-08-22T10:24:58.664Z,1755858298.664 [keepstation:KeepStation:Dive](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive 2025-08-22T10:24:58.665Z,1755858298.665 [keepstation:KeepStation:Dive:A] Running Loop=1 2025-08-22T10:24:58.665Z,1755858298.665 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive:A 2025-08-22T10:24:58.665Z,1755858298.665 [keepstation:DiveCmd:SurfaceSink] Running Loop=1 2025-08-22T10:24:58.665Z,1755858298.665 [keepstation:DiveCmd:SurfaceSink](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink 2025-08-22T10:24:58.665Z,1755858298.665 [keepstation:DiveCmd:SurfaceSink:sink] Running Loop=1 2025-08-22T10:24:58.665Z,1755858298.665 [keepstation:DiveCmd:SurfaceSink:sink](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink 2025-08-22T10:24:58.666Z,1755858298.666 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy] Running Loop=1 2025-08-22T10:24:58.666Z,1755858298.666 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Initialize Buoyancy Component. 2025-08-22T10:24:58.666Z,1755858298.666 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed] Running Loop=1 2025-08-22T10:24:58.666Z,1755858298.666 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Initialize. 2025-08-22T10:24:58.666Z,1755858298.666 [keepstation:DiveCmd:SurfaceSink:sink:C] Running Loop=1 2025-08-22T10:24:58.666Z,1755858298.666 [keepstation:DiveCmd:SurfaceSink:sink:C](INFO): Sinking to 10.000000 m 2025-08-22T10:24:58.667Z,1755858298.667 [keepstation:DiveCmd:SurfaceSink:sink:C] Stopped 2025-08-22T10:24:58.667Z,1755858298.667 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch] Running Loop=1 2025-08-22T10:24:58.667Z,1755858298.667 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch](DEBUG): Initialize. 2025-08-22T10:25:08.690Z,1755858308.690 [NAL9602](INFO): SBD MO Status=0, MOMSN=22238, MT Status=0, MTMSN=0 2025-08-22T10:25:08.690Z,1755858308.690 [NAL9602](INFO): No messages in MT queue 2025-08-22T10:25:39.379Z,1755858339.379 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-22T10:26:58.048Z,1755858418.048 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2025-08-22T10:27:03.070Z,1755858423.070 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](IMPORTANT): Altitude envelope ACTIVE. Altitude:0.840000m. At depth:1.646273m. 2025-08-22T10:27:29.188Z,1755858449.188 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T10:27:54.600Z,1755858474.600 [Radio_Surface](INFO): Powering down 2025-08-22T10:27:58.795Z,1755858478.795 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch](INFO): Timed out from 2025-08-22T10:24:58.7Z 2025-08-22T10:27:58.796Z,1755858478.796 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout] Running Loop=1 2025-08-22T10:27:58.796Z,1755858478.796 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout 2025-08-22T10:27:58.796Z,1755858478.796 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout:A] Running Loop=1 2025-08-22T10:27:58.796Z,1755858478.796 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout:A](IMPORTANT): Timed out while trying to reach target sink depth at current depth of 5.819696 m 2025-08-22T10:27:58.797Z,1755858478.797 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout:A] Stopped 2025-08-22T10:27:58.797Z,1755858478.797 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout](INFO): Completed keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout 2025-08-22T10:27:58.797Z,1755858478.797 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch] Stopped 2025-08-22T10:27:58.797Z,1755858478.797 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit] Running Loop=1 2025-08-22T10:27:58.797Z,1755858478.797 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit 2025-08-22T10:27:58.797Z,1755858478.797 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit:A] Running Loop=1 2025-08-22T10:27:59.196Z,1755858479.196 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit] Stopped 2025-08-22T10:27:59.196Z,1755858479.196 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit 2025-08-22T10:27:59.196Z,1755858479.196 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit:A] Stopped 2025-08-22T10:27:59.196Z,1755858479.196 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation] Running Loop=1 2025-08-22T10:27:59.196Z,1755858479.196 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink:sinkToStation 2025-08-22T10:27:59.196Z,1755858479.196 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation:A] Running Loop=1 2025-08-22T10:27:59.604Z,1755858479.604 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation:A] Stopped 2025-08-22T10:27:59.604Z,1755858479.604 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation](INFO): Completed keepstation:DiveCmd:SurfaceSink:sink:sinkToStation 2025-08-22T10:27:59.604Z,1755858479.604 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation] Stopped 2025-08-22T10:27:59.604Z,1755858479.604 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink:sink:sinkToStation 2025-08-22T10:27:59.605Z,1755858479.605 [keepstation:DiveCmd:SurfaceSink:sink](INFO): Completed keepstation:DiveCmd:SurfaceSink:sink 2025-08-22T10:27:59.605Z,1755858479.605 [keepstation:DiveCmd:SurfaceSink:sink] Stopped 2025-08-22T10:27:59.605Z,1755858479.605 [keepstation:DiveCmd:SurfaceSink:sink](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink:sink 2025-08-22T10:27:59.605Z,1755858479.605 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy] Stopped 2025-08-22T10:27:59.605Z,1755858479.605 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2025-08-22T10:27:59.605Z,1755858479.605 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed] Stopped 2025-08-22T10:27:59.605Z,1755858479.605 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Uninitialize. 2025-08-22T10:27:59.605Z,1755858479.605 [keepstation:DiveCmd:SurfaceSink](INFO): Completed keepstation:DiveCmd:SurfaceSink 2025-08-22T10:28:00.032Z,1755858480.032 [keepstation:DiveCmd:StationKeep] Running Loop=1 2025-08-22T10:28:00.032Z,1755858480.032 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::initialize keepstation:DiveCmd:StationKeep 2025-08-22T10:28:00.032Z,1755858480.032 [keepstation:DiveCmd:StationKeep:A] Running Loop=1 2025-08-22T10:28:00.032Z,1755858480.032 [keepstation:DiveCmd:StationKeep:B.Pitch] Running Loop=1 2025-08-22T10:28:00.032Z,1755858480.032 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Initialize. 2025-08-22T10:28:00.032Z,1755858480.032 [keepstation:DiveCmd:StationKeep:C.KeepStation] Running Loop=1 2025-08-22T10:28:00.032Z,1755858480.032 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Initialize KeepStationComponent. 2025-08-22T10:28:00.034Z,1755858480.034 [keepstation:DiveCmd:StationKeep:C.KeepStation](INFO): Rest->Waypoint 2025-08-22T10:28:00.312Z,1755858480.312 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T10:28:00.406Z,1755858480.406 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 20.00 deg, mass-position 30.60 mm (1 active estimators). 2025-08-22T10:28:01.318Z,1755858481.318 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2025-08-22T10:29:14.627Z,1755858554.627 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.406128 2025-08-22T10:32:52.957Z,1755858772.957 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,00000000000000,35.0,+12,000 2025-08-22T10:32:52.958Z,1755858772.958 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+12,000 2025-08-22T10:38:23.729Z,1755859103.729 [keepstation:DiveCmd:StationKeep:C.KeepStation](INFO): Waypoint->Rest 2025-08-22T10:42:49.937Z,1755859369.937 [keepstation:DiveCmd:StationKeep:C.KeepStation](INFO): Rest->Waypoint 2025-08-22T10:52:10.545Z,1755859930.545 [keepstation:DiveCmd:StationKeep:C.KeepStation](INFO): Waypoint->Rest 2025-08-22T11:12:23.424Z,1755861143.424 [BPC1](ERROR): Battery stick #2 (s/n: 0124) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-08-22T11:12:23.425Z,1755861143.425 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6. 2025-08-22T11:12:23.428Z,1755861143.428 [BPC1](INFO): Received data from all battery sticks. 2025-08-22T11:18:13.721Z,1755861493.721 [DVL_micro](ERROR): only read 3 of 4 data items for bottom velocity. Device response is::BI,-00110,-00100,-0000,A 2025-08-22T11:18:13.721Z,1755861493.721 [DVL_micro](ERROR): Failed to parse: :BI,-00110,-00100,-0000,A 2025-08-22T11:18:16.098Z,1755861496.098 [DVL_micro](ERROR): Failed to parse: :SA,+00.01,-00.38,157.6 2025-08-22T11:22:52.051Z,1755861772.051 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,00000000000000,35.0,+12.5,489.0,000 2025-08-22T11:22:52.051Z,1755861772.051 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+12.5,489.0,000 2025-08-22T11:24:56.880Z,1755861896.880 [keepstation:SurfaceComms] Running Loop=1 2025-08-22T11:24:56.880Z,1755861896.880 [keepstation:SurfaceComms](DEBUG): Aggregate::initialize keepstation:SurfaceComms 2025-08-22T11:24:56.880Z,1755861896.880 [keepstation:SurfaceComms:A] Running Loop=1 2025-08-22T11:24:56.881Z,1755861896.881 [keepstation:SurfaceComms:A] Stopped 2025-08-22T11:24:56.881Z,1755861896.881 [keepstation:SurfaceComms:B] Running Loop=1 2025-08-22T11:24:56.881Z,1755861896.881 [keepstation:SurfaceComms:B](DEBUG): Aggregate::initialize keepstation:SurfaceComms:B 2025-08-22T11:24:57.286Z,1755861897.286 [keepstation:KeepStation:Dive] Stopped 2025-08-22T11:24:57.286Z,1755861897.286 [keepstation:KeepStation:Dive](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive 2025-08-22T11:24:57.286Z,1755861897.286 [keepstation:KeepStation:Dive:A] Stopped 2025-08-22T11:24:57.287Z,1755861897.287 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive:A 2025-08-22T11:24:57.287Z,1755861897.287 [keepstation:DiveCmd:StationKeep] Stopped 2025-08-22T11:24:57.287Z,1755861897.287 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:StationKeep 2025-08-22T11:24:57.287Z,1755861897.287 [keepstation:DiveCmd:StationKeep:A] Stopped 2025-08-22T11:24:57.287Z,1755861897.287 [keepstation:DiveCmd:StationKeep:B.Pitch] Stopped 2025-08-22T11:24:57.287Z,1755861897.287 [keepstation:DiveCmd:StationKeep:C.KeepStation] Stopped 2025-08-22T11:24:57.288Z,1755861897.288 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Uninitialize KeepStationComponent. 2025-08-22T11:24:57.289Z,1755861897.289 [keepstation:NeedComms] Running Loop=1 2025-08-22T11:24:57.289Z,1755861897.289 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms 2025-08-22T11:24:57.289Z,1755861897.289 [keepstation:NeedComms:B.GoToSurface] Running Loop=1 2025-08-22T11:24:57.289Z,1755861897.289 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-08-22T11:24:57.290Z,1755861897.290 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2025-08-22T11:24:57.290Z,1755861897.290 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2025-08-22T11:24:57.290Z,1755861897.290 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2025-08-22T11:24:57.291Z,1755861897.291 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds. 2025-08-22T11:24:57.291Z,1755861897.291 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-08-22T11:24:57.292Z,1755861897.292 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-08-22T11:24:57.292Z,1755861897.292 [keepstation:NeedComms:A] Running Loop=1 2025-08-22T11:24:57.293Z,1755861897.293 [keepstation:NeedComms:A](INFO): last time_fix was: 1755858296.000000 second since 1970/01/01T00:00:00Z 2025-08-22T11:24:57.293Z,1755861897.293 [keepstation:NeedComms:A] Stopped 2025-08-22T11:25:21.886Z,1755861921.886 [DVL_micro](ERROR): Failed to parse: :SA,+19.50,+00.29,149.4 2025-08-22T11:26:38.068Z,1755861998.068 [keepstation:NeedComms:C] Running Loop=1 2025-08-22T11:26:38.432Z,1755861998.432 [Radio_Surface](INFO): Powering up 2025-08-22T11:26:43.888Z,1755862003.888 [DataOverHttps](INFO): Radio surface powered ON. 2025-08-22T11:27:14.024Z,1755862034.024 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T11:27:16.051Z,1755862036.051 [NAL9602](INFO): SBD MO Status=2, MOMSN=22239, MT Status=2, MTMSN=0 2025-08-22T11:27:16.052Z,1755862036.052 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-22T11:27:41.090Z,1755862061.090 [DVL_micro](ERROR): Failed to parse: :RD,+0000.32,+0000.17,+0000.23,+0000.23 2025-08-22T11:27:45.156Z,1755862065.156 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T11:28:09.773Z,1755862089.773 [NAL9602](INFO): SBD MO Status=2, MOMSN=22239, MT Status=2, MTMSN=0 2025-08-22T11:28:09.773Z,1755862089.773 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-22T11:28:16.280Z,1755862096.280 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T11:28:47.404Z,1755862127.404 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T11:28:57.445Z,1755862137.445 [NAL9602](INFO): SBD MO Status=2, MOMSN=22239, MT Status=2, MTMSN=0 2025-08-22T11:28:57.445Z,1755862137.445 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-22T11:29:06.183Z,1755862146.183 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002808 2025-08-22T11:31:14.445Z,1755862274.445 [NAL9602](INFO): SBD MO Status=2, MOMSN=22239, MT Status=2, MTMSN=0 2025-08-22T11:31:14.445Z,1755862274.445 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-22T11:31:55.246Z,1755862315.246 [NAL9602](INFO): SBD MO Status=2, MOMSN=22239, MT Status=2, MTMSN=0 2025-08-22T11:31:55.247Z,1755862315.247 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-22T11:31:55.665Z,1755862315.665 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-08-22T11:31:56.867Z,1755862316.867 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,113156.00,A,3650.48551,N,12209.26764,W,0.330,96.41,220825,,,A*4C 2025-08-22T11:31:56.869Z,1755862316.869 [NAL9602](INFO): GPS fix at 20250822T113156: (36.841425, -122.154461) 2025-08-22T11:31:56.934Z,1755862316.934 [UniversalFixResidualReporter](INFO): Fix residual: 6.5 %DT, over the last 1745.7 m. Residual distance 112.7 m at bearing -73.2 degrees. Fix at (36.8414, -122.1545) with 373.1 m made good. 2025-08-22T11:31:56.949Z,1755862316.949 [keepstation:NeedComms:C] Stopped 2025-08-22T11:31:56.950Z,1755862316.950 [keepstation:NeedComms:D] Running Loop=1 2025-08-22T11:31:59.649Z,1755862319.649 [DataOverHttps](INFO): Sending 99 bytes from file Logs/20250822T043000/Courier0030.lzma 2025-08-22T11:32:10.546Z,1755862330.546 [DataOverHttps](INFO): Moved sent file to Logs/20250822T043000/Courier0030.lzma.bak 2025-08-22T11:32:10.546Z,1755862330.546 [DataOverHttps](INFO): SBD MOMSN=25880961 2025-08-22T11:32:28.648Z,1755862348.648 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-22T11:32:38.745Z,1755862358.745 [DataOverHttps](INFO): Sending 905 bytes from file Logs/20250822T043000/Express0031.lzma 2025-08-22T11:32:49.785Z,1755862369.785 [DataOverHttps](INFO): Moved sent file to Logs/20250822T043000/Express0031.lzma.bak 2025-08-22T11:32:49.786Z,1755862369.786 [DataOverHttps](INFO): SBD MOMSN=25880964 2025-08-22T11:32:51.324Z,1755862371.324 [keepstation:NeedComms:D] Stopped 2025-08-22T11:32:51.324Z,1755862371.324 [keepstation:NeedComms:E] Running Loop=1 2025-08-22T11:32:53.349Z,1755862373.349 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,113253.00,A,3650.48125,N,12209.25900,W,0.467,64.07,220825,,,A*48 2025-08-22T11:32:53.351Z,1755862373.351 [NAL9602](INFO): GPS fix at 20250822T113253: (36.841354, -122.154317) 2025-08-22T11:32:53.398Z,1755862373.398 [keepstation:NeedComms:E] Stopped 2025-08-22T11:32:53.398Z,1755862373.398 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms 2025-08-22T11:32:53.398Z,1755862373.398 [keepstation:NeedComms] Stopped 2025-08-22T11:32:53.399Z,1755862373.399 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms 2025-08-22T11:32:53.399Z,1755862373.399 [keepstation:NeedComms:B.GoToSurface] Stopped 2025-08-22T11:32:53.399Z,1755862373.399 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-08-22T11:32:53.785Z,1755862373.785 [keepstation:SurfaceComms:B](INFO): Completed keepstation:SurfaceComms:B 2025-08-22T11:32:53.785Z,1755862373.785 [keepstation:SurfaceComms:B] Stopped 2025-08-22T11:32:53.785Z,1755862373.785 [keepstation:SurfaceComms:B](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:B 2025-08-22T11:32:53.785Z,1755862373.785 [keepstation:SurfaceComms:setTransit] Running Loop=1 2025-08-22T11:32:53.785Z,1755862373.785 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setTransit 2025-08-22T11:32:53.785Z,1755862373.785 [keepstation:SurfaceComms:setTransit:A] Running Loop=1 2025-08-22T11:32:54.149Z,1755862374.149 [keepstation:SurfaceComms:setTransit] Stopped 2025-08-22T11:32:54.149Z,1755862374.149 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setTransit 2025-08-22T11:32:54.149Z,1755862374.149 [keepstation:SurfaceComms:setTransit:A] Stopped 2025-08-22T11:32:54.149Z,1755862374.149 [keepstation:SurfaceComms:setStation] Running Loop=1 2025-08-22T11:32:54.149Z,1755862374.149 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setStation 2025-08-22T11:32:54.149Z,1755862374.149 [keepstation:SurfaceComms:setStation:A] Running Loop=1 2025-08-22T11:32:54.571Z,1755862374.571 [keepstation:SurfaceComms:setStation] Stopped 2025-08-22T11:32:54.572Z,1755862374.572 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setStation 2025-08-22T11:32:54.572Z,1755862374.572 [keepstation:SurfaceComms:setStation:A] Stopped 2025-08-22T11:32:54.572Z,1755862374.572 [keepstation:SurfaceComms:setSink] Running Loop=1 2025-08-22T11:32:54.572Z,1755862374.572 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setSink 2025-08-22T11:32:54.572Z,1755862374.572 [keepstation:SurfaceComms:setSink:A] Running Loop=1 2025-08-22T11:32:55.043Z,1755862375.043 [keepstation:SurfaceComms:setSink:A] Stopped 2025-08-22T11:32:55.043Z,1755862375.043 [keepstation:SurfaceComms:setSink](INFO): Completed keepstation:SurfaceComms:setSink 2025-08-22T11:32:55.043Z,1755862375.043 [keepstation:SurfaceComms:setSink] Stopped 2025-08-22T11:32:55.047Z,1755862375.047 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setSink 2025-08-22T11:32:55.048Z,1755862375.048 [keepstation:SurfaceComms](INFO): Completed keepstation:SurfaceComms 2025-08-22T11:32:55.048Z,1755862375.048 [keepstation:SurfaceComms] Stopped 2025-08-22T11:32:55.048Z,1755862375.048 [keepstation:SurfaceComms](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms 2025-08-22T11:32:55.414Z,1755862375.414 [keepstation:KeepStation:Dive] Running Loop=1 2025-08-22T11:32:55.414Z,1755862375.414 [keepstation:KeepStation:Dive](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive 2025-08-22T11:32:55.414Z,1755862375.414 [keepstation:KeepStation:Dive:A] Running Loop=1 2025-08-22T11:32:55.414Z,1755862375.414 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive:A 2025-08-22T11:32:55.414Z,1755862375.414 [keepstation:DiveCmd:SurfaceSink] Running Loop=1 2025-08-22T11:32:55.415Z,1755862375.415 [keepstation:DiveCmd:SurfaceSink](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink 2025-08-22T11:32:55.415Z,1755862375.415 [keepstation:DiveCmd:SurfaceSink:sink] Running Loop=1 2025-08-22T11:32:55.415Z,1755862375.415 [keepstation:DiveCmd:SurfaceSink:sink](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink 2025-08-22T11:32:55.415Z,1755862375.415 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy] Running Loop=1 2025-08-22T11:32:55.415Z,1755862375.415 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Initialize Buoyancy Component. 2025-08-22T11:32:55.415Z,1755862375.415 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed] Running Loop=1 2025-08-22T11:32:55.415Z,1755862375.415 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Initialize. 2025-08-22T11:32:55.420Z,1755862375.420 [keepstation:DiveCmd:SurfaceSink:sink:C] Running Loop=1 2025-08-22T11:32:55.421Z,1755862375.421 [keepstation:DiveCmd:SurfaceSink:sink:C](INFO): Sinking to 10.000000 m 2025-08-22T11:32:55.421Z,1755862375.421 [keepstation:DiveCmd:SurfaceSink:sink:C] Stopped 2025-08-22T11:32:55.421Z,1755862375.421 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch] Running Loop=1 2025-08-22T11:32:55.421Z,1755862375.421 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch](DEBUG): Initialize. 2025-08-22T11:33:13.922Z,1755862393.922 [NAL9602](INFO): SBD MO Status=2, MOMSN=22239, MT Status=2, MTMSN=0 2025-08-22T11:33:13.923Z,1755862393.923 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-22T11:33:36.144Z,1755862416.144 [NAL9602](INFO): SBD MO Status=2, MOMSN=22239, MT Status=2, MTMSN=0 2025-08-22T11:33:36.144Z,1755862416.144 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-22T11:34:01.997Z,1755862441.997 [NAL9602](INFO): SBD MO Status=2, MOMSN=22239, MT Status=2, MTMSN=0 2025-08-22T11:34:01.997Z,1755862441.997 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-22T11:34:16.156Z,1755862456.156 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](IMPORTANT): Altitude envelope ACTIVE. Altitude:0.540000m. At depth:1.530942m. 2025-08-22T11:34:21.436Z,1755862461.436 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2025-08-22T11:34:52.576Z,1755862492.576 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T11:35:11.576Z,1755862511.576 [Radio_Surface](INFO): Powering down 2025-08-22T11:35:23.708Z,1755862523.708 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T11:35:24.712Z,1755862524.712 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2025-08-22T11:35:55.538Z,1755862555.538 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch](INFO): Timed out from 2025-08-22T11:32:55.4Z 2025-08-22T11:35:55.538Z,1755862555.538 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout] Running Loop=1 2025-08-22T11:35:55.538Z,1755862555.538 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout 2025-08-22T11:35:55.538Z,1755862555.538 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout:A] Running Loop=1 2025-08-22T11:35:55.539Z,1755862555.539 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout:A](IMPORTANT): Timed out while trying to reach target sink depth at current depth of 9.627758 m 2025-08-22T11:35:55.539Z,1755862555.539 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout:A] Stopped 2025-08-22T11:35:55.539Z,1755862555.539 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout](INFO): Completed keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout 2025-08-22T11:35:55.539Z,1755862555.539 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch] Stopped 2025-08-22T11:35:55.540Z,1755862555.540 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit] Running Loop=1 2025-08-22T11:35:55.540Z,1755862555.540 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit 2025-08-22T11:35:55.540Z,1755862555.540 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit:A] Running Loop=1 2025-08-22T11:35:55.959Z,1755862555.959 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit] Stopped 2025-08-22T11:35:55.959Z,1755862555.959 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit 2025-08-22T11:35:55.959Z,1755862555.959 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit:A] Stopped 2025-08-22T11:35:55.959Z,1755862555.959 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation] Running Loop=1 2025-08-22T11:35:55.959Z,1755862555.959 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink:sinkToStation 2025-08-22T11:35:55.959Z,1755862555.959 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation:A] Running Loop=1 2025-08-22T11:35:56.368Z,1755862556.368 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation:A] Stopped 2025-08-22T11:35:56.368Z,1755862556.368 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation](INFO): Completed keepstation:DiveCmd:SurfaceSink:sink:sinkToStation 2025-08-22T11:35:56.368Z,1755862556.368 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation] Stopped 2025-08-22T11:35:56.368Z,1755862556.368 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink:sink:sinkToStation 2025-08-22T11:35:56.369Z,1755862556.369 [keepstation:DiveCmd:SurfaceSink:sink](INFO): Completed keepstation:DiveCmd:SurfaceSink:sink 2025-08-22T11:35:56.369Z,1755862556.369 [keepstation:DiveCmd:SurfaceSink:sink] Stopped 2025-08-22T11:35:56.369Z,1755862556.369 [keepstation:DiveCmd:SurfaceSink:sink](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink:sink 2025-08-22T11:35:56.369Z,1755862556.369 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy] Stopped 2025-08-22T11:35:56.369Z,1755862556.369 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2025-08-22T11:35:56.369Z,1755862556.369 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed] Stopped 2025-08-22T11:35:56.369Z,1755862556.369 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Uninitialize. 2025-08-22T11:35:56.370Z,1755862556.370 [keepstation:DiveCmd:SurfaceSink](INFO): Completed keepstation:DiveCmd:SurfaceSink 2025-08-22T11:35:56.765Z,1755862556.765 [keepstation:DiveCmd:StationKeep] Running Loop=1 2025-08-22T11:35:56.765Z,1755862556.765 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::initialize keepstation:DiveCmd:StationKeep 2025-08-22T11:35:56.765Z,1755862556.765 [keepstation:DiveCmd:StationKeep:A] Running Loop=1 2025-08-22T11:35:56.765Z,1755862556.765 [keepstation:DiveCmd:StationKeep:B.Pitch] Running Loop=1 2025-08-22T11:35:56.765Z,1755862556.765 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Initialize. 2025-08-22T11:35:56.765Z,1755862556.765 [keepstation:DiveCmd:StationKeep:C.KeepStation] Running Loop=1 2025-08-22T11:35:56.765Z,1755862556.765 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Initialize KeepStationComponent. 2025-08-22T11:36:49.064Z,1755862609.064 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.763123 2025-08-22T11:37:55.626Z,1755862675.626 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-08-22T11:38:26.327Z,1755862706.327 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-22T11:44:50.540Z,1755863090.540 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+12.6,0000.0,1489.0,000 2025-08-22T11:45:16.388Z,1755863116.388 [DVL_micro](ERROR): Failed to parse: :RD,+0123.62,+0121.99,+9999.99,+0121.37 2025-08-22T11:47:12.765Z,1755863232.765 [DVL_micro](ERROR): only read 2 of 4 data items for beam range. Device response is::RD,+9999.99,+0112.64,+ 2025-08-22T11:47:12.766Z,1755863232.766 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+0112.64,+ 2025-08-22T11:58:23.013Z,1755863903.013 [DVL_micro](ERROR): Failed to parse: :SA,+02.46,+00.62,296.7 2025-08-22T12:01:16.746Z,1755864076.746 [DVL_micro](ERROR): Failed to parse: :SA,+00.15,+00.55,276.2 2025-08-22T12:09:40.523Z,1755864580.523 [DVL_micro](ERROR): only read 1 of 4 data items for beam range. Device response is::RD,+0117.50.87 2025-08-22T12:09:40.523Z,1755864580.523 [DVL_micro](ERROR): Failed to parse: :RD,+0117.50.87 2025-08-22T12:18:14.459Z,1755865094.459 [keepstation:DiveCmd:StationKeep:C.KeepStation](INFO): Rest->Waypoint 2025-08-22T12:19:58.869Z,1755865198.869 [BPC1](ERROR): Battery stick #2 (s/n: 0124) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-08-22T12:19:58.870Z,1755865198.870 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6. 2025-08-22T12:19:58.889Z,1755865198.889 [BPC1](INFO): Received data from all battery sticks. 2025-08-22T12:24:34.255Z,1755865474.255 [DVL_micro](ERROR): Failed to parse: :3,+00299,+00000,A 2025-08-22T12:25:51.940Z,1755865551.940 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2025-08-22T12:25:53.174Z,1755865553.174 [keepstation:DiveCmd:StationKeep:C.KeepStation](INFO): Waypoint->Rest 2025-08-22T12:26:32.007Z,1755865592.007 [DVL_micro](ERROR): DVL uart error: serial timeout 2025-08-22T12:26:32.007Z,1755865592.007 [DVL_micro] Communications Fault, FailCount= 1 2025-08-22T12:26:32.007Z,1755865592.007 [DVL_micro](ERROR): Communications Fault 2025-08-22T12:26:32.008Z,1755865592.008 [DVL_micro](ERROR): Failed to parse: 2025-08-22T12:26:32.228Z,1755865592.228 [CBIT](ERROR): Communications Fault in component: DVL_micro 2025-08-22T12:26:32.436Z,1755865592.436 [DVL_micro](INFO): Powering down 2025-08-22T12:26:33.300Z,1755865593.300 [CBIT](INFO): Clearing failed state for component DVL_micro 2025-08-22T12:26:33.300Z,1755865593.300 [DVL_micro] No Fault, FailCount= 1 2025-08-22T12:32:53.729Z,1755865973.729 [keepstation:SurfaceComms] Running Loop=1 2025-08-22T12:32:53.729Z,1755865973.729 [keepstation:SurfaceComms](DEBUG): Aggregate::initialize keepstation:SurfaceComms 2025-08-22T12:32:53.729Z,1755865973.729 [keepstation:SurfaceComms:A] Running Loop=1 2025-08-22T12:32:53.730Z,1755865973.730 [keepstation:SurfaceComms:A] Stopped 2025-08-22T12:32:53.730Z,1755865973.730 [keepstation:SurfaceComms:B] Running Loop=1 2025-08-22T12:32:53.730Z,1755865973.730 [keepstation:SurfaceComms:B](DEBUG): Aggregate::initialize keepstation:SurfaceComms:B 2025-08-22T12:32:54.128Z,1755865974.128 [keepstation:KeepStation:Dive] Stopped 2025-08-22T12:32:54.128Z,1755865974.128 [keepstation:KeepStation:Dive](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive 2025-08-22T12:32:54.128Z,1755865974.128 [keepstation:KeepStation:Dive:A] Stopped 2025-08-22T12:32:54.128Z,1755865974.128 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive:A 2025-08-22T12:32:54.129Z,1755865974.129 [keepstation:DiveCmd:StationKeep] Stopped 2025-08-22T12:32:54.129Z,1755865974.129 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:StationKeep 2025-08-22T12:32:54.129Z,1755865974.129 [keepstation:DiveCmd:StationKeep:A] Stopped 2025-08-22T12:32:54.129Z,1755865974.129 [keepstation:DiveCmd:StationKeep:B.Pitch] Stopped 2025-08-22T12:32:54.129Z,1755865974.129 [keepstation:DiveCmd:StationKeep:C.KeepStation] Stopped 2025-08-22T12:32:54.129Z,1755865974.129 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Uninitialize KeepStationComponent. 2025-08-22T12:32:54.131Z,1755865974.131 [keepstation:NeedComms] Running Loop=1 2025-08-22T12:32:54.131Z,1755865974.131 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms 2025-08-22T12:32:54.131Z,1755865974.131 [keepstation:NeedComms:B.GoToSurface] Running Loop=1 2025-08-22T12:32:54.131Z,1755865974.131 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-08-22T12:32:54.132Z,1755865974.132 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2025-08-22T12:32:54.132Z,1755865974.132 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2025-08-22T12:32:54.132Z,1755865974.132 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2025-08-22T12:32:54.133Z,1755865974.133 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds. 2025-08-22T12:32:54.133Z,1755865974.133 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-08-22T12:32:54.133Z,1755865974.133 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-08-22T12:32:54.134Z,1755865974.134 [keepstation:NeedComms:A] Running Loop=1 2025-08-22T12:32:54.135Z,1755865974.135 [keepstation:NeedComms:A](INFO): last time_fix was: 1755862373.000000 second since 1970/01/01T00:00:00Z 2025-08-22T12:32:54.135Z,1755865974.135 [keepstation:NeedComms:A] Stopped 2025-08-22T12:34:13.288Z,1755866053.288 [keepstation:NeedComms:C] Running Loop=1 2025-08-22T12:34:13.964Z,1755866053.964 [Radio_Surface](INFO): Powering up 2025-08-22T12:34:19.360Z,1755866059.360 [DataOverHttps](INFO): Radio surface powered ON. 2025-08-22T12:34:46.154Z,1755866086.154 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2025-08-22T12:34:46.231Z,1755866086.231 [NAL9602](ERROR): received: +CSQ:0 OK239, 2, 0, 0, 0 OK 2025-08-22T12:34:49.480Z,1755866089.480 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T12:35:20.612Z,1755866120.612 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T12:35:51.736Z,1755866151.736 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T12:36:22.868Z,1755866182.868 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T12:36:41.492Z,1755866201.492 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003119 2025-08-22T12:37:52.797Z,1755866272.797 [NAL9602](INFO): SBD MO Status=2, MOMSN=22239, MT Status=2, MTMSN=0 2025-08-22T12:37:52.797Z,1755866272.797 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-22T12:38:10.993Z,1755866290.993 [NAL9602](INFO): SBD MO Status=2, MOMSN=22239, MT Status=2, MTMSN=0 2025-08-22T12:38:10.993Z,1755866290.993 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-22T12:38:39.279Z,1755866319.279 [NAL9602](INFO): SBD MO Status=0, MOMSN=22239, MT Status=0, MTMSN=0 2025-08-22T12:38:39.279Z,1755866319.279 [NAL9602](INFO): No messages in MT queue 2025-08-22T12:38:40.488Z,1755866320.488 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,123840.00,A,3650.38205,N,12209.41569,W,0.836,197.11,220825,,,A*76 2025-08-22T12:38:40.490Z,1755866320.490 [NAL9602](INFO): GPS fix at 20250822T123840: (36.839701, -122.156928) 2025-08-22T12:38:40.503Z,1755866320.503 [UniversalFixResidualReporter](INFO): Fix residual: 17.3 %DT, over the last 1328.3 m. Residual distance 230.3 m at bearing -151.6 degrees. Fix at (36.8397, -122.1569) with 296.3 m made good. 2025-08-22T12:38:40.506Z,1755866320.506 [keepstation:NeedComms:C] Stopped 2025-08-22T12:38:40.507Z,1755866320.507 [keepstation:NeedComms:D] Running Loop=1 2025-08-22T12:38:52.731Z,1755866332.731 [DataOverHttps](INFO): Sending 98 bytes from file Logs/20250822T043000/Courier0033.lzma 2025-08-22T12:39:03.725Z,1755866343.725 [DataOverHttps](INFO): Moved sent file to Logs/20250822T043000/Courier0033.lzma.bak 2025-08-22T12:39:03.726Z,1755866343.726 [DataOverHttps](INFO): SBD MOMSN=25881133 2025-08-22T12:39:12.809Z,1755866352.809 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-22T12:39:30.081Z,1755866370.081 [DataOverHttps](INFO): Sending 733 bytes from file Logs/20250822T043000/Express0034.lzma 2025-08-22T12:39:41.121Z,1755866381.121 [DataOverHttps](INFO): Moved sent file to Logs/20250822T043000/Express0034.lzma.bak 2025-08-22T12:39:41.122Z,1755866381.122 [DataOverHttps](INFO): SBD MOMSN=25881137 2025-08-22T12:39:42.325Z,1755866382.325 [keepstation:NeedComms:D] Stopped 2025-08-22T12:39:42.326Z,1755866382.326 [keepstation:NeedComms:E] Running Loop=1 2025-08-22T12:39:44.315Z,1755866384.315 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,123944.00,A,3650.37589,N,12209.41023,W,0.583,82.93,220825,,,A*48 2025-08-22T12:39:44.317Z,1755866384.317 [NAL9602](INFO): GPS fix at 20250822T123944: (36.839598, -122.156837) 2025-08-22T12:39:44.362Z,1755866384.362 [keepstation:NeedComms:E] Stopped 2025-08-22T12:39:44.363Z,1755866384.363 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms 2025-08-22T12:39:44.363Z,1755866384.363 [keepstation:NeedComms] Stopped 2025-08-22T12:39:44.363Z,1755866384.363 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms 2025-08-22T12:39:44.363Z,1755866384.363 [keepstation:NeedComms:B.GoToSurface] Stopped 2025-08-22T12:39:44.363Z,1755866384.363 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-08-22T12:39:44.801Z,1755866384.801 [keepstation:SurfaceComms:B](INFO): Completed keepstation:SurfaceComms:B 2025-08-22T12:39:44.801Z,1755866384.801 [keepstation:SurfaceComms:B] Stopped 2025-08-22T12:39:44.801Z,1755866384.801 [keepstation:SurfaceComms:B](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:B 2025-08-22T12:39:44.801Z,1755866384.801 [keepstation:SurfaceComms:setTransit] Running Loop=1 2025-08-22T12:39:44.801Z,1755866384.801 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setTransit 2025-08-22T12:39:44.801Z,1755866384.801 [keepstation:SurfaceComms:setTransit:A] Running Loop=1 2025-08-22T12:39:45.152Z,1755866385.152 [keepstation:SurfaceComms:setTransit] Stopped 2025-08-22T12:39:45.153Z,1755866385.153 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setTransit 2025-08-22T12:39:45.153Z,1755866385.153 [keepstation:SurfaceComms:setTransit:A] Stopped 2025-08-22T12:39:45.153Z,1755866385.153 [keepstation:SurfaceComms:setStation] Running Loop=1 2025-08-22T12:39:45.153Z,1755866385.153 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setStation 2025-08-22T12:39:45.153Z,1755866385.153 [keepstation:SurfaceComms:setStation:A] Running Loop=1 2025-08-22T12:39:45.560Z,1755866385.560 [keepstation:SurfaceComms:setStation] Stopped 2025-08-22T12:39:45.560Z,1755866385.560 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setStation 2025-08-22T12:39:45.560Z,1755866385.560 [keepstation:SurfaceComms:setStation:A] Stopped 2025-08-22T12:39:45.560Z,1755866385.560 [keepstation:SurfaceComms:setSink] Running Loop=1 2025-08-22T12:39:45.560Z,1755866385.560 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setSink 2025-08-22T12:39:45.560Z,1755866385.560 [keepstation:SurfaceComms:setSink:A] Running Loop=1 2025-08-22T12:39:45.984Z,1755866385.984 [keepstation:SurfaceComms:setSink:A] Stopped 2025-08-22T12:39:45.985Z,1755866385.985 [keepstation:SurfaceComms:setSink](INFO): Completed keepstation:SurfaceComms:setSink 2025-08-22T12:39:45.985Z,1755866385.985 [keepstation:SurfaceComms:setSink] Stopped 2025-08-22T12:39:45.985Z,1755866385.985 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setSink 2025-08-22T12:39:45.985Z,1755866385.985 [keepstation:SurfaceComms](INFO): Completed keepstation:SurfaceComms 2025-08-22T12:39:45.985Z,1755866385.985 [keepstation:SurfaceComms] Stopped 2025-08-22T12:39:45.985Z,1755866385.985 [keepstation:SurfaceComms](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms 2025-08-22T12:39:46.385Z,1755866386.385 [keepstation:KeepStation:Dive] Running Loop=1 2025-08-22T12:39:46.386Z,1755866386.386 [keepstation:KeepStation:Dive](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive 2025-08-22T12:39:46.386Z,1755866386.386 [keepstation:KeepStation:Dive:A] Running Loop=1 2025-08-22T12:39:46.386Z,1755866386.386 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive:A 2025-08-22T12:39:46.386Z,1755866386.386 [keepstation:DiveCmd:SurfaceSink] Running Loop=1 2025-08-22T12:39:46.386Z,1755866386.386 [keepstation:DiveCmd:SurfaceSink](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink 2025-08-22T12:39:46.387Z,1755866386.387 [keepstation:DiveCmd:SurfaceSink:sink] Running Loop=1 2025-08-22T12:39:46.387Z,1755866386.387 [keepstation:DiveCmd:SurfaceSink:sink](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink 2025-08-22T12:39:46.387Z,1755866386.387 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy] Running Loop=1 2025-08-22T12:39:46.387Z,1755866386.387 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Initialize Buoyancy Component. 2025-08-22T12:39:46.387Z,1755866386.387 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed] Running Loop=1 2025-08-22T12:39:46.387Z,1755866386.387 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Initialize. 2025-08-22T12:39:46.387Z,1755866386.387 [keepstation:DiveCmd:SurfaceSink:sink:C] Running Loop=1 2025-08-22T12:39:46.392Z,1755866386.392 [keepstation:DiveCmd:SurfaceSink:sink:C](INFO): Sinking to 10.000000 m 2025-08-22T12:39:46.392Z,1755866386.392 [keepstation:DiveCmd:SurfaceSink:sink:C] Stopped 2025-08-22T12:39:46.392Z,1755866386.392 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch] Running Loop=1 2025-08-22T12:39:46.392Z,1755866386.392 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch](DEBUG): Initialize. 2025-08-22T12:40:17.039Z,1755866417.039 [NAL9602](INFO): SBD MO Status=0, MOMSN=22240, MT Status=0, MTMSN=0 2025-08-22T12:40:17.039Z,1755866417.039 [NAL9602](INFO): No messages in MT queue 2025-08-22T12:40:47.769Z,1755866447.769 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-22T12:41:13.112Z,1755866473.112 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T12:41:44.236Z,1755866504.236 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T12:41:54.556Z,1755866514.556 [Radio_Surface](INFO): Powering down 2025-08-22T12:42:15.360Z,1755866535.360 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T12:42:16.364Z,1755866536.364 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2025-08-22T12:42:46.548Z,1755866566.548 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch](INFO): Timed out from 2025-08-22T12:39:46.4Z 2025-08-22T12:42:46.548Z,1755866566.548 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout] Running Loop=1 2025-08-22T12:42:46.548Z,1755866566.548 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout 2025-08-22T12:42:46.548Z,1755866566.548 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout:A] Running Loop=1 2025-08-22T12:42:46.549Z,1755866566.549 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout:A](IMPORTANT): Timed out while trying to reach target sink depth at current depth of 8.041449 m 2025-08-22T12:42:46.549Z,1755866566.549 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout:A] Stopped 2025-08-22T12:42:46.549Z,1755866566.549 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout](INFO): Completed keepstation:DiveCmd:SurfaceSink:sink:D.Pitch:A_Timeout 2025-08-22T12:42:46.549Z,1755866566.549 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch] Stopped 2025-08-22T12:42:46.549Z,1755866566.549 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit] Running Loop=1 2025-08-22T12:42:46.549Z,1755866566.549 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit 2025-08-22T12:42:46.549Z,1755866566.549 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit:A] Running Loop=1 2025-08-22T12:42:46.951Z,1755866566.951 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit] Stopped 2025-08-22T12:42:46.951Z,1755866566.951 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit 2025-08-22T12:42:46.951Z,1755866566.951 [keepstation:DiveCmd:SurfaceSink:sink:sinkToTransit:A] Stopped 2025-08-22T12:42:46.951Z,1755866566.951 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation] Running Loop=1 2025-08-22T12:42:46.951Z,1755866566.951 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink:sinkToStation 2025-08-22T12:42:46.951Z,1755866566.951 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation:A] Running Loop=1 2025-08-22T12:42:47.364Z,1755866567.364 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation:A] Stopped 2025-08-22T12:42:47.364Z,1755866567.364 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation](INFO): Completed keepstation:DiveCmd:SurfaceSink:sink:sinkToStation 2025-08-22T12:42:47.364Z,1755866567.364 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation] Stopped 2025-08-22T12:42:47.364Z,1755866567.364 [keepstation:DiveCmd:SurfaceSink:sink:sinkToStation](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink:sink:sinkToStation 2025-08-22T12:42:47.365Z,1755866567.365 [keepstation:DiveCmd:SurfaceSink:sink](INFO): Completed keepstation:DiveCmd:SurfaceSink:sink 2025-08-22T12:42:47.365Z,1755866567.365 [keepstation:DiveCmd:SurfaceSink:sink] Stopped 2025-08-22T12:42:47.365Z,1755866567.365 [keepstation:DiveCmd:SurfaceSink:sink](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink:sink 2025-08-22T12:42:47.365Z,1755866567.365 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy] Stopped 2025-08-22T12:42:47.365Z,1755866567.365 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2025-08-22T12:42:47.365Z,1755866567.365 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed] Stopped 2025-08-22T12:42:47.365Z,1755866567.365 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Uninitialize. 2025-08-22T12:42:47.365Z,1755866567.365 [keepstation:DiveCmd:SurfaceSink](INFO): Completed keepstation:DiveCmd:SurfaceSink 2025-08-22T12:42:47.785Z,1755866567.785 [keepstation:DiveCmd:StationKeep] Running Loop=1 2025-08-22T12:42:47.785Z,1755866567.785 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::initialize keepstation:DiveCmd:StationKeep 2025-08-22T12:42:47.785Z,1755866567.785 [keepstation:DiveCmd:StationKeep:A] Running Loop=1 2025-08-22T12:42:47.786Z,1755866567.786 [keepstation:DiveCmd:StationKeep:B.Pitch] Running Loop=1 2025-08-22T12:42:47.786Z,1755866567.786 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Initialize. 2025-08-22T12:42:47.786Z,1755866567.786 [keepstation:DiveCmd:StationKeep:C.KeepStation] Running Loop=1 2025-08-22T12:42:47.786Z,1755866567.786 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Initialize KeepStationComponent. 2025-08-22T12:43:31.712Z,1755866611.712 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.771393 2025-08-22T12:59:48.254Z,1755867588.254 [DVL_micro](ERROR): Failed to parse: :WI,+00146,+00137,-00042,+00000,A