2025-01-15T23:47:37.373Z,1736984857.373 [CommandExec](IMPORTANT): got command set optimize_roll_speed.NeedCommsTime 60 minute
2025-01-15T23:47:37.374Z,1736984857.374 [CommandExec](IMPORTANT): got command set optimize_roll_speed.Latitude 36.797 degree
2025-01-15T23:47:37.375Z,1736984857.375 [CommandExec](IMPORTANT): got command set optimize_roll_speed.Longitude -121.847 degree
2025-01-15T23:47:37.375Z,1736984857.375 [CommandExec](IMPORTANT): got command set optimize_roll_speed.RollError 0.5 degree
2025-01-15T23:47:37.378Z,1736984857.378 [CommandExec](IMPORTANT): got command restart logs
2025-01-15T23:47:48.852Z,1736984868.852 [CommandExec](IMPORTANT): got command set optimize_roll_speed.WindowLen 10 minute
2025-01-15T23:47:48.875Z,1736984868.875 [CommandExec](IMPORTANT): got command run
2025-01-15T23:47:48.908Z,1736984868.908 [Default] Stopped
2025-01-15T23:47:48.908Z,1736984868.908 [Default](DEBUG): Aggregate::uninitialize Default
2025-01-15T23:47:48.908Z,1736984868.908 [Default:B.GoToSurface] Stopped
2025-01-15T23:47:48.908Z,1736984868.908 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-01-15T23:47:48.908Z,1736984868.908 [Default:CheckIn] Stopped
2025-01-15T23:47:48.908Z,1736984868.908 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-01-15T23:47:48.908Z,1736984868.908 [Default:CheckIn:C.Wait] Stopped
2025-01-15T23:47:48.908Z,1736984868.908 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-01-15T23:47:48.909Z,1736984868.909 [MissionManager](IMPORTANT): Started mission optimize_roll_speed
2025-01-15T23:47:48.909Z,1736984868.909 [optimize_roll_speed] Running Loop=1
2025-01-15T23:47:48.909Z,1736984868.909 [optimize_roll_speed](DEBUG): Aggregate::initialize optimize_roll_speed
2025-01-15T23:47:48.909Z,1736984868.909 [optimize_roll_speed:StandardEnvelopes] Running Loop=1
2025-01-15T23:47:48.909Z,1736984868.909 [optimize_roll_speed:StandardEnvelopes](DEBUG): Aggregate::initialize optimize_roll_speed:StandardEnvelopes
2025-01-15T23:47:48.909Z,1736984868.909 [optimize_roll_speed:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2025-01-15T23:47:48.909Z,1736984868.909 [optimize_roll_speed:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2025-01-15T23:47:48.910Z,1736984868.910 [optimize_roll_speed:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2025-01-15T23:47:48.910Z,1736984868.910 [optimize_roll_speed:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2025-01-15T23:47:48.910Z,1736984868.910 [optimize_roll_speed:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2025-01-15T23:47:48.910Z,1736984868.910 [optimize_roll_speed:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2025-01-15T23:47:48.910Z,1736984868.910 [optimize_roll_speed:BackseatDriver] Running Loop=1
2025-01-15T23:47:48.910Z,1736984868.910 [optimize_roll_speed:BackseatDriver](DEBUG): Aggregate::initialize optimize_roll_speed:BackseatDriver
2025-01-15T23:47:48.910Z,1736984868.910 [optimize_roll_speed:BackseatDriver:A.BackseatDriver] Running Loop=1
2025-01-15T23:47:48.910Z,1736984868.910 [optimize_roll_speed:PowerOnly] Running Loop=1
2025-01-15T23:47:48.910Z,1736984868.910 [optimize_roll_speed:PowerOnly](DEBUG): Aggregate::initialize optimize_roll_speed:PowerOnly
2025-01-15T23:47:48.910Z,1736984868.910 [optimize_roll_speed:PowerOnly:A] Running Loop=1
2025-01-15T23:47:48.910Z,1736984868.910 [optimize_roll_speed:PowerOnly:B] Running Loop=1
2025-01-15T23:47:48.911Z,1736984868.911 [optimize_roll_speed:PowerOnly:C] Running Loop=1
2025-01-15T23:47:48.911Z,1736984868.911 [optimize_roll_speed:PowerOnly:D] Running Loop=1
2025-01-15T23:47:48.911Z,1736984868.911 [optimize_roll_speed:PowerOnly:E.Wait] Running Loop=1
2025-01-15T23:47:48.911Z,1736984868.911 [optimize_roll_speed:PowerOnly:E.Wait](DEBUG): Initialize Wait Component.
2025-01-15T23:47:48.911Z,1736984868.911 [optimize_roll_speed:BuoyancyHold.Buoyancy] Running Loop=1
2025-01-15T23:47:48.911Z,1736984868.911 [optimize_roll_speed:BuoyancyHold.Buoyancy](DEBUG): Initialize Buoyancy Component.
2025-01-15T23:47:48.911Z,1736984868.911 [optimize_roll_speed:MassHold.Pitch] Running Loop=1
2025-01-15T23:47:48.911Z,1736984868.911 [optimize_roll_speed:MassHold.Pitch](DEBUG): Initialize.
2025-01-15T23:47:48.911Z,1736984868.911 [optimize_roll_speed:B] Running Loop=1
2025-01-15T23:47:48.912Z,1736984868.912 [optimize_roll_speed:MassHold.Pitch] Running Loop=1
2025-01-15T23:47:48.912Z,1736984868.912 [optimize_roll_speed:BuoyancyHold.Buoyancy] Running Loop=1
2025-01-15T23:47:48.913Z,1736984868.913 [optimize_roll_speed:PowerOnly] Running Loop=1
2025-01-15T23:47:48.913Z,1736984868.913 [optimize_roll_speed:PowerOnly:D] Stopped
2025-01-15T23:47:48.913Z,1736984868.913 [optimize_roll_speed:PowerOnly:C] Stopped
2025-01-15T23:47:48.913Z,1736984868.913 [optimize_roll_speed:PowerOnly:B] Stopped
2025-01-15T23:47:48.913Z,1736984868.913 [optimize_roll_speed:PowerOnly:A] Stopped
2025-01-15T23:47:48.913Z,1736984868.913 [optimize_roll_speed:BackseatDriver] Running Loop=1
2025-01-15T23:47:48.913Z,1736984868.913 [optimize_roll_speed:StandardEnvelopes] Running Loop=1
2025-01-15T23:47:48.914Z,1736984868.914 [optimize_roll_speed:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2025-01-15T23:47:48.914Z,1736984868.914 [optimize_roll_speed:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2025-01-15T23:47:48.914Z,1736984868.914 [optimize_roll_speed:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2025-01-15T23:47:48.915Z,1736984868.915 [optimize_roll_speed:B] Stopped
2025-01-15T23:47:48.915Z,1736984868.915 [optimize_roll_speed:C] Running Loop=1
2025-01-15T23:47:49.295Z,1736984869.295 [optimize_roll_speed:C] Stopped
2025-01-15T23:47:49.295Z,1736984869.295 [optimize_roll_speed:E] Running Loop=1
2025-01-15T23:47:49.669Z,1736984869.669 [CommandExec](IMPORTANT): Running 
2025-01-15T23:47:49.770Z,1736984869.770 [optimize_roll_speed:E] Stopped
2025-01-15T23:47:49.770Z,1736984869.770 [optimize_roll_speed:F] Running Loop=1
2025-01-15T23:47:50.131Z,1736984870.131 [optimize_roll_speed:F] Stopped
2025-01-15T23:47:50.131Z,1736984870.131 [optimize_roll_speed:G] Running Loop=1
2025-01-15T23:47:50.511Z,1736984870.511 [optimize_roll_speed:G] Stopped
2025-01-15T23:47:50.511Z,1736984870.511 [optimize_roll_speed:StartingMission] Running Loop=1
2025-01-15T23:47:50.511Z,1736984870.511 [optimize_roll_speed:StartingMission](DEBUG): Aggregate::initialize optimize_roll_speed:StartingMission
2025-01-15T23:47:50.919Z,1736984870.919 [optimize_roll_speed:NeedComms] Running Loop=1
2025-01-15T23:47:50.919Z,1736984870.919 [optimize_roll_speed:NeedComms](DEBUG): Aggregate::initialize optimize_roll_speed:NeedComms
2025-01-15T23:47:50.919Z,1736984870.919 [optimize_roll_speed:NeedComms:B.GoToSurface] Running Loop=1
2025-01-15T23:47:50.919Z,1736984870.919 [optimize_roll_speed:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-01-15T23:47:50.919Z,1736984870.919 [optimize_roll_speed:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2025-01-15T23:47:50.920Z,1736984870.920 [optimize_roll_speed:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2025-01-15T23:47:50.920Z,1736984870.920 [optimize_roll_speed:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2025-01-15T23:47:50.920Z,1736984870.920 [optimize_roll_speed:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds.
2025-01-15T23:47:50.925Z,1736984870.925 [optimize_roll_speed:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-01-15T23:47:50.925Z,1736984870.925 [optimize_roll_speed:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-01-15T23:47:50.926Z,1736984870.926 [optimize_roll_speed:NeedComms:A] Running Loop=1
2025-01-15T23:47:50.927Z,1736984870.927 [optimize_roll_speed:NeedComms:A](INFO): last time_fix was:  1736984570.000000 second since 1970/01/01T00:00:00Z 
2025-01-15T23:47:50.927Z,1736984870.927 [optimize_roll_speed:NeedComms:A] Stopped
2025-01-15T23:47:51.307Z,1736984871.307 [optimize_roll_speed:NeedComms:C] Running Loop=1
2025-01-15T23:47:51.711Z,1736984871.711 [optimize_roll_speed:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-01-15T23:47:53.321Z,1736984873.321 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,234752.00,A,3647.84354,N,12149.62168,W,0.194,256.05,150125,,,D*7A
2025-01-15T23:47:53.323Z,1736984873.323 [NAL9602](INFO): GPS fix at 20250115T234752: (36.797392, -121.827028)
2025-01-15T23:47:53.375Z,1736984873.375 [optimize_roll_speed:NeedComms:C] Stopped
2025-01-15T23:47:53.375Z,1736984873.375 [optimize_roll_speed:NeedComms:D] Running Loop=1
2025-01-15T23:47:53.822Z,1736984873.822 [optimize_roll_speed:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-01-15T23:47:57.991Z,1736984877.991 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250115T231445/Courier0006.lzma
2025-01-15T23:47:58.735Z,1736984878.735 [DataOverHttps](INFO): Moved sent file to Logs/20250115T231445/Courier0006.lzma.bak
2025-01-15T23:47:58.735Z,1736984878.735 [DataOverHttps](INFO): SBD MOMSN=23908128
2025-01-15T23:48:12.143Z,1736984892.143 [NAL9602](INFO): SBD MO Status=1, MOMSN=11750, MT Status=0, MTMSN=0
2025-01-15T23:48:12.143Z,1736984892.143 [NAL9602](INFO): No messages in MT queue
2025-01-15T23:48:15.631Z,1736984895.631 [DataOverHttps](INFO): Sending 269 bytes from file Logs/20250115T234737/Courier0000.lzma
2025-01-15T23:48:16.631Z,1736984896.631 [DataOverHttps](INFO): Moved sent file to Logs/20250115T234737/Courier0000.lzma.bak
2025-01-15T23:48:16.631Z,1736984896.631 [DataOverHttps](INFO): SBD MOMSN=23908130
2025-01-15T23:48:33.088Z,1736984913.088 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250115T234737/Courier0003.lzma
2025-01-15T23:48:34.090Z,1736984914.090 [DataOverHttps](INFO): Moved sent file to Logs/20250115T234737/Courier0003.lzma.bak
2025-01-15T23:48:34.090Z,1736984914.090 [DataOverHttps](INFO): SBD MOMSN=23908134
2025-01-15T23:48:42.818Z,1736984922.818 [NAL9602](INFO): Not Powering down - fast GPS
2025-01-15T23:48:50.439Z,1736984930.439 [DataOverHttps](INFO): Sending 1350 bytes from file Logs/20250115T231445/Express0007.lzma
2025-01-15T23:48:51.439Z,1736984931.439 [DataOverHttps](INFO): Moved sent file to Logs/20250115T231445/Express0007.lzma.bak
2025-01-15T23:48:51.439Z,1736984931.439 [DataOverHttps](INFO): SBD MOMSN=23908137
2025-01-15T23:49:11.549Z,1736984951.549 [DataOverHttps](INFO): Sending 510 bytes from file Logs/20250115T234737/Express0001.lzma
2025-01-15T23:49:12.551Z,1736984952.551 [DataOverHttps](INFO): Moved sent file to Logs/20250115T234737/Express0001.lzma.bak
2025-01-15T23:49:12.551Z,1736984952.551 [DataOverHttps](INFO): SBD MOMSN=23908151
2025-01-15T23:49:28.892Z,1736984968.892 [DataOverHttps](INFO): Sending 197 bytes from file Logs/20250115T234737/Express0004.lzma
2025-01-15T23:49:29.894Z,1736984969.894 [DataOverHttps](INFO): Moved sent file to Logs/20250115T234737/Express0004.lzma.bak
2025-01-15T23:49:29.895Z,1736984969.895 [DataOverHttps](INFO): SBD MOMSN=23908162
2025-01-15T23:49:30.971Z,1736984970.971 [optimize_roll_speed:NeedComms:D] Stopped
2025-01-15T23:49:30.971Z,1736984970.971 [optimize_roll_speed:NeedComms:E] Running Loop=1
2025-01-15T23:49:31.355Z,1736984971.355 [optimize_roll_speed:NeedComms:E](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-01-15T23:49:32.953Z,1736984972.953 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,234932.00,A,3647.84279,N,12149.62906,W,0.622,253.74,150125,,,D*75
2025-01-15T23:49:32.955Z,1736984972.955 [NAL9602](INFO): GPS fix at 20250115T234932: (36.797380, -121.827151)
2025-01-15T23:49:32.981Z,1736984972.981 [optimize_roll_speed:NeedComms:E] Stopped
2025-01-15T23:49:32.982Z,1736984972.982 [optimize_roll_speed:NeedComms](INFO): Completed optimize_roll_speed:NeedComms
2025-01-15T23:49:32.982Z,1736984972.982 [optimize_roll_speed:NeedComms] Stopped
2025-01-15T23:49:32.982Z,1736984972.982 [optimize_roll_speed:NeedComms](DEBUG): Aggregate::uninitialize optimize_roll_speed:NeedComms
2025-01-15T23:49:32.983Z,1736984972.983 [optimize_roll_speed:NeedComms:B.GoToSurface] Stopped
2025-01-15T23:49:32.983Z,1736984972.983 [optimize_roll_speed:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-01-15T23:49:33.394Z,1736984973.394 [optimize_roll_speed:StartingMission](INFO): Completed optimize_roll_speed:StartingMission
2025-01-15T23:49:33.394Z,1736984973.394 [optimize_roll_speed:StartingMission] Stopped
2025-01-15T23:49:33.394Z,1736984973.394 [optimize_roll_speed:StartingMission](DEBUG): Aggregate::uninitialize optimize_roll_speed:StartingMission
2025-01-15T23:49:33.394Z,1736984973.394 [optimize_roll_speed:Transit] Running Loop=1
2025-01-15T23:49:33.394Z,1736984973.394 [optimize_roll_speed:Transit](DEBUG): Aggregate::initialize optimize_roll_speed:Transit
2025-01-15T23:49:33.394Z,1736984973.394 [optimize_roll_speed:Transit:A.Pitch] Running Loop=1
2025-01-15T23:49:33.394Z,1736984973.394 [optimize_roll_speed:Transit:A.Pitch](DEBUG): Initialize.
2025-01-15T23:49:33.395Z,1736984973.395 [optimize_roll_speed:Transit:B.SetRollSpeed] Running Loop=1
2025-01-15T23:49:33.395Z,1736984973.395 [optimize_roll_speed:Transit:B.SetRollSpeed](DEBUG): Initialize.
2025-01-15T23:49:33.396Z,1736984973.396 [optimize_roll_speed:Transit:Wpt1.Waypoint] Running Loop=1
2025-01-15T23:49:33.396Z,1736984973.396 [optimize_roll_speed:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2025-01-15T23:49:33.401Z,1736984973.401 [optimize_roll_speed:Transit:Wpt1.Waypoint](IMPORTANT): Navigating to waypoint: 36.797001,-121.847000
2025-01-15T23:49:33.794Z,1736984973.794 [optimize_roll_speed:Transit:Wpt1.Waypoint](INFO): Navigating to waypoint: 36.797001,-121.847000
2025-01-15T23:49:33.794Z,1736984973.794 [optimize_roll_speed:Transit:B.SetRollSpeed] Running Loop=1
2025-01-15T23:49:33.795Z,1736984973.795 [optimize_roll_speed:Transit:A.Pitch] Running Loop=1
2025-01-15T23:49:46.347Z,1736984986.347 [NAL9602](INFO): SBD MO Status=1, MOMSN=11751, MT Status=0, MTMSN=0
2025-01-15T23:49:46.347Z,1736984986.347 [NAL9602](INFO): No messages in MT queue
2025-01-15T23:50:17.051Z,1736985017.051 [NAL9602](INFO): Not Powering down - fast GPS
2025-01-15T23:51:01.329Z,1736985061.329 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-15T23:51:27.153Z,1736985087.153 [Radio_Surface](INFO): Powering down
2025-01-15T23:51:32.453Z,1736985092.453 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-15T23:51:33.457Z,1736985093.457 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2025-01-15T23:53:09.847Z,1736985189.847 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.723648
2025-01-15T23:53:12.065Z,1736985192.065 [ThrusterHE](INFO): Failure count cleared after critical for ThrusterHE
2025-01-15T23:56:27.929Z,1736985387.929 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2025-01-15T23:59:33.398Z,1736985573.398 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): Averaging window complete. Average roll: 1.289939 degrees over 1477 samples
2025-01-15T23:59:33.399Z,1736985573.399 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): Adjusting speed to 0.950000 m/s (avg roll: 1.289939 degrees, target: 0.000000 degrees)
2025-01-16T00:00:52.973Z,1736985652.973 [BPC1](ERROR): Battery stick #62 (s/n: 00CC) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0.
2025-01-16T00:00:52.974Z,1736985652.974 [BPC1](INFO): Calculating totals. Valid battery stick count: 27. Valid reserve battery stick count: 3.
2025-01-16T00:00:52.977Z,1736985652.977 [BPC1](FAULT): Failed to receive data from 1 sticks prior to timeout. Will not retry this scan cycle. Missing stick IDs are: 62.
2025-01-16T00:09:34.146Z,1736986174.146 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): Averaging window complete. Average roll: -1.814542 degrees over 1483 samples
2025-01-16T00:09:34.146Z,1736986174.146 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): Crossed target. New step: 0.025000 m/s
2025-01-16T00:09:34.147Z,1736986174.147 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): Adjusting speed to 0.925000 m/s (avg roll: -1.814542 degrees, target: 0.000000 degrees)
2025-01-16T00:19:34.570Z,1736986774.570 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): Averaging window complete. Average roll: -0.813532 degrees over 1479 samples
2025-01-16T00:19:34.571Z,1736986774.571 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): Adjusting speed to 0.900000 m/s (avg roll: -0.813532 degrees, target: 0.000000 degrees)
2025-01-16T00:24:38.394Z,1736987078.394 [optimize_roll_speed:Transit:Wpt1.Waypoint](IMPORTANT): Reached waypoint: 36.797001,-121.847000
2025-01-16T00:24:38.394Z,1736987078.394 [optimize_roll_speed:Transit:Wpt1.Waypoint] Stopped
2025-01-16T00:24:38.394Z,1736987078.394 [optimize_roll_speed:Transit:Wpt1.Waypoint](DEBUG): Uninitialize WaypointComponent.
2025-01-16T00:24:38.395Z,1736987078.395 [optimize_roll_speed:Transit:PhoneHome] Running Loop=1
2025-01-16T00:24:38.395Z,1736987078.395 [optimize_roll_speed:Transit:PhoneHome](DEBUG): Aggregate::initialize optimize_roll_speed:Transit:PhoneHome
2025-01-16T00:24:38.804Z,1736987078.804 [optimize_roll_speed:NeedComms] Running Loop=1
2025-01-16T00:24:38.804Z,1736987078.804 [optimize_roll_speed:NeedComms](DEBUG): Aggregate::initialize optimize_roll_speed:NeedComms
2025-01-16T00:24:38.804Z,1736987078.804 [optimize_roll_speed:NeedComms:B.GoToSurface] Running Loop=1
2025-01-16T00:24:38.804Z,1736987078.804 [optimize_roll_speed:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-01-16T00:24:38.805Z,1736987078.805 [optimize_roll_speed:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2025-01-16T00:24:38.805Z,1736987078.805 [optimize_roll_speed:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2025-01-16T00:24:38.805Z,1736987078.805 [optimize_roll_speed:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2025-01-16T00:24:38.806Z,1736987078.806 [optimize_roll_speed:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds.
2025-01-16T00:24:38.806Z,1736987078.806 [optimize_roll_speed:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-01-16T00:24:38.806Z,1736987078.806 [optimize_roll_speed:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-01-16T00:24:38.807Z,1736987078.807 [optimize_roll_speed:NeedComms:A] Running Loop=1
2025-01-16T00:24:38.808Z,1736987078.808 [optimize_roll_speed:NeedComms:A](INFO): last time_fix was:  1736984972.000000 second since 1970/01/01T00:00:00Z 
2025-01-16T00:24:38.808Z,1736987078.808 [optimize_roll_speed:NeedComms:A] Stopped
2025-01-16T00:26:14.251Z,1736987174.251 [optimize_roll_speed:NeedComms:C] Running Loop=1
2025-01-16T00:26:14.709Z,1736987174.709 [Radio_Surface](INFO): Powering up
2025-01-16T00:26:20.117Z,1736987180.117 [DataOverHttps](INFO): Radio surface powered ON.
2025-01-16T00:26:43.786Z,1736987203.786 [NAL9602](INFO): SBD MO Status=2, MOMSN=11752, MT Status=2, MTMSN=0
2025-01-16T00:26:43.787Z,1736987203.787 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-01-16T00:26:50.237Z,1736987210.237 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-16T00:27:21.361Z,1736987241.361 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-16T00:27:31.395Z,1736987251.395 [NAL9602](INFO): SBD MO Status=1, MOMSN=11752, MT Status=0, MTMSN=0
2025-01-16T00:27:31.395Z,1736987251.395 [NAL9602](INFO): No messages in MT queue
2025-01-16T00:27:32.616Z,1736987252.616 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,002731.00,A,3647.84837,N,12150.74079,W,0.311,47.43,160125,,,A*41
2025-01-16T00:27:32.618Z,1736987252.618 [NAL9602](INFO): GPS fix at 20250116T002731: (36.797473, -121.845680)
2025-01-16T00:27:32.631Z,1736987252.631 [UniversalFixResidualReporter](INFO): Fix residual: 10.4 %DT, over the last 1879.4 m. Residual distance 195.8 m at bearing -95.1 degrees. Fix at (36.7975, -121.8457) with 1649.8 m made good.
2025-01-16T00:27:32.634Z,1736987252.634 [optimize_roll_speed:NeedComms:C] Stopped
2025-01-16T00:27:32.634Z,1736987252.634 [optimize_roll_speed:NeedComms:D] Running Loop=1
2025-01-16T00:27:50.483Z,1736987270.483 [NAL9602](INFO): SBD MO Status=1, MOMSN=11753, MT Status=0, MTMSN=0
2025-01-16T00:27:50.533Z,1736987270.533 [NAL9602](INFO): Sent 266 bytes from file Logs/20250115T234737/Courier0006.lzma
2025-01-16T00:27:50.533Z,1736987270.533 [NAL9602](INFO): Packets left to send: 0
2025-01-16T00:27:52.497Z,1736987272.497 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-16T00:28:08.311Z,1736987288.311 [NAL9602](INFO): SBD MO Status=1, MOMSN=11754, MT Status=0, MTMSN=0
2025-01-16T00:28:08.361Z,1736987288.361 [NAL9602](INFO): Sent 332 bytes from file Logs/20250115T234737/Express0007.lzma
2025-01-16T00:28:08.361Z,1736987288.361 [NAL9602](INFO): Packets left to send: 3
2025-01-16T00:28:20.867Z,1736987300.867 [NAL9602](INFO): SBD MO Status=1, MOMSN=11755, MT Status=0, MTMSN=0
2025-01-16T00:28:20.921Z,1736987300.921 [NAL9602](INFO): Sent 332 bytes from file Logs/20250115T234737/Express0007.lzma
2025-01-16T00:28:20.921Z,1736987300.921 [NAL9602](INFO): Packets left to send: 2
2025-01-16T00:28:23.621Z,1736987303.621 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-16T00:28:32.295Z,1736987312.295 [NAL9602](INFO): SBD MO Status=1, MOMSN=11756, MT Status=0, MTMSN=0
2025-01-16T00:28:32.393Z,1736987312.393 [NAL9602](INFO): Sent 332 bytes from file Logs/20250115T234737/Express0007.lzma
2025-01-16T00:28:32.393Z,1736987312.393 [NAL9602](INFO): Packets left to send: 1
2025-01-16T00:28:37.797Z,1736987317.797 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003350
2025-01-16T00:28:42.197Z,1736987322.197 [NAL9602](INFO): SBD MO Status=1, MOMSN=11757, MT Status=0, MTMSN=0
2025-01-16T00:28:42.253Z,1736987322.253 [NAL9602](INFO): Sent 205 bytes from file Logs/20250115T234737/Express0007.lzma
2025-01-16T00:28:42.253Z,1736987322.253 [NAL9602](INFO): Packets left to send: 0
2025-01-16T00:28:47.879Z,1736987327.879 [optimize_roll_speed:NeedComms:D] Stopped
2025-01-16T00:28:47.881Z,1736987327.881 [optimize_roll_speed:NeedComms:E] Running Loop=1
2025-01-16T00:28:49.856Z,1736987329.856 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,002849.00,A,3647.85255,N,12150.73427,W,0.136,75.33,160125,,,D*42
2025-01-16T00:28:49.964Z,1736987329.964 [NAL9602](INFO): GPS fix at 20250116T002849: (36.797542, -121.845571)
2025-01-16T00:28:50.023Z,1736987330.023 [optimize_roll_speed:NeedComms:E] Stopped
2025-01-16T00:28:50.024Z,1736987330.024 [optimize_roll_speed:NeedComms](INFO): Completed optimize_roll_speed:NeedComms
2025-01-16T00:28:50.024Z,1736987330.024 [optimize_roll_speed:NeedComms] Stopped
2025-01-16T00:28:50.024Z,1736987330.024 [optimize_roll_speed:NeedComms](DEBUG): Aggregate::uninitialize optimize_roll_speed:NeedComms
2025-01-16T00:28:50.024Z,1736987330.024 [optimize_roll_speed:NeedComms:B.GoToSurface] Stopped
2025-01-16T00:28:50.024Z,1736987330.024 [optimize_roll_speed:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-01-16T00:28:50.376Z,1736987330.376 [optimize_roll_speed:Transit:PhoneHome](INFO): Completed optimize_roll_speed:Transit:PhoneHome
2025-01-16T00:28:50.376Z,1736987330.376 [optimize_roll_speed:Transit:PhoneHome] Stopped
2025-01-16T00:28:50.376Z,1736987330.376 [optimize_roll_speed:Transit:PhoneHome](DEBUG): Aggregate::uninitialize optimize_roll_speed:Transit:PhoneHome
2025-01-16T00:28:50.377Z,1736987330.377 [optimize_roll_speed:Transit](INFO): Completed optimize_roll_speed:Transit
2025-01-16T00:28:50.377Z,1736987330.377 [optimize_roll_speed:Transit] Stopped
2025-01-16T00:28:50.377Z,1736987330.377 [optimize_roll_speed:Transit](DEBUG): Aggregate::uninitialize optimize_roll_speed:Transit
2025-01-16T00:28:50.377Z,1736987330.377 [optimize_roll_speed:Transit:A.Pitch] Stopped
2025-01-16T00:28:50.377Z,1736987330.377 [optimize_roll_speed:Transit:B.SetRollSpeed] Stopped
2025-01-16T00:28:50.378Z,1736987330.378 [optimize_roll_speed:Transit:B.SetRollSpeed](DEBUG): Uninitialize.
2025-01-16T00:28:50.379Z,1736987330.379 [optimize_roll_speed](INFO): Completed optimize_roll_speed
2025-01-16T00:28:50.380Z,1736987330.380 [MissionManager](INFO): optimize_roll_speed is completed.
2025-01-16T00:28:50.380Z,1736987330.380 [MissionManager](INFO): Uninitializing Mission optimize_roll_speed
2025-01-16T00:28:50.380Z,1736987330.380 [optimize_roll_speed] Stopped
2025-01-16T00:28:50.380Z,1736987330.380 [optimize_roll_speed](DEBUG): Aggregate::uninitialize optimize_roll_speed
2025-01-16T00:28:50.380Z,1736987330.380 [optimize_roll_speed:StandardEnvelopes] Stopped
2025-01-16T00:28:50.380Z,1736987330.380 [optimize_roll_speed:StandardEnvelopes](DEBUG): Aggregate::uninitialize optimize_roll_speed:StandardEnvelopes
2025-01-16T00:28:50.380Z,1736987330.380 [optimize_roll_speed:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2025-01-16T00:28:50.380Z,1736987330.380 [optimize_roll_speed:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2025-01-16T00:28:50.380Z,1736987330.380 [optimize_roll_speed:StandardEnvelopes:B.DepthEnvelope] Stopped
2025-01-16T00:28:50.381Z,1736987330.381 [optimize_roll_speed:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2025-01-16T00:28:50.381Z,1736987330.381 [optimize_roll_speed:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2025-01-16T00:28:50.381Z,1736987330.381 [optimize_roll_speed:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2025-01-16T00:28:50.381Z,1736987330.381 [optimize_roll_speed:BackseatDriver] Stopped
2025-01-16T00:28:50.381Z,1736987330.381 [optimize_roll_speed:BackseatDriver](DEBUG): Aggregate::uninitialize optimize_roll_speed:BackseatDriver
2025-01-16T00:28:50.381Z,1736987330.381 [optimize_roll_speed:BackseatDriver:A.BackseatDriver] Stopped
2025-01-16T00:28:50.381Z,1736987330.381 [optimize_roll_speed:PowerOnly] Stopped
2025-01-16T00:28:50.381Z,1736987330.381 [optimize_roll_speed:PowerOnly](DEBUG): Aggregate::uninitialize optimize_roll_speed:PowerOnly
2025-01-16T00:28:50.381Z,1736987330.381 [optimize_roll_speed:PowerOnly:E.Wait] Stopped
2025-01-16T00:28:50.381Z,1736987330.381 [optimize_roll_speed:PowerOnly:E.Wait](DEBUG): Uninitialize Wait Component.
2025-01-16T00:28:50.381Z,1736987330.381 [optimize_roll_speed:BuoyancyHold.Buoyancy] Stopped
2025-01-16T00:28:50.381Z,1736987330.381 [optimize_roll_speed:BuoyancyHold.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2025-01-16T00:28:50.382Z,1736987330.382 [optimize_roll_speed:MassHold.Pitch] Stopped
2025-01-16T00:28:50.859Z,1736987330.859 [MissionManager](IMPORTANT): Started mission Default
2025-01-16T00:28:50.859Z,1736987330.859 [Default] Running Loop=1
2025-01-16T00:28:50.859Z,1736987330.859 [Default](DEBUG): Aggregate::initialize Default
2025-01-16T00:28:50.859Z,1736987330.859 [Default:B.GoToSurface] Running Loop=1
2025-01-16T00:28:50.859Z,1736987330.859 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-01-16T00:28:50.860Z,1736987330.860 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-01-16T00:28:50.860Z,1736987330.860 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-01-16T00:28:50.869Z,1736987330.869 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-01-16T00:28:50.869Z,1736987330.869 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-01-16T00:28:50.869Z,1736987330.869 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-01-16T00:28:50.870Z,1736987330.870 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-01-16T00:28:50.870Z,1736987330.870 [Default:A.Wait] Running Loop=1
2025-01-16T00:28:50.870Z,1736987330.870 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-01-16T00:29:04.210Z,1736987344.210 [Default:A.Wait](INFO): Done Waiting.
2025-01-16T00:29:04.211Z,1736987344.211 [Default:A.Wait] Stopped
2025-01-16T00:29:04.211Z,1736987344.211 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-01