2025-06-19T17:53:06.133Z,1750355586.133 [CommandExec](IMPORTANT): got command restart logs
2025-06-19T17:53:52.652Z,1750355632.652 [NAL9602](INFO): SBD MO Status=2, MOMSN=9570, MT Status=2, MTMSN=0
2025-06-19T17:53:52.652Z,1750355632.652 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-19T17:54:28.202Z,1750355668.202 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=9570, MT Status=1, MTMSN=1509
2025-06-19T17:54:28.202Z,1750355668.202 [NAL9602](INFO): Data available in MT queue
2025-06-19T17:54:28.772Z,1750355668.772 [NAL9602](INFO): Received command: sched asap "set keepstation.ApproachDepth 5 m;set keepstation.MaxDepth 20 m;run" 30hmm 2 2
2025-06-19T17:54:28.866Z,1750355668.866 [CommandExec](IMPORTANT): got command schedule asap "set keepstation.ApproachDepth 5 m;set keepstation.MaxDepth 20 m;run" 30hmm 2 2.000000
2025-06-19T17:54:28.867Z,1750355668.867 [CommandExec](IMPORTANT): Scheduling command #2 of 2 with id=30hmm
2025-06-19T17:54:28.869Z,1750355668.869 [CommandExec](IMPORTANT): Scheduled #14 (#2 of 2 with id='30hmm'): "set keepstation.ApproachDepth 5 m;set keepstation.MaxDepth 20 m;run", ASAP
2025-06-19T17:54:28.985Z,1750355668.985 [CommandExec](IMPORTANT): got command load ./Missions/Transport/keepstation.tl
2025-06-19T17:54:28.986Z,1750355668.986 [MissionManager](INFO): Loading Mission from file: ./Missions/Transport/keepstation.tl
2025-06-19T17:54:28.986Z,1750355668.986 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Transport/keepstation.tl
2025-06-19T17:54:29.025Z,1750355669.025 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Transport/keepstation.tl
2025-06-19T17:54:30.132Z,1750355670.132 [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-06-19T17:54:30.146Z,1750355670.146 [MissionManager](INFO): DefineArg keepstation.MissionTimeout = 4.000000 h
2025-06-19T17:54:30.150Z,1750355670.150 [MissionManager](INFO): DefineArg keepstation.NeedCommsTime = 45.000000 min
2025-06-19T17:54:30.154Z,1750355670.154 [MissionManager](INFO): DefineArg keepstation.Latitude = nan arcdeg
2025-06-19T17:54:30.157Z,1750355670.157 [MissionManager](INFO): DefineArg keepstation.Longitude = nan arcdeg
2025-06-19T17:54:30.161Z,1750355670.161 [MissionManager](INFO): DefineArg keepstation.Depth = 30.000000 m
2025-06-19T17:54:30.164Z,1750355670.164 [MissionManager](INFO): DefineArg keepstation.ApproachDepth = 15.000000 m
2025-06-19T17:54:30.168Z,1750355670.168 [MissionManager](INFO): DefineArg keepstation.DepthDeadband = 4.000000 m
2025-06-19T17:54:30.171Z,1750355670.171 [MissionManager](INFO): DefineArg keepstation.Speed = 0.750000 m/s
2025-06-19T17:54:30.174Z,1750355670.174 [MissionManager](INFO): DefineArg keepstation.Radius = 200.000000 m
2025-06-19T17:54:30.178Z,1750355670.178 [MissionManager](INFO): DefineArg keepstation.SinkOffSurface = 0 bool
2025-06-19T17:54:30.181Z,1750355670.181 [MissionManager](INFO): DefineArg keepstation.SinkDepth = 10.000000 m
2025-06-19T17:54:30.185Z,1750355670.185 [MissionManager](INFO): DefineArg keepstation.SinkDepthTimeout = 10.000000 min
2025-06-19T17:54:30.236Z,1750355670.236 [MissionManager](INFO): DefineArg keepstation.MaxDepth = 45.000000 m
2025-06-19T17:54:30.244Z,1750355670.244 [MissionManager](INFO): DefineArg keepstation.MinOffshore = 2.000000 km
2025-06-19T17:54:30.253Z,1750355670.253 [MissionManager](INFO): DefineOutput keepstation.DiveMode = 0.000000 count
2025-06-19T17:54:30.276Z,1750355670.276 [MissionManager](INFO): DefineOutput keepstation.DoingComms = 0.000000 count
2025-06-19T17:54:30.292Z,1750355670.292 [MissionManager](INFO): DefineOutput keepstation.SurfaceSink = 1.000000 count
2025-06-19T17:54:30.300Z,1750355670.300 [MissionManager](INFO): DefineOutput keepstation.TransitToStation = 2.000000 count
2025-06-19T17:54:30.304Z,1750355670.304 [MissionManager](INFO): DefineOutput keepstation.StationKeep = 3.000000 count
2025-06-19T17:54:30.310Z,1750355670.310 [MissionManager](INFO): DefineOutput keepstation.OnStation = 0 bool
2025-06-19T17:54:30.310Z,1750355670.310 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/NeedComms.tl
2025-06-19T17:54:30.310Z,1750355670.310 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/NeedComms.tl
2025-06-19T17:54:30.320Z,1750355670.320 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/NeedComms.tl
2025-06-19T17:54:30.758Z,1750355670.758 [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-06-19T17:54:30.765Z,1750355670.765 [MissionManager](INFO): DefineArg keepstation:NeedComms.DiveInterval = 1.000000 h
2025-06-19T17:54:30.768Z,1750355670.768 [MissionManager](INFO): DefineArg keepstation:NeedComms.WaitForPitchUp = 10.000000 min
2025-06-19T17:54:30.772Z,1750355670.772 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfacePitch = 20.000000 arcdeg
2025-06-19T17:54:30.775Z,1750355670.775 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfaceDepthRate = nan m/s
2025-06-19T17:54:30.778Z,1750355670.778 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfaceSpeed = 1.000000 m/s
2025-06-19T17:54:30.783Z,1750355670.783 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfacingTimeout = 1000.000000 s
2025-06-19T17:54:30.786Z,1750355670.786 [MissionManager](INFO): DefineArg keepstation:NeedComms.GPSTimeout = 7.000000 min
2025-06-19T17:54:30.790Z,1750355670.790 [MissionManager](INFO): DefineArg keepstation:NeedComms.CommsTimeout = 30.000000 min
2025-06-19T17:54:30.798Z,1750355670.798 [keepstation:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2025-06-19T17:54:30.853Z,1750355670.853 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/StandardEnvelopes.tl
2025-06-19T17:54:30.853Z,1750355670.853 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/StandardEnvelopes.tl
2025-06-19T17:54:30.854Z,1750355670.854 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/StandardEnvelopes.tl
2025-06-19T17:54:30.996Z,1750355670.996 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/StandardEnvelopes.tl translated into:
5
1.5
200
2000
2025-06-19T17:54:31.045Z,1750355671.045 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MinAltitude = 5.000000 m
2025-06-19T17:54:31.048Z,1750355671.048 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MaxDepthIgnore = 1.500000 m
2025-06-19T17:54:31.056Z,1750355671.056 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MaxDepth = 200.000000 m
2025-06-19T17:54:31.067Z,1750355671.067 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MinOffshore = 2000.000000 m
2025-06-19T17:54:31.076Z,1750355671.076 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2025-06-19T17:54:31.099Z,1750355671.099 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2025-06-19T17:54:31.122Z,1750355671.122 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2025-06-19T17:54:31.146Z,1750355671.146 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl
2025-06-19T17:54:31.146Z,1750355671.146 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl
2025-06-19T17:54:31.147Z,1750355671.147 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl
2025-06-19T17:54:31.186Z,1750355671.186 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into:
2025-06-19T17:54:31.199Z,1750355671.199 [MissionManager](INFO): DefineArg keepstation:BackseatDriver.EnableBackseat = 0 bool
2025-06-19T17:54:31.202Z,1750355671.202 [keepstation:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver.
2025-06-19T17:54:31.206Z,1750355671.206 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/PowerOnly.tl
2025-06-19T17:54:31.206Z,1750355671.206 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/PowerOnly.tl
2025-06-19T17:54:31.207Z,1750355671.207 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/PowerOnly.tl
2025-06-19T17:54:31.402Z,1750355671.402 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/PowerOnly.tl translated into:
99999
2025-06-19T17:54:31.447Z,1750355671.447 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleAll = 0 bool
2025-06-19T17:54:31.451Z,1750355671.451 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleLoad1 = 0 bool
2025-06-19T17:54:31.462Z,1750355671.462 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleLoad2 = 0 bool
2025-06-19T17:54:31.473Z,1750355671.473 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleLoad3 = 0 bool
2025-06-19T17:54:31.493Z,1750355671.493 [MissionManager](INFO): DefineArg keepstation:PowerOnly.EnabledPowerOnly = 0 bool
2025-06-19T17:54:31.513Z,1750355671.513 [keepstation:PowerOnly:E.Wait](DEBUG): Construct Wait.
2025-06-19T17:54:31.520Z,1750355671.520 [keepstation:H.Pitch](DEBUG): Construct.
2025-06-19T17:54:31.568Z,1750355671.568 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Construct Buoyancy.
2025-06-19T17:54:31.576Z,1750355671.576 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Construct.
2025-06-19T17:54:31.585Z,1750355671.585 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch](DEBUG): Construct.
2025-06-19T17:54:31.630Z,1750355671.630 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Construct Buoyancy.
2025-06-19T17:54:31.638Z,1750355671.638 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch](DEBUG): Construct.
2025-06-19T17:54:31.653Z,1750355671.653 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Construct.
2025-06-19T17:54:31.668Z,1750355671.668 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Construct.
2025-06-19T17:54:31.674Z,1750355671.674 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Construct KeepStation.
2025-06-19T17:54:31.709Z,1750355671.709 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Construct Waypoint.
2025-06-19T17:54:31.748Z,1750355671.748 [keepstation:KeepStation:B.Wait](DEBUG): Construct Wait.
2025-06-19T17:54:31.780Z,1750355671.780 [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-06-19T17:54:31.781Z,1750355671.781 [CommandExec](IMPORTANT): Loaded ./Missions/Transport/keepstation.tl id=keepstation
2025-06-19T17:54:54.118Z,1750355694.118 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-19T17:54:54.118Z,1750355694.118 [Default:CheckIn:C.Wait] Stopped
2025-06-19T17:54:54.118Z,1750355694.118 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-19T17:54:54.118Z,1750355694.118 [Default:CheckIn:D] Running Loop=1
2025-06-19T17:54:54.522Z,1750355694.522 [Default:CheckIn:D] Stopped
2025-06-19T17:54:54.522Z,1750355694.522 [Default:CheckIn:E] Running Loop=1
2025-06-19T17:54:55.002Z,1750355695.002 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 38.562203 min
2025-06-19T17:54:55.002Z,1750355695.002 [Default:CheckIn:E] Stopped
2025-06-19T17:54:55.002Z,1750355695.002 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-19T17:54:55.002Z,1750355695.002 [Default:CheckIn] Stopped
2025-06-19T17:54:55.002Z,1750355695.002 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-19T17:54:55.002Z,1750355695.002 [Default:CheckIn](INFO): Running loop #6
2025-06-19T17:54:55.002Z,1750355695.002 [Default:CheckIn] Running Loop=6
2025-06-19T17:54:55.002Z,1750355695.002 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-19T17:54:55.002Z,1750355695.002 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-19T17:54:56.902Z,1750355696.902 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175458.00,A,3647.81266,N,12150.35286,W,24.648,59.81,190625,,,D*73
2025-06-19T17:54:56.904Z,1750355696.904 [NAL9602](INFO): GPS fix at 20250619T175458: (36.796878, -121.839214)
2025-06-19T17:54:56.923Z,1750355696.923 [Default:CheckIn:Read_GPS] Stopped
2025-06-19T17:54:56.923Z,1750355696.923 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-19T17:55:05.901Z,1750355705.901 [CommandExec](IMPORTANT): got command set keepstation.MissionTimeout 6 hour
2025-06-19T17:55:05.902Z,1750355705.902 [CommandExec](IMPORTANT): got command set keepstation.NeedCommsTime 30 minute
2025-06-19T17:55:05.903Z,1750355705.903 [CommandExec](IMPORTANT): got command set keepstation.Latitude 36.806966 degree
2025-06-19T17:55:05.908Z,1750355705.908 [CommandExec](IMPORTANT): got command set keepstation.Longitude -121.824326 degree
2025-06-19T17:55:05.909Z,1750355705.909 [CommandExec](IMPORTANT): got command set keepstation.Depth 10 meter
2025-06-19T17:55:09.143Z,1750355709.143 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250617T181852/Courier0378.lzma
2025-06-19T17:55:10.146Z,1750355710.146 [DataOverHttps](INFO): Moved sent file to Logs/20250617T181852/Courier0378.lzma.bak
2025-06-19T17:55:10.146Z,1750355710.146 [DataOverHttps](INFO): SBD MOMSN=25229501
2025-06-19T17:55:20.790Z,1750355720.790 [CommandExec](IMPORTANT): got command set keepstation.ApproachDepth 5 meter
2025-06-19T17:55:20.791Z,1750355720.791 [CommandExec](IMPORTANT): got command set keepstation.MaxDepth 20 meter
2025-06-19T17:55:20.792Z,1750355720.792 [CommandExec](IMPORTANT): got command run
2025-06-19T17:55:20.798Z,1750355720.798 [CommandExec](IMPORTANT): Running
2025-06-19T17:55:20.902Z,1750355720.902 [Default] Stopped
2025-06-19T17:55:20.902Z,1750355720.902 [Default](DEBUG): Aggregate::uninitialize Default
2025-06-19T17:55:20.902Z,1750355720.902 [Default:B.GoToSurface] Stopped
2025-06-19T17:55:20.902Z,1750355720.902 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-06-19T17:55:20.902Z,1750355720.902 [Default:CheckIn] Stopped
2025-06-19T17:55:20.902Z,1750355720.902 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-19T17:55:20.902Z,1750355720.902 [Default:CheckIn:Read_Iridium] Stopped
2025-06-19T17:55:20.902Z,1750355720.902 [MissionManager](IMPORTANT): Started mission keepstation
2025-06-19T17:55:20.903Z,1750355720.903 [keepstation] Running Loop=1
2025-06-19T17:55:20.903Z,1750355720.903 [keepstation](DEBUG): Aggregate::initialize keepstation
2025-06-19T17:55:20.903Z,1750355720.903 [keepstation:StandardEnvelopes] Running Loop=1
2025-06-19T17:55:20.903Z,1750355720.903 [keepstation:StandardEnvelopes](DEBUG): Aggregate::initialize keepstation:StandardEnvelopes
2025-06-19T17:55:20.903Z,1750355720.903 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2025-06-19T17:55:20.903Z,1750355720.903 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2025-06-19T17:55:20.904Z,1750355720.904 [keepstation:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2025-06-19T17:55:20.904Z,1750355720.904 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2025-06-19T17:55:20.904Z,1750355720.904 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2025-06-19T17:55:20.904Z,1750355720.904 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2025-06-19T17:55:20.904Z,1750355720.904 [keepstation:BackseatDriver] Running Loop=1
2025-06-19T17:55:20.904Z,1750355720.904 [keepstation:BackseatDriver](DEBUG): Aggregate::initialize keepstation:BackseatDriver
2025-06-19T17:55:20.904Z,1750355720.904 [keepstation:BackseatDriver:A.BackseatDriver] Running Loop=1
2025-06-19T17:55:20.904Z,1750355720.904 [keepstation:PowerOnly] Running Loop=1
2025-06-19T17:55:20.904Z,1750355720.904 [keepstation:PowerOnly](DEBUG): Aggregate::initialize keepstation:PowerOnly
2025-06-19T17:55:20.904Z,1750355720.904 [keepstation:PowerOnly:A] Running Loop=1
2025-06-19T17:55:20.904Z,1750355720.904 [keepstation:PowerOnly:B] Running Loop=1
2025-06-19T17:55:20.905Z,1750355720.905 [keepstation:PowerOnly:C] Running Loop=1
2025-06-19T17:55:20.905Z,1750355720.905 [keepstation:PowerOnly:D] Running Loop=1
2025-06-19T17:55:20.905Z,1750355720.905 [keepstation:PowerOnly:E.Wait] Running Loop=1
2025-06-19T17:55:20.905Z,1750355720.905 [keepstation:PowerOnly:E.Wait](DEBUG): Initialize Wait Component.
2025-06-19T17:55:20.905Z,1750355720.905 [keepstation:H.Pitch] Running Loop=1
2025-06-19T17:55:20.905Z,1750355720.905 [keepstation:H.Pitch](DEBUG): Initialize.
2025-06-19T17:55:20.905Z,1750355720.905 [keepstation:B] Running Loop=1
2025-06-19T17:55:20.906Z,1750355720.906 [keepstation:H.Pitch] Running Loop=1
2025-06-19T17:55:20.906Z,1750355720.906 [keepstation:PowerOnly] Running Loop=1
2025-06-19T17:55:20.907Z,1750355720.907 [keepstation:PowerOnly:D] Stopped
2025-06-19T17:55:20.907Z,1750355720.907 [keepstation:PowerOnly:C] Stopped
2025-06-19T17:55:20.907Z,1750355720.907 [keepstation:PowerOnly:B] Stopped
2025-06-19T17:55:20.907Z,1750355720.907 [keepstation:PowerOnly:A] Stopped
2025-06-19T17:55:20.907Z,1750355720.907 [keepstation:BackseatDriver] Running Loop=1
2025-06-19T17:55:20.907Z,1750355720.907 [keepstation:StandardEnvelopes] Running Loop=1
2025-06-19T17:55:20.907Z,1750355720.907 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2025-06-19T17:55:20.908Z,1750355720.908 [keepstation:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2025-06-19T17:55:20.908Z,1750355720.908 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2025-06-19T17:55:20.908Z,1750355720.908 [keepstation:B] Stopped
2025-06-19T17:55:20.909Z,1750355720.909 [keepstation:D] Running Loop=1
2025-06-19T17:55:21.310Z,1750355721.310 [keepstation:D] Stopped
2025-06-19T17:55:21.311Z,1750355721.311 [keepstation:E] Running Loop=1
2025-06-19T17:55:21.704Z,1750355721.704 [keepstation:E] Stopped
2025-06-19T17:55:21.705Z,1750355721.705 [keepstation:StartingMission] Running Loop=1
2025-06-19T17:55:21.705Z,1750355721.705 [keepstation:StartingMission](DEBUG): Aggregate::initialize keepstation:StartingMission
2025-06-19T17:55:22.108Z,1750355722.108 [keepstation:SurfaceComms] Running Loop=1
2025-06-19T17:55:22.108Z,1750355722.108 [keepstation:SurfaceComms](DEBUG): Aggregate::initialize keepstation:SurfaceComms
2025-06-19T17:55:22.108Z,1750355722.108 [keepstation:SurfaceComms:A] Running Loop=1
2025-06-19T17:55:22.108Z,1750355722.108 [keepstation:SurfaceComms:A] Stopped
2025-06-19T17:55:22.108Z,1750355722.108 [keepstation:SurfaceComms:B] Running Loop=1
2025-06-19T17:55:22.108Z,1750355722.108 [keepstation:SurfaceComms:B](DEBUG): Aggregate::initialize keepstation:SurfaceComms:B
2025-06-19T17:55:22.515Z,1750355722.515 [keepstation:NeedComms] Running Loop=1
2025-06-19T17:55:22.515Z,1750355722.515 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms
2025-06-19T17:55:22.515Z,1750355722.515 [keepstation:NeedComms:B.GoToSurface] Running Loop=1
2025-06-19T17:55:22.515Z,1750355722.515 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-06-19T17:55:22.516Z,1750355722.516 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2025-06-19T17:55:22.516Z,1750355722.516 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2025-06-19T17:55:22.516Z,1750355722.516 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2025-06-19T17:55:22.517Z,1750355722.517 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds.
2025-06-19T17:55:22.517Z,1750355722.517 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-06-19T17:55:22.517Z,1750355722.517 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-06-19T17:55:22.518Z,1750355722.518 [keepstation:NeedComms:A] Running Loop=1
2025-06-19T17:55:22.519Z,1750355722.519 [keepstation:NeedComms:A](INFO): last time_fix was: 1750355698.000000 second since 1970/01/01T00:00:00Z
2025-06-19T17:55:22.519Z,1750355722.519 [keepstation:NeedComms:A] Stopped
2025-06-19T17:55:22.931Z,1750355722.931 [keepstation:NeedComms:C] Running Loop=1
2025-06-19T17:55:23.345Z,1750355723.345 [keepstation:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-06-19T17:55:25.004Z,1750355725.004 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175526.00,A,3647.91558,N,12150.14483,W,27.214,62.89,190625,,,D*7E
2025-06-19T17:55:25.006Z,1750355725.006 [NAL9602](INFO): GPS fix at 20250619T175526: (36.798593, -121.835747)
2025-06-19T17:55:25.026Z,1750355725.026 [keepstation:NeedComms:C] Stopped
2025-06-19T17:55:25.031Z,1750355725.031 [keepstation:NeedComms:D] Running Loop=1
2025-06-19T17:55:25.383Z,1750355725.383 [keepstation:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-06-19T17:55:29.716Z,1750355729.716 [DataOverHttps](INFO): Sending 268 bytes from file Logs/20250619T175306/Courier0000.lzma
2025-06-19T17:55:30.717Z,1750355730.717 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Courier0000.lzma.bak
2025-06-19T17:55:30.718Z,1750355730.718 [DataOverHttps](INFO): SBD MOMSN=25229503
2025-06-19T17:55:46.687Z,1750355746.687 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250619T175306/Courier0006.lzma
2025-06-19T17:55:47.689Z,1750355747.689 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Courier0006.lzma.bak
2025-06-19T17:55:47.689Z,1750355747.689 [DataOverHttps](INFO): SBD MOMSN=25229507
2025-06-19T17:55:56.908Z,1750355756.908 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-19T17:56:08.599Z,1750355768.599 [DataOverHttps](INFO): Sending 104 bytes from file Logs/20250617T181852/Express0379.lzma
2025-06-19T17:56:20.647Z,1750355780.647 [DataOverHttps](INFO): Moved sent file to Logs/20250617T181852/Express0379.lzma.bak
2025-06-19T17:56:20.647Z,1750355780.647 [DataOverHttps](INFO): SBD MOMSN=25229510
2025-06-19T17:56:41.533Z,1750355801.533 [DataOverHttps](INFO): Sending 721 bytes from file Logs/20250619T175306/Express0001.lzma
2025-06-19T17:56:42.533Z,1750355802.533 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Express0001.lzma.bak
2025-06-19T17:56:42.533Z,1750355802.533 [DataOverHttps](INFO): SBD MOMSN=25229514
2025-06-19T17:57:03.424Z,1750355823.424 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20250619T175306/Express0004.lzma
2025-06-19T17:57:04.426Z,1750355824.426 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Express0004.lzma.bak
2025-06-19T17:57:04.427Z,1750355824.427 [DataOverHttps](INFO): SBD MOMSN=25229525
2025-06-19T17:57:20.320Z,1750355840.320 [DataOverHttps](INFO): Sending 336 bytes from file Logs/20250619T175306/Express0007.lzma
2025-06-19T17:57:21.321Z,1750355841.321 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Express0007.lzma.bak
2025-06-19T17:57:21.321Z,1750355841.321 [DataOverHttps](INFO): SBD MOMSN=25229527
2025-06-19T17:57:23.004Z,1750355843.004 [keepstation:NeedComms:D] Stopped
2025-06-19T17:57:23.004Z,1750355843.004 [keepstation:NeedComms:E] Running Loop=1
2025-06-19T17:57:23.403Z,1750355843.403 [keepstation:NeedComms:E](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-06-19T17:57:25.037Z,1750355845.037 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175726.00,A,3648.32504,N,12149.47911,W,10.730,29.48,190625,,,D*7E
2025-06-19T17:57:25.056Z,1750355845.056 [NAL9602](INFO): GPS fix at 20250619T175726: (36.805417, -121.824652)
2025-06-19T17:57:25.081Z,1750355845.081 [keepstation:NeedComms:E] Stopped
2025-06-19T17:57:25.081Z,1750355845.081 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms
2025-06-19T17:57:25.082Z,1750355845.082 [keepstation:NeedComms] Stopped
2025-06-19T17:57:25.082Z,1750355845.082 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms
2025-06-19T17:57:25.082Z,1750355845.082 [keepstation:NeedComms:B.GoToSurface] Stopped
2025-06-19T17:57:25.082Z,1750355845.082 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-06-19T17:57:25.457Z,1750355845.457 [keepstation:SurfaceComms:B](INFO): Completed keepstation:SurfaceComms:B
2025-06-19T17:57:25.457Z,1750355845.457 [keepstation:SurfaceComms:B] Stopped
2025-06-19T17:57:25.457Z,1750355845.457 [keepstation:SurfaceComms:B](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:B
2025-06-19T17:57:25.457Z,1750355845.457 [keepstation:SurfaceComms:setTransit] Running Loop=1
2025-06-19T17:57:25.457Z,1750355845.457 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setTransit
2025-06-19T17:57:25.457Z,1750355845.457 [keepstation:SurfaceComms:setTransit:A] Running Loop=1
2025-06-19T17:57:25.844Z,1750355845.844 [keepstation:SurfaceComms:setTransit:A] Stopped
2025-06-19T17:57:25.844Z,1750355845.844 [keepstation:SurfaceComms:setTransit](INFO): Completed keepstation:SurfaceComms:setTransit
2025-06-19T17:57:25.844Z,1750355845.844 [keepstation:SurfaceComms:setTransit] Stopped
2025-06-19T17:57:25.845Z,1750355845.845 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setTransit
2025-06-19T17:57:25.845Z,1750355845.845 [keepstation:SurfaceComms:setStation] Running Loop=1
2025-06-19T17:57:25.845Z,1750355845.845 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setStation
2025-06-19T17:57:25.845Z,1750355845.845 [keepstation:SurfaceComms:setStation:A] Running Loop=1
2025-06-19T17:57:26.263Z,1750355846.263 [keepstation:SurfaceComms:setStation] Stopped
2025-06-19T17:57:26.267Z,1750355846.267 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setStation
2025-06-19T17:57:26.267Z,1750355846.267 [keepstation:SurfaceComms:setStation:A] Stopped
2025-06-19T17:57:26.267Z,1750355846.267 [keepstation:SurfaceComms:setSink] Running Loop=1
2025-06-19T17:57:26.267Z,1750355846.267 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setSink
2025-06-19T17:57:26.268Z,1750355846.268 [keepstation:SurfaceComms:setSink:A] Running Loop=1
2025-06-19T17:57:26.673Z,1750355846.673 [keepstation:SurfaceComms:setSink] Stopped
2025-06-19T17:57:26.673Z,1750355846.673 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setSink
2025-06-19T17:57:26.673Z,1750355846.673 [keepstation:SurfaceComms:setSink:A] Stopped
2025-06-19T17:57:26.673Z,1750355846.673 [keepstation:SurfaceComms](INFO): Completed keepstation:SurfaceComms
2025-06-19T17:57:26.673Z,1750355846.673 [keepstation:SurfaceComms] Stopped
2025-06-19T17:57:26.673Z,1750355846.673 [keepstation:SurfaceComms](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms
2025-06-19T17:57:27.053Z,1750355847.053 [keepstation:StartingMission](INFO): Completed keepstation:StartingMission
2025-06-19T17:57:27.053Z,1750355847.053 [keepstation:StartingMission] Stopped
2025-06-19T17:57:27.053Z,1750355847.053 [keepstation:StartingMission](DEBUG): Aggregate::uninitialize keepstation:StartingMission
2025-06-19T17:57:27.053Z,1750355847.053 [keepstation:TransitToStation] Running Loop=1
2025-06-19T17:57:27.053Z,1750355847.053 [keepstation:TransitToStation](DEBUG): Aggregate::initialize keepstation:TransitToStation
2025-06-19T17:57:27.053Z,1750355847.053 [keepstation:TransitToStation:Dive] Running Loop=1
2025-06-19T17:57:27.054Z,1750355847.054 [keepstation:TransitToStation:Dive](DEBUG): Aggregate::initialize keepstation:TransitToStation:Dive
2025-06-19T17:57:27.054Z,1750355847.054 [keepstation:TransitToStation:Dive:A] Running Loop=1
2025-06-19T17:57:27.054Z,1750355847.054 [keepstation:TransitToStation:Dive:A](DEBUG): Aggregate::initialize keepstation:TransitToStation:Dive:A
2025-06-19T17:57:27.054Z,1750355847.054 [keepstation:TransitToStation:Wpt1.Waypoint] Running Loop=1
2025-06-19T17:57:27.054Z,1750355847.054 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2025-06-19T17:57:27.059Z,1750355847.059 [keepstation:TransitToStation:Wpt1.Waypoint](IMPORTANT): Navigating to waypoint: 36.806965,-121.824326
2025-06-19T17:57:27.464Z,1750355847.464 [keepstation:TransitToStation:Wpt1.Waypoint](INFO): Navigating to waypoint: 36.806965,-121.824326
2025-06-19T17:57:27.464Z,1750355847.464 [keepstation:TransitToStation:Dive] Running Loop=1
2025-06-19T17:57:27.465Z,1750355847.465 [keepstation:DiveCmd] Running Loop=1
2025-06-19T17:57:27.465Z,1750355847.465 [keepstation:DiveCmd](DEBUG): Aggregate::initialize keepstation:DiveCmd
2025-06-19T17:57:27.465Z,1750355847.465 [keepstation:DiveCmd:SurfaceSink] Running Loop=1
2025-06-19T17:57:27.465Z,1750355847.465 [keepstation:DiveCmd:SurfaceSink](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink
2025-06-19T17:57:27.465Z,1750355847.465 [keepstation:DiveCmd:SurfaceSink:sink] Running Loop=1
2025-06-19T17:57:27.465Z,1750355847.465 [keepstation:DiveCmd:SurfaceSink:sink](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink
2025-06-19T17:57:27.465Z,1750355847.465 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy] Running Loop=1
2025-06-19T17:57:27.465Z,1750355847.465 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Initialize Buoyancy Component.
2025-06-19T17:57:27.465Z,1750355847.465 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed] Running Loop=1
2025-06-19T17:57:27.465Z,1750355847.465 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Initialize.
2025-06-19T17:57:27.466Z,1750355847.466 [keepstation:DiveCmd:SurfaceSink:sink:C] Running Loop=1
2025-06-19T17:57:27.466Z,1750355847.466 [keepstation:DiveCmd:TransitToStation] Running Loop=1
2025-06-19T17:57:27.466Z,1750355847.466 [keepstation:DiveCmd:TransitToStation](DEBUG): Aggregate::initialize keepstation:DiveCmd:TransitToStation
2025-06-19T17:57:27.466Z,1750355847.466 [keepstation:DiveCmd:TransitToStation:dive] Running Loop=1
2025-06-19T17:57:27.466Z,1750355847.466 [keepstation:DiveCmd:TransitToStation:dive](DEBUG): Aggregate::initialize keepstation:DiveCmd:TransitToStation:dive
2025-06-19T17:57:27.466Z,1750355847.466 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy] Running Loop=1
2025-06-19T17:57:27.466Z,1750355847.466 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Initialize Buoyancy Component.
2025-06-19T17:57:27.466Z,1750355847.466 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch] Running Loop=1
2025-06-19T17:57:27.466Z,1750355847.466 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch](DEBUG): Initialize.
2025-06-19T17:57:27.466Z,1750355847.466 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed] Running Loop=1
2025-06-19T17:57:27.467Z,1750355847.467 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Initialize.
2025-06-19T17:57:27.467Z,1750355847.467 [keepstation:DiveCmd:StationKeep] Running Loop=1
2025-06-19T17:57:27.467Z,1750355847.467 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::initialize keepstation:DiveCmd:StationKeep
2025-06-19T17:57:27.467Z,1750355847.467 [keepstation:DiveCmd:StationKeep:A] Running Loop=1
2025-06-19T17:57:27.471Z,1750355847.471 [keepstation:DiveCmd:StationKeep:B.Pitch] Running Loop=1
2025-06-19T17:57:27.471Z,1750355847.471 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Initialize.
2025-06-19T17:57:27.471Z,1750355847.471 [keepstation:DiveCmd:StationKeep:C.KeepStation] Running Loop=1
2025-06-19T17:57:27.472Z,1750355847.472 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Initialize KeepStationComponent.
2025-06-19T17:57:27.472Z,1750355847.472 [keepstation:DiveCmd:StationKeep] Stopped
2025-06-19T17:57:27.472Z,1750355847.472 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:StationKeep
2025-06-19T17:57:27.473Z,1750355847.473 [keepstation:DiveCmd:StationKeep:A] Stopped
2025-06-19T17:57:27.473Z,1750355847.473 [keepstation:DiveCmd:StationKeep:B.Pitch] Stopped
2025-06-19T17:57:27.473Z,1750355847.473 [keepstation:DiveCmd:StationKeep:C.KeepStation] Stopped
2025-06-19T17:57:27.473Z,1750355847.473 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Uninitialize KeepStationComponent.
2025-06-19T17:57:27.473Z,1750355847.473 [keepstation:DiveCmd:TransitToStation] Running Loop=1
2025-06-19T17:57:27.473Z,1750355847.473 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed] Running Loop=1
2025-06-19T17:57:27.473Z,1750355847.473 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch] Running Loop=1
2025-06-19T17:57:27.474Z,1750355847.474 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy] Running Loop=1
2025-06-19T17:57:27.474Z,1750355847.474 [keepstation:DiveCmd:SurfaceSink] Stopped
2025-06-19T17:57:27.474Z,1750355847.474 [keepstation:DiveCmd:SurfaceSink](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink
2025-06-19T17:57:27.474Z,1750355847.474 [keepstation:DiveCmd:SurfaceSink:sink] Stopped
2025-06-19T17:57:27.474Z,1750355847.474 [keepstation:DiveCmd:SurfaceSink:sink](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink:sink
2025-06-19T17:57:27.474Z,1750355847.474 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy] Stopped
2025-06-19T17:57:27.474Z,1750355847.474 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2025-06-19T17:57:27.474Z,1750355847.474 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed] Stopped
2025-06-19T17:57:27.474Z,1750355847.474 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Uninitialize.
2025-06-19T17:57:27.474Z,1750355847.474 [keepstation:DiveCmd:SurfaceSink:sink:C] Stopped
2025-06-19T17:58:45.462Z,1750355925.462 [NAL9602](INFO): SBD MO Status=2, MOMSN=9571, MT Status=2, MTMSN=0
2025-06-19T17:58:45.463Z,1750355925.463 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-19T17:58:53.281Z,1750355933.281 [DataOverHttps](IMPORTANT): SBD MTMSN=20250619T175854
2025-06-19T17:59:01.135Z,1750355941.135 [DataOverHttps](INFO): Received command: stop
2025-06-19T17:59:01.209Z,1750355941.209 [CommandExec](IMPORTANT): got command stop
2025-06-19T17:59:01.210Z,1750355941.210 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2025-06-19T17:59:01.234Z,1750355941.234 [MissionManager](INFO): MissionManager is completed.
2025-06-19T17:59:01.234Z,1750355941.234 [MissionManager](INFO): Uninitializing Mission keepstation
2025-06-19T17:59:01.234Z,1750355941.234 [keepstation] Stopped
2025-06-19T17:59:01.234Z,1750355941.234 [keepstation](DEBUG): Aggregate::uninitialize keepstation
2025-06-19T17:59:01.235Z,1750355941.235 [keepstation:StandardEnvelopes] Stopped
2025-06-19T17:59:01.235Z,1750355941.235 [keepstation:StandardEnvelopes](DEBUG): Aggregate::uninitialize keepstation:StandardEnvelopes
2025-06-19T17:59:01.235Z,1750355941.235 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2025-06-19T17:59:01.235Z,1750355941.235 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2025-06-19T17:59:01.235Z,1750355941.235 [keepstation:StandardEnvelopes:B.DepthEnvelope] Stopped
2025-06-19T17:59:01.235Z,1750355941.235 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2025-06-19T17:59:01.235Z,1750355941.235 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2025-06-19T17:59:01.235Z,1750355941.235 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2025-06-19T17:59:01.235Z,1750355941.235 [keepstation:BackseatDriver] Stopped
2025-06-19T17:59:01.235Z,1750355941.235 [keepstation:BackseatDriver](DEBUG): Aggregate::uninitialize keepstation:BackseatDriver
2025-06-19T17:59:01.236Z,1750355941.236 [keepstation:BackseatDriver:A.BackseatDriver] Stopped
2025-06-19T17:59:01.236Z,1750355941.236 [keepstation:PowerOnly] Stopped
2025-06-19T17:59:01.236Z,1750355941.236 [keepstation:PowerOnly](DEBUG): Aggregate::uninitialize keepstation:PowerOnly
2025-06-19T17:59:01.236Z,1750355941.236 [keepstation:PowerOnly:E.Wait] Stopped
2025-06-19T17:59:01.236Z,1750355941.236 [keepstation:PowerOnly:E.Wait](DEBUG): Uninitialize Wait Component.
2025-06-19T17:59:01.236Z,1750355941.236 [keepstation:H.Pitch] Stopped
2025-06-19T17:59:01.236Z,1750355941.236 [keepstation:DiveCmd] Stopped
2025-06-19T17:59:01.236Z,1750355941.236 [keepstation:DiveCmd](DEBUG): Aggregate::uninitialize keepstation:DiveCmd
2025-06-19T17:59:01.236Z,1750355941.236 [keepstation:DiveCmd:TransitToStation] Stopped
2025-06-19T17:59:01.236Z,1750355941.236 [keepstation:DiveCmd:TransitToStation](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:TransitToStation
2025-06-19T17:59:01.236Z,1750355941.236 [keepstation:DiveCmd:TransitToStation:dive] Stopped
2025-06-19T17:59:01.236Z,1750355941.236 [keepstation:DiveCmd:TransitToStation:dive](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:TransitToStation:dive
2025-06-19T17:59:01.236Z,1750355941.236 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy] Stopped
2025-06-19T17:59:01.237Z,1750355941.237 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2025-06-19T17:59:01.237Z,1750355941.237 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch] Stopped
2025-06-19T17:59:01.237Z,1750355941.237 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed] Stopped
2025-06-19T17:59:01.237Z,1750355941.237 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Uninitialize.
2025-06-19T17:59:01.237Z,1750355941.237 [keepstation:TransitToStation] Stopped
2025-06-19T17:59:01.237Z,1750355941.237 [keepstation:TransitToStation](DEBUG): Aggregate::uninitialize keepstation:TransitToStation
2025-06-19T17:59:01.237Z,1750355941.237 [keepstation:TransitToStation:Dive] Stopped
2025-06-19T17:59:01.237Z,1750355941.237 [keepstation:TransitToStation:Dive](DEBUG): Aggregate::uninitialize keepstation:TransitToStation:Dive
2025-06-19T17:59:01.237Z,1750355941.237 [keepstation:TransitToStation:Dive:A] Stopped
2025-06-19T17:59:01.237Z,1750355941.237 [keepstation:TransitToStation:Dive:A](DEBUG): Aggregate::uninitialize keepstation:TransitToStation:Dive:A
2025-06-19T17:59:01.237Z,1750355941.237 [keepstation:TransitToStation:Wpt1.Waypoint] Stopped
2025-06-19T17:59:01.237Z,1750355941.237 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Uninitialize WaypointComponent.
2025-06-19T17:59:01.646Z,1750355941.646 [MissionManager](IMPORTANT): Started mission Default
2025-06-19T17:59:01.646Z,1750355941.646 [Default] Running Loop=1
2025-06-19T17:59:01.646Z,1750355941.646 [Default](DEBUG): Aggregate::initialize Default
2025-06-19T17:59:01.647Z,1750355941.647 [Default:B.GoToSurface] Running Loop=1
2025-06-19T17:59:01.647Z,1750355941.647 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-06-19T17:59:01.647Z,1750355941.647 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-06-19T17:59:01.647Z,1750355941.647 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-06-19T17:59:01.648Z,1750355941.648 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-06-19T17:59:01.648Z,1750355941.648 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-06-19T17:59:01.649Z,1750355941.649 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-06-19T17:59:01.649Z,1750355941.649 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-06-19T17:59:01.649Z,1750355941.649 [Default:A.Wait] Running Loop=1
2025-06-19T17:59:01.650Z,1750355941.650 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-06-19T17:59:14.964Z,1750355954.964 [Default:A.Wait](INFO): Done Waiting.
2025-06-19T17:59:14.964Z,1750355954.964 [Default:A.Wait] Stopped
2025-06-19T17:59:14.964Z,1750355954.964 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-06-19T17:59:15.375Z,1750355955.375 [Default:CheckIn] Running Loop=1
2025-06-19T17:59:15.376Z,1750355955.376 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-19T17:59:15.376Z,1750355955.376 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-19T18:00:02.896Z,1750356002.896 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.759216
2025-06-19T18:01:09.008Z,1750356069.008 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003296
2025-06-19T18:01:15.357Z,1750356075.357 [NAL9602](INFO): SBD MO Status=0, MOMSN=9571, MT Status=0, MTMSN=0
2025-06-19T18:01:15.357Z,1750356075.357 [NAL9602](INFO): No messages in MT queue
2025-06-19T18:01:16.565Z,1750356076.565 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180118.00,A,3648.45294,N,12149.45847,W,0.952,29.97,190625,,,D*48
2025-06-19T18:01:16.567Z,1750356076.567 [NAL9602](INFO): GPS fix at 20250619T180118: (36.807549, -121.824308)
2025-06-19T18:01:16.577Z,1750356076.577 [Default:CheckIn:Read_GPS] Stopped
2025-06-19T18:01:16.577Z,1750356076.577 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-19T18:01:37.539Z,1750356097.539 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250619T175306/Courier0009.lzma
2025-06-19T18:01:38.541Z,1750356098.541 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Courier0009.lzma.bak
2025-06-19T18:01:38.541Z,1750356098.541 [DataOverHttps](INFO): SBD MOMSN=25229550
2025-06-19T18:01:49.288Z,1750356109.288 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-19T18:02:47.768Z,1750356167.768 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.791409
2025-06-19T18:03:08.978Z,1750356188.978 [NAL9602](INFO): SBD MO Status=1, MOMSN=9572, MT Status=0, MTMSN=0
2025-06-19T18:03:09.031Z,1750356189.031 [NAL9602](INFO): Sent 332 bytes from file Logs/20250619T175306/Express0010.lzma
2025-06-19T18:03:09.032Z,1750356189.032 [NAL9602](INFO): Packets left to send: 1
2025-06-19T18:03:18.892Z,1750356198.892 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-06-19T18:03:26.042Z,1750356206.042 [NAL9602](INFO): SBD MO Status=2, MOMSN=9573, MT Status=2, MTMSN=0
2025-06-19T18:03:26.042Z,1750356206.042 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-19T18:03:35.030Z,1750356215.030 [NAL9602](INFO): SBD MO Status=1, MOMSN=9573, MT Status=0, MTMSN=0
2025-06-19T18:03:35.079Z,1750356215.079 [NAL9602](INFO): Sent 48 bytes from file Logs/20250619T175306/Express0010.lzma
2025-06-19T18:03:35.080Z,1750356215.080 [NAL9602](INFO): Packets left to send: 0
2025-06-19T18:03:43.933Z,1750356223.933 [NAL9602](INFO): SBD MO Status=0, MOMSN=9574, MT Status=0, MTMSN=0
2025-06-19T18:03:44.011Z,1750356224.011 [Default:CheckIn:Read_Iridium] Stopped
2025-06-19T18:03:44.012Z,1750356224.012 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-19T18:03:44.012Z,1750356224.012 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-19T18:04:07.872Z,1750356247.872 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003316
2025-06-19T18:04:14.632Z,1750356254.632 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-19T18:05:05.120Z,1750356305.120 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-06-19T18:05:08.132Z,1750356308.132 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.263309
2025-06-19T18:05:28.548Z,1750356328.548 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003350
2025-06-19T18:07:34.344Z,1750356454.344 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.247261
2025-06-19T18:08:13.913Z,1750356493.913 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003549
2025-06-19T18:08:44.542Z,1750356524.542 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-19T18:08:44.542Z,1750356524.542 [Default:CheckIn:C.Wait] Stopped
2025-06-19T18:08:44.542Z,1750356524.542 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-19T18:08:44.543Z,1750356524.543 [Default:CheckIn:D] Running Loop=1
2025-06-19T18:08:44.946Z,1750356524.946 [Default:CheckIn:D] Stopped
2025-06-19T18:08:44.947Z,1750356524.947 [Default:CheckIn:E] Running Loop=1
2025-06-19T18:08:45.339Z,1750356525.339 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 9.721666 min
2025-06-19T18:08:45.339Z,1750356525.339 [Default:CheckIn:E] Stopped
2025-06-19T18:08:45.339Z,1750356525.339 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-19T18:08:45.339Z,1750356525.339 [Default:CheckIn] Stopped
2025-06-19T18:08:45.359Z,1750356525.359 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-19T18:08:45.359Z,1750356525.359 [Default:CheckIn](INFO): Running loop #2
2025-06-19T18:08:45.359Z,1750356525.359 [Default:CheckIn] Running Loop=2
2025-06-19T18:08:45.360Z,1750356525.360 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-19T18:08:45.360Z,1750356525.360 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-19T18:08:47.342Z,1750356527.342 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180849.00,A,3648.27206,N,12148.08194,W,21.441,96.59,190625,,,D*7F
2025-06-19T18:08:47.344Z,1750356527.344 [NAL9602](INFO): GPS fix at 20250619T180849: (36.804534, -121.801366)
2025-06-19T18:08:47.367Z,1750356527.367 [Default:CheckIn:Read_GPS] Stopped
2025-06-19T18:08:47.367Z,1750356527.367 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-19T18:08:48.753Z,1750356528.753 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250619T175306/Courier0012.lzma
2025-06-19T18:08:49.553Z,1750356529.553 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Courier0012.lzma.bak
2025-06-19T18:08:49.553Z,1750356529.553 [DataOverHttps](INFO): SBD MOMSN=25229577
2025-06-19T18:09:05.467Z,1750356545.467 [DataOverHttps](INFO): Sending 166 bytes from file Logs/20250619T175306/Express0014.lzma
2025-06-19T18:09:06.469Z,1750356546.469 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Express0014.lzma.bak
2025-06-19T18:09:06.469Z,1750356546.469 [DataOverHttps](INFO): SBD MOMSN=25229580
2025-06-19T18:09:08.365Z,1750356548.365 [Default:CheckIn:Read_Iridium] Stopped
2025-06-19T18:09:08.365Z,1750356548.365 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-19T18:09:08.365Z,1750356548.365 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-19T18:09:13.598Z,1750356553.598 [NAL9602](INFO): SBD MO Status=2, MOMSN=9575, MT Status=2, MTMSN=0
2025-06-19T18:09:13.599Z,1750356553.599 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-19T18:09:32.595Z,1750356572.595 [NAL9602](INFO): SBD MO Status=2, MOMSN=9575, MT Status=2, MTMSN=0
2025-06-19T18:09:32.595Z,1750356572.595 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-19T18:10:10.570Z,1750356610.570 [NAL9602](INFO): SBD MO Status=0, MOMSN=9575, MT Status=0, MTMSN=0
2025-06-19T18:10:10.570Z,1750356610.570 [NAL9602](INFO): No messages in MT queue
2025-06-19T18:10:41.353Z,1750356641.353 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-19T18:14:08.930Z,1750356848.930 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-19T18:14:08.930Z,1750356848.930 [Default:CheckIn:C.Wait] Stopped
2025-06-19T18:14:08.930Z,1750356848.930 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-19T18:14:08.930Z,1750356848.930 [Default:CheckIn:D] Running Loop=1
2025-06-19T18:14:09.335Z,1750356849.335 [Default:CheckIn:D] Stopped
2025-06-19T18:14:09.335Z,1750356849.335 [Default:CheckIn:E] Running Loop=1
2025-06-19T18:14:09.743Z,1750356849.743 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 15.128149 min
2025-06-19T18:14:09.743Z,1750356849.743 [Default:CheckIn:E] Stopped
2025-06-19T18:14:09.743Z,1750356849.743 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-19T18:14:09.743Z,1750356849.743 [Default:CheckIn] Stopped
2025-06-19T18:14:09.743Z,1750356849.743 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-19T18:14:09.744Z,1750356849.744 [Default:CheckIn](INFO): Running loop #3
2025-06-19T18:14:09.744Z,1750356849.744 [Default:CheckIn] Running Loop=3
2025-06-19T18:14:09.744Z,1750356849.744 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-19T18:14:09.744Z,1750356849.744 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-19T18:14:11.760Z,1750356851.760 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181413.00,A,3648.39103,N,12147.12962,W,3.771,179.95,190625,,,D*71
2025-06-19T18:14:11.762Z,1750356851.762 [NAL9602](INFO): GPS fix at 20250619T181413: (36.806517, -121.785494)
2025-06-19T18:14:11.773Z,1750356851.773 [Default:CheckIn:Read_GPS] Stopped
2025-06-19T18:14:11.773Z,1750356851.773 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-19T18:14:18.840Z,1750356858.840 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250619T175306/Courier0018.lzma
2025-06-19T18:14:19.841Z,1750356859.841 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Courier0018.lzma.bak
2025-06-19T18:14:19.841Z,1750356859.841 [DataOverHttps](INFO): SBD MOMSN=25229589
2025-06-19T18:14:38.463Z,1750356878.463 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20250619T175306/Express0019.lzma
2025-06-19T18:14:39.465Z,1750356879.465 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Express0019.lzma.bak
2025-06-19T18:14:39.465Z,1750356879.465 [DataOverHttps](INFO): SBD MOMSN=25229592
2025-06-19T18:14:40.940Z,1750356880.940 [Default:CheckIn:Read_Iridium] Stopped
2025-06-19T18:14:40.940Z,1750356880.940 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-19T18:14:40.940Z,1750356880.940 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-19T18:14:43.742Z,1750356883.742 [NAL9602](INFO): SBD MO Status=2, MOMSN=9576, MT Status=2, MTMSN=0
2025-06-19T18:14:43.742Z,1750356883.742 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-19T18:18:05.742Z,1750357085.742 [NAL9602](INFO): SBD MO Status=0, MOMSN=9576, MT Status=0, MTMSN=0
2025-06-19T18:18:05.742Z,1750357085.742 [NAL9602](INFO): No messages in MT queue
2025-06-19T18:18:36.449Z,1750357116.449 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-19T18:19:41.507Z,1750357181.507 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-19T18:19:41.507Z,1750357181.507 [Default:CheckIn:C.Wait] Stopped
2025-06-19T18:19:41.507Z,1750357181.507 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-19T18:19:41.507Z,1750357181.507 [Default:CheckIn:D] Running Loop=1
2025-06-19T18:19:41.914Z,1750357181.914 [Default:CheckIn:D] Stopped
2025-06-19T18:19:41.915Z,1750357181.915 [Default:CheckIn:E] Running Loop=1
2025-06-19T18:19:42.314Z,1750357182.314 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.671134 min
2025-06-19T18:19:42.314Z,1750357182.314 [Default:CheckIn:E] Stopped
2025-06-19T18:19:42.314Z,1750357182.314 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-19T18:19:42.314Z,1750357182.314 [Default:CheckIn] Stopped
2025-06-19T18:19:42.314Z,1750357182.314 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-19T18:19:42.315Z,1750357182.315 [Default:CheckIn](INFO): Running loop #4
2025-06-19T18:19:42.315Z,1750357182.315 [Default:CheckIn] Running Loop=4
2025-06-19T18:19:42.315Z,1750357182.315 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-19T18:19:42.315Z,1750357182.315 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-19T18:19:44.330Z,1750357184.330 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181946.00,A,3648.15244,N,12147.22051,W,0.097,216.26,190625,,,D*76
2025-06-19T18:19:44.333Z,1750357184.333 [NAL9602](INFO): GPS fix at 20250619T181946: (36.802541, -121.787008)
2025-06-19T18:19:44.343Z,1750357184.343 [Default:CheckIn:Read_GPS] Stopped
2025-06-19T18:19:44.343Z,1750357184.343 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-19T18:19:51.531Z,1750357191.531 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250619T175306/Courier0021.lzma
2025-06-19T18:19:52.533Z,1750357192.533 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Courier0021.lzma.bak
2025-06-19T18:19:52.533Z,1750357192.533 [DataOverHttps](INFO): SBD MOMSN=25229602
2025-06-19T18:20:04.930Z,1750357204.930 [NAL9602](INFO): SBD MO Status=2, MOMSN=9577, MT Status=2, MTMSN=0
2025-06-19T18:20:04.930Z,1750357204.930 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-19T18:20:08.499Z,1750357208.499 [DataOverHttps](INFO): Sending 171 bytes from file Logs/20250619T175306/Express0022.lzma
2025-06-19T18:20:09.501Z,1750357209.501 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Express0022.lzma.bak
2025-06-19T18:20:09.501Z,1750357209.501 [DataOverHttps](INFO): SBD MOMSN=25229605
2025-06-19T18:20:11.008Z,1750357211.008 [Default:CheckIn:Read_Iridium] Stopped
2025-06-19T18:20:11.008Z,1750357211.008 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-19T18:20:11.008Z,1750357211.008 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-19T18:20:26.338Z,1750357226.338 [NAL9602](INFO): SBD MO Status=0, MOMSN=9577, MT Status=0, MTMSN=0
2025-06-19T18:20:26.338Z,1750357226.338 [NAL9602](INFO): No messages in MT queue
2025-06-19T18:20:57.041Z,1750357257.041 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-19T18:22:57.036Z,1750357377.036 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-06-19T18:23:09.556Z,1750357389.556 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-06-19T18:23:22.080Z,1750357402.080 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-06-19T18:23:34.605Z,1750357414.605 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-06-19T18:23:46.723Z,1750357426.723 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-06-19T18:23:59.247Z,1750357439.247 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-06-19T18:24:11.771Z,1750357451.771 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-06-19T18:25:11.583Z,1750357511.583 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-19T18:25:11.583Z,1750357511.583 [Default:CheckIn:C.Wait] Stopped
2025-06-19T18:25:11.583Z,1750357511.583 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-19T18:25:11.584Z,1750357511.584 [Default:CheckIn:D] Running Loop=1
2025-06-19T18:25:12.042Z,1750357512.042 [Default:CheckIn:D] Stopped
2025-06-19T18:25:12.042Z,1750357512.042 [Default:CheckIn:E] Running Loop=1
2025-06-19T18:25:12.423Z,1750357512.423 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 26.173263 min
2025-06-19T18:25:12.423Z,1750357512.423 [Default:CheckIn:E] Stopped
2025-06-19T18:25:12.423Z,1750357512.423 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-19T18:25:12.423Z,1750357512.423 [Default:CheckIn] Stopped
2025-06-19T18:25:12.424Z,1750357512.424 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-19T18:25:12.424Z,1750357512.424 [Default:CheckIn](INFO): Running loop #5
2025-06-19T18:25:12.424Z,1750357512.424 [Default:CheckIn] Running Loop=5
2025-06-19T18:25:12.424Z,1750357512.424 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-19T18:25:12.424Z,1750357512.424 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-19T18:25:14.402Z,1750357514.402 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182516.00,A,3648.15663,N,12147.22119,W,0.019,323.68,190625,,,D*7B
2025-06-19T18:25:14.405Z,1750357514.405 [NAL9602](INFO): GPS fix at 20250619T182516: (36.802611, -121.787020)
2025-06-19T18:25:14.415Z,1750357514.415 [Default:CheckIn:Read_GPS] Stopped
2025-06-19T18:25:14.415Z,1750357514.415 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-19T18:25:22.219Z,1750357522.219 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20250619T175306/Courier0024.lzma
2025-06-19T18:25:23.221Z,1750357523.221 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Courier0024.lzma.bak
2025-06-19T18:25:23.221Z,1750357523.221 [DataOverHttps](INFO): SBD MOMSN=25229614
2025-06-19T18:25:39.507Z,1750357539.507 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20250619T175306/Express0025.lzma
2025-06-19T18:25:40.509Z,1750357540.509 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Express0025.lzma.bak
2025-06-19T18:25:40.509Z,1750357540.509 [DataOverHttps](INFO): SBD MOMSN=25229617
2025-06-19T18:25:41.908Z,1750357541.908 [Default:CheckIn:Read_Iridium] Stopped
2025-06-19T18:25:41.908Z,1750357541.908 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-19T18:25:41.908Z,1750357541.908 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-19T18:26:47.357Z,1750357607.357 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2025-06-19T18:26:53.013Z,1750357613.013 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-06-19T18:26:53.821Z,1750357613.821 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2025-06-19T18:27:08.363Z,1750357628.363 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-06-19T18:27:09.177Z,1750357629.177 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2025-06-19T18:27:23.311Z,1750357643.311 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-06-19T18:27:24.121Z,1750357644.121 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2025-06-19T18:27:39.068Z,1750357659.068 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2025-06-19T18:27:39.074Z,1750357659.074 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-06-19T18:27:54.016Z,1750357674.016 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2025-06-19T18:27:54.022Z,1750357674.022 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-06-19T18:28:08.965Z,1750357688.965 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2025-06-19T18:28:09.380Z,1750357689.380 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-06-19T18:28:20.322Z,1750357700.322 [NAL9602](INFO): SBD MO Status=0, MOMSN=9578, MT Status=0, MTMSN=0
2025-06-19T18:28:20.322Z,1750357700.322 [NAL9602](INFO): No messages in MT queue
2025-06-19T18:28:23.912Z,1750357703.912 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2025-06-19T18:28:24.732Z,1750357704.732 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-06-19T18:28:38.859Z,1750357718.859 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2025-06-19T18:28:39.680Z,1750357719.680 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-06-19T18:28:50.984Z,1750357730.984 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-19T18:28:53.809Z,1750357733.809 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2025-06-19T18:28:55.423Z,1750357735.423 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-06-19T18:29:08.758Z,1750357748.758 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2025-06-19T18:29:10.795Z,1750357750.795 [BPC1](INFO): Calculating totals. Valid battery stick count: 47. Valid reserve battery stick count: 5.
2025-06-19T18:29:10.801Z,1750357750.801 [BPC1](INFO): Received data from all battery sticks.
2025-06-19T18:30:42.502Z,1750357842.502 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-19T18:30:42.502Z,1750357842.502 [Default:CheckIn:C.Wait] Stopped
2025-06-19T18:30:42.502Z,1750357842.502 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-19T18:30:42.503Z,1750357842.503 [Default:CheckIn:D] Running Loop=1
2025-06-19T18:30:42.902Z,1750357842.902 [Default:CheckIn:D] Stopped
2025-06-19T18:30:42.902Z,1750357842.902 [Default:CheckIn:E] Running Loop=1
2025-06-19T18:30:43.304Z,1750357843.304 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.687590 min
2025-06-19T18:30:43.304Z,1750357843.304 [Default:CheckIn:E] Stopped
2025-06-19T18:30:43.304Z,1750357843.304 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-19T18:30:43.304Z,1750357843.304 [Default:CheckIn] Stopped
2025-06-19T18:30:43.304Z,1750357843.304 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-19T18:30:43.304Z,1750357843.304 [Default:CheckIn](INFO): Running loop #6
2025-06-19T18:30:43.304Z,1750357843.304 [Default:CheckIn] Running Loop=6
2025-06-19T18:30:43.304Z,1750357843.304 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-19T18:30:43.304Z,1750357843.304 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-19T18:30:45.316Z,1750357845.316 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183047.00,A,3648.15296,N,12147.21539,W,0.019,198.97,190625,,,A*77
2025-06-19T18:30:45.318Z,1750357845.318 [NAL9602](INFO): GPS fix at 20250619T183047: (36.802549, -121.786923)
2025-06-19T18:30:45.328Z,1750357845.328 [Default:CheckIn:Read_GPS] Stopped
2025-06-19T18:30:45.328Z,1750357845.328 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-19T18:30:52.747Z,1750357852.747 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20250619T175306/Courier0027.lzma
2025-06-19T18:30:53.750Z,1750357853.750 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Courier0027.lzma.bak
2025-06-19T18:30:53.750Z,1750357853.750 [DataOverHttps](INFO): SBD MOMSN=25229626
2025-06-19T18:31:09.555Z,1750357869.555 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250619T175306/Express0028.lzma
2025-06-19T18:31:09.968Z,1750357869.968 [NAL9602](INFO): SBD MO Status=2, MOMSN=9579, MT Status=2, MTMSN=0
2025-06-19T18:31:09.968Z,1750357869.968 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-19T18:31:10.559Z,1750357870.559 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Express0028.lzma.bak
2025-06-19T18:31:10.559Z,1750357870.559 [DataOverHttps](INFO): SBD MOMSN=25229629
2025-06-19T18:31:12.008Z,1750357872.008 [Default:CheckIn:Read_Iridium] Stopped
2025-06-19T18:31:12.009Z,1750357872.009 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-19T18:31:12.009Z,1750357872.009 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-19T18:31:35.824Z,1750357895.824 [NAL9602](INFO): SBD MO Status=2, MOMSN=9579, MT Status=2, MTMSN=0
2025-06-19T18:31:35.824Z,1750357895.824 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-19T18:32:12.182Z,1750357932.182 [NAL9602](INFO): SBD MO Status=2, MOMSN=9579, MT Status=2, MTMSN=0
2025-06-19T18:32:12.182Z,1750357932.182 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-19T18:35:49.535Z,1750358149.535 [NAL9602](INFO): SBD MO Status=2, MOMSN=9579, MT Status=2, MTMSN=0
2025-06-19T18:35:49.536Z,1750358149.536 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-19T18:35:49.941Z,1750358149.941 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-06-19T18:36:12.580Z,1750358172.580 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-19T18:36:12.581Z,1750358172.581 [Default:CheckIn:C.Wait] Stopped
2025-06-19T18:36:12.581Z,1750358172.581 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-19T18:36:12.581Z,1750358172.581 [Default:CheckIn:D] Running Loop=1
2025-06-19T18:36:12.982Z,1750358172.982 [Default:CheckIn:D] Stopped
2025-06-19T18:36:12.982Z,1750358172.982 [Default:CheckIn:E] Running Loop=1
2025-06-19T18:36:13.379Z,1750358173.379 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 37.188932 min
2025-06-19T18:36:13.379Z,1750358173.379 [Default:CheckIn:E] Stopped
2025-06-19T18:36:13.379Z,1750358173.379 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-19T18:36:13.379Z,1750358173.379 [Default:CheckIn] Stopped
2025-06-19T18:36:13.379Z,1750358173.379 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-19T18:36:13.380Z,1750358173.380 [Default:CheckIn](INFO): Running loop #7
2025-06-19T18:36:13.380Z,1750358173.380 [Default:CheckIn] Running Loop=7
2025-06-19T18:36:13.380Z,1750358173.380 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-19T18:36:13.380Z,1750358173.380 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-19T18:36:15.393Z,1750358175.393 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183617.00,A,3648.14444,N,12147.25099,W,1.477,298.80,190625,,,A*7F
2025-06-19T18:36:15.396Z,1750358175.396 [NAL9602](INFO): GPS fix at 20250619T183617: (36.802407, -121.787516)
2025-06-19T18:36:15.406Z,1750358175.406 [Default:CheckIn:Read_GPS] Stopped
2025-06-19T18:36:15.406Z,1750358175.406 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-19T18:36:24.463Z,1750358184.463 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250619T175306/Courier0030.lzma
2025-06-19T18:36:25.465Z,1750358185.465 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Courier0030.lzma.bak
2025-06-19T18:36:25.465Z,1750358185.465 [DataOverHttps](INFO): SBD MOMSN=25229638
2025-06-19T18:36:41.700Z,1750358201.700 [DataOverHttps](INFO): Sending 238 bytes from file Logs/20250619T175306/Express0031.lzma
2025-06-19T18:36:42.701Z,1750358202.701 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Express0031.lzma.bak
2025-06-19T18:36:42.701Z,1750358202.701 [DataOverHttps](INFO): SBD MOMSN=25229641
2025-06-19T18:36:44.114Z,1750358204.114 [Default:CheckIn:Read_Iridium] Stopped
2025-06-19T18:36:44.114Z,1750358204.114 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-19T18:36:44.114Z,1750358204.114 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-19T18:36:48.136Z,1750358208.136 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-19T18:38:27.284Z,1750358307.284 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.619305
2025-06-19T18:38:46.704Z,1750358326.704 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003321
2025-06-19T18:41:44.698Z,1750358504.698 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-19T18:41:44.698Z,1750358504.698 [Default:CheckIn:C.Wait] Stopped
2025-06-19T18:41:44.698Z,1750358504.698 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-19T18:41:44.698Z,1750358504.698 [Default:CheckIn:D] Running Loop=1
2025-06-19T18:41:45.102Z,1750358505.102 [Default:CheckIn:D] Stopped
2025-06-19T18:41:45.102Z,1750358505.102 [Default:CheckIn:E] Running Loop=1
2025-06-19T18:41:45.505Z,1750358505.505 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.724264 min
2025-06-19T18:41:45.505Z,1750358505.505 [Default:CheckIn:E] Stopped
2025-06-19T18:41:45.505Z,1750358505.505 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-19T18:41:45.505Z,1750358505.505 [Default:CheckIn] Stopped
2025-06-19T18:41:45.505Z,1750358505.505 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-19T18:41:45.505Z,1750358505.505 [Default:CheckIn](INFO): Running loop #8
2025-06-19T18:41:45.505Z,1750358505.505 [Default:CheckIn] Running Loop=8
2025-06-19T18:41:45.505Z,1750358505.505 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-19T18:41:45.505Z,1750358505.505 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-19T18:41:47.526Z,1750358507.526 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184149.00,A,3648.18197,N,12147.26475,W,0.117,259.23,190625,,,A*70
2025-06-19T18:41:47.528Z,1750358507.528 [NAL9602](INFO): GPS fix at 20250619T184149: (36.803033, -121.787746)
2025-06-19T18:41:47.538Z,1750358507.538 [Default:CheckIn:Read_GPS] Stopped
2025-06-19T18:41:47.538Z,1750358507.538 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-19T18:41:54.415Z,1750358514.415 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250619T175306/Courier0033.lzma
2025-06-19T18:41:55.417Z,1750358515.417 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Courier0033.lzma.bak
2025-06-19T18:41:55.417Z,1750358515.417 [DataOverHttps](INFO): SBD MOMSN=25229693
2025-06-19T18:42:11.331Z,1750358531.331 [DataOverHttps](INFO): Sending 166 bytes from file Logs/20250619T175306/Express0034.lzma
2025-06-19T18:42:12.334Z,1750358532.334 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Express0034.lzma.bak
2025-06-19T18:42:12.334Z,1750358532.334 [DataOverHttps](INFO): SBD MOMSN=25229696
2025-06-19T18:42:13.808Z,1750358533.808 [Default:CheckIn:Read_Iridium] Stopped
2025-06-19T18:42:13.808Z,1750358533.808 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-19T18:42:13.808Z,1750358533.808 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-19T18:46:49.736Z,1750358809.736 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-06-19T18:47:14.390Z,1750358834.390 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-19T18:47:14.390Z,1750358834.390 [Default:CheckIn:C.Wait] Stopped
2025-06-19T18:47:14.391Z,1750358834.391 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-19T18:47:14.391Z,1750358834.391 [Default:CheckIn:D] Running Loop=1
2025-06-19T18:47:14.804Z,1750358834.804 [Default:CheckIn:D] Stopped
2025-06-19T18:47:14.804Z,1750358834.804 [Default:CheckIn:E] Running Loop=1
2025-06-19T18:47:15.209Z,1750358835.209 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.219287 min
2025-06-19T18:47:15.209Z,1750358835.209 [Default:CheckIn:E] Stopped
2025-06-19T18:47:15.210Z,1750358835.210 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-19T18:47:15.210Z,1750358835.210 [Default:CheckIn] Stopped
2025-06-19T18:47:15.210Z,1750358835.210 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-19T18:47:15.210Z,1750358835.210 [Default:CheckIn](INFO): Running loop #9
2025-06-19T18:47:15.210Z,1750358835.210 [Default:CheckIn] Running Loop=9
2025-06-19T18:47:15.210Z,1750358835.210 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-19T18:47:15.210Z,1750358835.210 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-19T18:47:17.211Z,1750358837.211 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184718.00,A,3648.18225,N,12147.26676,W,0.019,259.23,190625,,,A*76
2025-06-19T18:47:17.213Z,1750358837.213 [NAL9602](INFO): GPS fix at 20250619T184718: (36.803038, -121.787779)
2025-06-19T18:47:17.224Z,1750358837.224 [Default:CheckIn:Read_GPS] Stopped
2025-06-19T18:47:17.224Z,1750358837.224 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-19T18:47:24.203Z,1750358844.203 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250619T175306/Courier0036.lzma
2025-06-19T18:47:25.206Z,1750358845.206 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Courier0036.lzma.bak
2025-06-19T18:47:25.206Z,1750358845.206 [DataOverHttps](INFO): SBD MOMSN=25229767
2025-06-19T18:47:40.000Z,1750358861.000 [DataOverHttps](INFO): Sending 229 bytes from file Logs/20250619T175306/Express0037.lzma
2025-06-19T18:47:42.001Z,1750358862.001 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Express0037.lzma.bak
2025-06-19T18:47:42.001Z,1750358862.001 [DataOverHttps](INFO): SBD MOMSN=25229776
2025-06-19T18:47:43.483Z,1750358863.483 [Default:CheckIn:Read_Iridium] Stopped
2025-06-19T18:47:43.483Z,1750358863.483 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-19T18:47:43.483Z,1750358863.483 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-19T18:47:49.933Z,1750358869.933 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-19T18:52:44.068Z,1750359164.068 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-19T18:52:44.068Z,1750359164.068 [Default:CheckIn:C.Wait] Stopped
2025-06-19T18:52:44.068Z,1750359164.068 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-19T18:52:44.070Z,1750359164.070 [Default:CheckIn:D] Running Loop=1
2025-06-19T18:52:44.480Z,1750359164.480 [Default:CheckIn:D] Stopped
2025-06-19T18:52:44.480Z,1750359164.480 [Default:CheckIn:E] Running Loop=1
2025-06-19T18:52:44.876Z,1750359164.876 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 53.713900 min
2025-06-19T18:52:44.876Z,1750359164.876 [Default:CheckIn:E] Stopped
2025-06-19T18:52:44.876Z,1750359164.876 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-19T18:52:44.876Z,1750359164.876 [Default:CheckIn] Stopped
2025-06-19T18:52:44.876Z,1750359164.876 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-19T18:52:44.876Z,1750359164.876 [Default:CheckIn](INFO): Running loop #10
2025-06-19T18:52:44.876Z,1750359164.876 [Default:CheckIn] Running Loop=10
2025-06-19T18:52:44.876Z,1750359164.876 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-19T18:52:44.876Z,1750359164.876 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-19T18:52:46.888Z,1750359166.888 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185248.00,A,3648.17825,N,12147.27554,W,0.058,259.23,190625,,,A*75
2025-06-19T18:52:46.891Z,1750359166.891 [NAL9602](INFO): GPS fix at 20250619T185248: (36.802971, -121.787926)
2025-06-19T18:52:46.901Z,1750359166.901 [Default:CheckIn:Read_GPS] Stopped
2025-06-19T18:52:46.901Z,1750359166.901 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-19T18:52:54.087Z,1750359174.087 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250619T175306/Courier0039.lzma
2025-06-19T18:52:55.089Z,1750359175.089 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Courier0039.lzma.bak
2025-06-19T18:52:55.089Z,1750359175.089 [DataOverHttps](INFO): SBD MOMSN=25229838
2025-06-19T18:53:10.939Z,1750359190.939 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20250619T175306/Express0040.lzma
2025-06-19T18:53:11.941Z,1750359191.941 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Express0040.lzma.bak
2025-06-19T18:53:11.942Z,1750359191.942 [DataOverHttps](INFO): SBD MOMSN=25229841
2025-06-19T18:53:13.581Z,1750359193.581 [Default:CheckIn:Read_Iridium] Stopped
2025-06-19T18:53:13.581Z,1750359193.581 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-19T18:53:13.581Z,1750359193.581 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-19T18:53:17.593Z,1750359197.593 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-06-19T18:53:17.675Z,1750359197.675 [NAL9602](ERROR): received:
+CSQ:0
OK79, 2, 0, 0, 0
OK
2025-06-19T18:57:48.681Z,1750359468.681 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-06-19T18:58:14.145Z,1750359494.145 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-19T18:58:14.145Z,1750359494.145 [Default:CheckIn:C.Wait] Stopped
2025-06-19T18:58:14.145Z,1750359494.145 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-19T18:58:14.145Z,1750359494.145 [Default:CheckIn:D] Running Loop=1
2025-06-19T18:58:14.538Z,1750359494.538 [Default:CheckIn:D] Stopped
2025-06-19T18:58:14.538Z,1750359494.538 [Default:CheckIn:E] Running Loop=1
2025-06-19T18:58:14.943Z,1750359494.943 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 59.214860 min
2025-06-19T18:58:14.943Z,1750359494.943 [Default:CheckIn:E] Stopped
2025-06-19T18:58:14.943Z,1750359494.943 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-19T18:58:14.943Z,1750359494.943 [Default:CheckIn] Stopped
2025-06-19T18:58:14.944Z,1750359494.944 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-19T18:58:14.944Z,1750359494.944 [Default:CheckIn](INFO): Running loop #11
2025-06-19T18:58:14.944Z,1750359494.944 [Default:CheckIn] Running Loop=11
2025-06-19T18:58:14.944Z,1750359494.944 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-19T18:58:14.944Z,1750359494.944 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-19T18:58:16.957Z,1750359496.957 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185818.00,A,3648.18380,N,12147.26705,W,0.097,259.23,190625,,,A*75
2025-06-19T18:58:16.959Z,1750359496.959 [NAL9602](INFO): GPS fix at 20250619T185818: (36.803063, -121.787784)
2025-06-19T18:58:16.970Z,1750359496.970 [Default:CheckIn:Read_GPS] Stopped
2025-06-19T18:58:16.970Z,1750359496.970 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-19T18:58:27.191Z,1750359507.191 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250619T175306/Courier0042.lzma
2025-06-19T18:58:28.193Z,1750359508.193 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Courier0042.lzma.bak
2025-06-19T18:58:28.193Z,1750359508.193 [DataOverHttps](INFO): SBD MOMSN=25229865
2025-06-19T18:58:44.081Z,1750359524.081 [DataOverHttps](INFO): Sending 224 bytes from file Logs/20250619T175306/Express0043.lzma
2025-06-19T18:58:45.081Z,1750359525.081 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Express0043.lzma.bak
2025-06-19T18:58:45.081Z,1750359525.081 [DataOverHttps](INFO): SBD MOMSN=25229868
2025-06-19T18:58:46.529Z,1750359526.529 [Default:CheckIn:Read_Iridium] Stopped
2025-06-19T18:58:46.530Z,1750359526.530 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-19T18:58:46.530Z,1750359526.530 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-19T18:58:48.925Z,1750359528.925 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-19T19:03:47.110Z,1750359827.110 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-19T19:03:47.110Z,1750359827.110 [Default:CheckIn:C.Wait] Stopped
2025-06-19T19:03:47.110Z,1750359827.110 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-19T19:03:47.110Z,1750359827.110 [Default:CheckIn:D] Running Loop=1
2025-06-19T19:03:47.522Z,1750359827.522 [Default:CheckIn:D] Stopped
2025-06-19T19:03:47.522Z,1750359827.522 [Default:CheckIn:E] Running Loop=1
2025-06-19T19:03:47.921Z,1750359827.921 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 64.764596 min
2025-06-19T19:03:47.921Z,1750359827.921 [Default:CheckIn:E] Stopped
2025-06-19T19:03:47.922Z,1750359827.922 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-19T19:03:47.922Z,1750359827.922 [Default:CheckIn] Stopped
2025-06-19T19:03:47.922Z,1750359827.922 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-19T19:03:47.922Z,1750359827.922 [Default:CheckIn](INFO): Running loop #12
2025-06-19T19:03:47.922Z,1750359827.922 [Default:CheckIn] Running Loop=12
2025-06-19T19:03:47.922Z,1750359827.922 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-19T19:03:47.922Z,1750359827.922 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-19T19:03:49.931Z,1750359829.931 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190351.00,A,3648.17835,N,12147.27500,W,0.233,258.31,190625,,,A*75
2025-06-19T19:03:49.934Z,1750359829.934 [NAL9602](INFO): GPS fix at 20250619T190351: (36.802973, -121.787917)
2025-06-19T19:03:49.969Z,1750359829.969 [Default:CheckIn:Read_GPS] Stopped
2025-06-19T19:03:49.969Z,1750359829.969 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-19T19:03:57.232Z,1750359837.232 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250619T175306/Courier0045.lzma
2025-06-19T19:03:58.229Z,1750359838.229 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Courier0045.lzma.bak
2025-06-19T19:03:58.229Z,1750359838.229 [DataOverHttps](INFO): SBD MOMSN=25229879
2025-06-19T19:04:14.163Z,1750359854.163 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20250619T175306/Express0046.lzma
2025-06-19T19:04:15.165Z,1750359855.165 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Express0046.lzma.bak
2025-06-19T19:04:15.165Z,1750359855.165 [DataOverHttps](INFO): SBD MOMSN=25229882
2025-06-19T19:04:16.610Z,1750359856.610 [Default:CheckIn:Read_Iridium] Stopped
2025-06-19T19:04:16.610Z,1750359856.610 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-19T19:04:16.610Z,1750359856.610 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-19T19:04:20.661Z,1750359860.661 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-06-19T19:04:20.743Z,1750359860.743 [NAL9602](ERROR): received:
+CSQ:0
OK79, 2, 0, 0, 0
OK
2025-06-19T19:08:51.769Z,1750360131.769 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-06-19T19:09:17.235Z,1750360157.235 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-19T19:09:17.235Z,1750360157.235 [Default:CheckIn:C.Wait] Stopped
2025-06-19T19:09:17.235Z,1750360157.235 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-19T19:09:17.235Z,1750360157.235 [Default:CheckIn:D] Running Loop=1
2025-06-19T19:09:17.637Z,1750360157.637 [Default:CheckIn:D] Stopped
2025-06-19T19:09:17.637Z,1750360157.637 [Default:CheckIn:E] Running Loop=1
2025-06-19T19:09:18.048Z,1750360158.048 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 70.266504 min
2025-06-19T19:09:18.048Z,1750360158.048 [Default:CheckIn:E] Stopped
2025-06-19T19:09:18.048Z,1750360158.048 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-19T19:09:18.048Z,1750360158.048 [Default:CheckIn] Stopped
2025-06-19T19:09:18.048Z,1750360158.048 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-19T19:09:18.049Z,1750360158.049 [Default:CheckIn](INFO): Running loop #13
2025-06-19T19:09:18.049Z,1750360158.049 [Default:CheckIn] Running Loop=13
2025-06-19T19:09:18.049Z,1750360158.049 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-19T19:09:18.049Z,1750360158.049 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-19T19:09:20.063Z,1750360160.063 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190921.00,A,3648.16877,N,12147.28487,W,0.117,258.31,190625,,,A*7B
2025-06-19T19:09:20.065Z,1750360160.065 [NAL9602](INFO): GPS fix at 20250619T190921: (36.802813, -121.788081)
2025-06-19T19:09:20.076Z,1750360160.076 [Default:CheckIn:Read_GPS] Stopped
2025-06-19T19:09:20.076Z,1750360160.076 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-19T19:09:27.459Z,1750360167.459 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250619T175306/Courier0048.lzma
2025-06-19T19:09:28.461Z,1750360168.461 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Courier0048.lzma.bak
2025-06-19T19:09:28.461Z,1750360168.461 [DataOverHttps](INFO): SBD MOMSN=25229892
2025-06-19T19:09:44.284Z,1750360184.284 [DataOverHttps](INFO): Sending 228 bytes from file Logs/20250619T175306/Express0049.lzma
2025-06-19T19:09:45.285Z,1750360185.285 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Express0049.lzma.bak
2025-06-19T19:09:45.285Z,1750360185.285 [DataOverHttps](INFO): SBD MOMSN=25229895
2025-06-19T19:09:46.733Z,1750360186.733 [Default:CheckIn:Read_Iridium] Stopped
2025-06-19T19:09:46.733Z,1750360186.733 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-19T19:09:46.733Z,1750360186.733 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-19T19:09:51.964Z,1750360191.964 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-19T19:14:47.307Z,1750360487.307 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-19T19:14:47.307Z,1750360487.307 [Default:CheckIn:C.Wait] Stopped
2025-06-19T19:14:47.307Z,1750360487.307 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-19T19:14:47.308Z,1750360487.308 [Default:CheckIn:D] Running Loop=1
2025-06-19T19:14:47.702Z,1750360487.702 [Default:CheckIn:D] Stopped
2025-06-19T19:14:47.702Z,1750360487.702 [Default:CheckIn:E] Running Loop=1
2025-06-19T19:14:48.108Z,1750360488.108 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 75.767603 min
2025-06-19T19:14:48.108Z,1750360488.108 [Default:CheckIn:E] Stopped
2025-06-19T19:14:48.108Z,1750360488.108 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-19T19:14:48.108Z,1750360488.108 [Default:CheckIn] Stopped
2025-06-19T19:14:48.109Z,1750360488.109 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-19T19:14:48.109Z,1750360488.109 [Default:CheckIn](INFO): Running loop #14
2025-06-19T19:14:48.109Z,1750360488.109 [Default:CheckIn] Running Loop=14
2025-06-19T19:14:48.109Z,1750360488.109 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-19T19:14:48.109Z,1750360488.109 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-19T19:14:50.120Z,1750360490.120 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191451.00,A,3648.16521,N,12147.27343,W,0.544,258.31,190625,,,A*7C
2025-06-19T19:14:50.123Z,1750360490.123 [NAL9602](INFO): GPS fix at 20250619T191451: (36.802754, -121.787891)
2025-06-19T19:14:50.133Z,1750360490.133 [Default:CheckIn:Read_GPS] Stopped
2025-06-19T19:14:50.133Z,1750360490.133 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-19T19:14:57.687Z,1750360497.687 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250619T175306/Courier0051.lzma
2025-06-19T19:14:58.689Z,1750360498.689 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Courier0051.lzma.bak
2025-06-19T19:14:58.689Z,1750360498.689 [DataOverHttps](INFO): SBD MOMSN=25229907
2025-06-19T19:15:14.521Z,1750360514.521 [DataOverHttps](INFO): Sending 148 bytes from file Logs/20250619T175306/Express0052.lzma
2025-06-19T19:15:15.521Z,1750360515.521 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Express0052.lzma.bak
2025-06-19T19:15:15.522Z,1750360515.522 [DataOverHttps](INFO): SBD MOMSN=25229911
2025-06-19T19:15:17.199Z,1750360517.199 [Default:CheckIn:Read_Iridium] Stopped
2025-06-19T19:15:17.199Z,1750360517.199 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-19T19:15:17.199Z,1750360517.199 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-19T19:19:52.721Z,1750360792.721 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-06-19T19:20:17.780Z,1750360817.780 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-19T19:20:17.780Z,1750360817.780 [Default:CheckIn:C.Wait] Stopped
2025-06-19T19:20:17.780Z,1750360817.780 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-19T19:20:17.780Z,1750360817.780 [Default:CheckIn:D] Running Loop=1
2025-06-19T19:20:18.184Z,1750360818.184 [Default:CheckIn:D] Stopped
2025-06-19T19:20:18.184Z,1750360818.184 [Default:CheckIn:E] Running Loop=1
2025-06-19T19:20:18.595Z,1750360818.595 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 81.275627 min
2025-06-19T19:20:18.595Z,1750360818.595 [Default:CheckIn:E] Stopped
2025-06-19T19:20:18.595Z,1750360818.595 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-19T19:20:18.595Z,1750360818.595 [Default:CheckIn] Stopped
2025-06-19T19:20:18.596Z,1750360818.596 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-19T19:20:18.596Z,1750360818.596 [Default:CheckIn](INFO): Running loop #15
2025-06-19T19:20:18.596Z,1750360818.596 [Default:CheckIn] Running Loop=15
2025-06-19T19:20:18.596Z,1750360818.596 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-19T19:20:18.596Z,1750360818.596 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-19T19:20:20.602Z,1750360820.602 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192022.00,A,3648.16708,N,12147.27246,W,0.039,0.00,190625,,,A*70
2025-06-19T19:20:20.604Z,1750360820.604 [NAL9602](INFO): GPS fix at 20250619T192022: (36.802785, -121.787874)
2025-06-19T19:20:20.635Z,1750360820.635 [Default:CheckIn:Read_GPS] Stopped
2025-06-19T19:20:20.635Z,1750360820.635 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-19T19:20:27.691Z,1750360827.691 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250619T175306/Courier0054.lzma
2025-06-19T19:20:28.693Z,1750360828.693 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Courier0054.lzma.bak
2025-06-19T19:20:28.693Z,1750360828.693 [DataOverHttps](INFO): SBD MOMSN=25229914
2025-06-19T19:20:44.492Z,1750360844.492 [DataOverHttps](INFO): Sending 228 bytes from file Logs/20250619T175306/Express0055.lzma
2025-06-19T19:20:45.494Z,1750360845.494 [DataOverHttps](INFO): Moved sent file to Logs/20250619T175306/Express0055.lzma.bak
2025-06-19T19:20:45.495Z,1750360845.495 [DataOverHttps](INFO): SBD MOMSN=25229917
2025-06-19T19:20:46.874Z,1750360846.874 [Default:CheckIn:Read_Iridium] Stopped
2025-06-19T19:20:46.874Z,1750360846.874 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-19T19:20:46.875Z,1750360846.875 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-19T19:20:52.921Z,1750360852.921 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-19T19:22:59.610Z,1750360979.610 [DAT](INFO): DAT read: 19:22:58.6043 LVL= 5760, 4001, 4754, 4483, AGC= 75, IDX= 13,-0.33,-2.601,-1.204,-2.903,-1.912, PHS=-0.705, 0.783,-0.944, RAW= 337.3, 10.7, CAL= 338.9, 13.3, ROT= 171.1, -13.3
2025-06-19T19:22:59.611Z,1750360979.611 [DAT](INFO): got valid direction response:
19:22:58.6043 LVL= 5760, 4001, 4754, 4483, AGC= 75, IDX= 13,-0.33,-2.601,-1.204,-2.903,-1.912, PHS=-0.705, 0.783,-0.944, RAW= 337.3, 10.7, CAL= 338.9, 13.3, ROT= 171.1, -13.3
2025-06-19T19:22:59.612Z,1750360979.612 [DAT](INFO): DAT read: Rx Time:19:22:58.6043
2025-06-19T19:22:59.613Z,1750360979.613 [DAT](INFO): Rx dataTimestamp_ set to:1750360979.612523
2025-06-19T19:22:59.613Z,1750360979.613 [DAT](INFO): DAT read: $Low SNR acquisition
2025-06-19T19:22:59.614Z,1750360979.614 [DAT](INFO): Received low SNR in chirp
2025-06-19T19:22:59.628Z,1750360979.628 [DAT](INFO): #Rx 2: Read direction message, but no range.
2025-06-19T19:22:59.629Z,1750360979.629 [DAT](INFO): direction in FSK: [-0.961462,0.150561,0.230050]
2025-06-19T19:25:06.546Z,1750361106.546 [CommandExec](IMPORTANT): got command failComponent
2025-06-19T19:25:06.546Z,1750361106.546 [CommandExec](IMPORTANT): Failed components:
2025-06-19T19:25:06.546Z,1750361106.546 [CommandExec](IMPORTANT): No failed Components.
2025-06-19T19:25:08.565Z,1750361108.565 [CommandExec](IMPORTANT): got command quit
2025-06-19T19:25:09.581Z,1750361109.581 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2025-06-19T19:25:09.581Z,1750361109.581 [CommandExec](INFO): Uninitializing the command executive.
2025-06-19T19:25:09.581Z,1750361109.581 [CommandExec](INFO): Uninitializing the command scheduler.
2025-06-19T19:25:09.582Z,1750361109.582 [CommandExec ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:09.737Z,1750361109.737 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2025-06-19T19:25:09.737Z,1750361109.737 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2025-06-19T19:25:09.737Z,1750361109.737 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:09.737Z,1750361109.737 [NavChartDb](INFO): Join timeout helper Thread ID is 5377
2025-06-19T19:25:10.081Z,1750361110.081 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2025-06-19T19:25:10.082Z,1750361110.082 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:10.093Z,1750361110.093 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2025-06-19T19:25:10.093Z,1750361110.093 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:10.094Z,1750361110.094 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 5378
2025-06-19T19:25:10.241Z,1750361110.241 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2025-06-19T19:25:10.241Z,1750361110.241 [WetLabsBB2FL](INFO): Powering down
2025-06-19T19:25:10.242Z,1750361110.242 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:10.249Z,1750361110.249 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2025-06-19T19:25:10.249Z,1750361110.249 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:10.249Z,1750361110.249 [CTD_Seabird](INFO): Join timeout helper Thread ID is 5379
2025-06-19T19:25:10.498Z,1750361110.498 [CTD_Seabird](INFO): Powering down
2025-06-19T19:25:10.513Z,1750361110.513 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2025-06-19T19:25:10.513Z,1750361110.513 [CTD_Seabird](INFO): Powering down
2025-06-19T19:25:10.525Z,1750361110.525 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:10.545Z,1750361110.545 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2025-06-19T19:25:10.545Z,1750361110.545 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:10.545Z,1750361110.545 [Radio_Surface](INFO): Join timeout helper Thread ID is 5380
2025-06-19T19:25:10.929Z,1750361110.929 [Radio_Surface](INFO): Powering down
2025-06-19T19:25:10.930Z,1750361110.930 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2025-06-19T19:25:10.930Z,1750361110.930 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:10.941Z,1750361110.941 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2025-06-19T19:25:10.941Z,1750361110.941 [Onboard ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:10.941Z,1750361110.941 [Onboard](INFO): Join timeout helper Thread ID is 5381
2025-06-19T19:25:11.005Z,1750361111.005 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2025-06-19T19:25:11.833Z,1750361111.833 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2025-06-19T19:25:11.833Z,1750361111.833 [Onboard ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:11.850Z,1750361111.850 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2025-06-19T19:25:11.850Z,1750361111.850 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:11.851Z,1750361111.851 [DataOverHttps](INFO): Join timeout helper Thread ID is 5382
2025-06-19T19:25:12.009Z,1750361112.009 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2025-06-19T19:25:12.009Z,1750361112.009 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:12.017Z,1750361112.017 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler
2025-06-19T19:25:12.018Z,1750361112.018 [DAT ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:12.018Z,1750361112.018 [DAT](INFO): Join timeout helper Thread ID is 5383
2025-06-19T19:25:12.181Z,1750361112.181 [DAT](INFO): Powering down
2025-06-19T19:25:12.249Z,1750361112.249 [DAT ThreadHandler](INFO): Uninitializing protected caller thread.
2025-06-19T19:25:12.249Z,1750361112.249 [DAT](INFO): Powering down
2025-06-19T19:25:12.250Z,1750361112.250 [DAT ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:12.269Z,1750361112.269 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2025-06-19T19:25:12.269Z,1750361112.269 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:12.270Z,1750361112.270 [BackseatComponent](INFO): Join timeout helper Thread ID is 5384
2025-06-19T19:25:12.365Z,1750361112.365 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2025-06-19T19:25:12.365Z,1750361112.365 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:12.372Z,1750361112.372 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2025-06-19T19:25:12.373Z,1750361112.373 [logger ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:12.381Z,1750361112.381 [logger](INFO): Join timeout helper Thread ID is 5385
2025-06-19T19:25:12.385Z,1750361112.385 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2025-06-19T19:25:12.385Z,1750361112.385 [logger ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:12.386Z,1750361112.386 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2025-06-19T19:25:12.386Z,1750361112.386 [CommandLine ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:12.387Z,1750361112.387 [CommandLine](INFO): Join timeout helper Thread ID is 5386
2025-06-19T19:25:12.397Z,1750361112.397 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2025-06-19T19:25:12.397Z,1750361112.397 [CommandLine ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:12.413Z,1750361112.413 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2025-06-19T19:25:12.413Z,1750361112.413 [CommandExec ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:12.414Z,1750361112.414 [CommandExec](INFO): Join timeout helper Thread ID is 5387
2025-06-19T19:25:12.415Z,1750361112.415 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2025-06-19T19:25:12.415Z,1750361112.415 [controlThread ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:12.415Z,1750361112.415 [controlThread](INFO): Join timeout helper Thread ID is 5388
2025-06-19T19:25:12.769Z,1750361112.769 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2025-06-19T19:25:12.769Z,1750361112.769 [controlThread](DEBUG): Uninitializing ControlThread
2025-06-19T19:25:12.769Z,1750361112.769 [AHRS_M2](INFO): Powering down
2025-06-19T19:25:12.842Z,1750361112.842 [NAL9602](INFO): Powering down
2025-06-19T19:25:12.843Z,1750361112.843 [Sonardyne_Nano](INFO): Powering down
2025-06-19T19:25:12.961Z,1750361112.961 [Waterlinked](INFO): Powering down
2025-06-19T19:25:13.049Z,1750361113.049 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2025-06-19T19:25:13.050Z,1750361113.050 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2025-06-19T19:25:13.050Z,1750361113.050 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2025-06-19T19:25:13.051Z,1750361113.051 [MissionManager](INFO): Uninitializing Mission Default
2025-06-19T19:25:13.051Z,1750361113.051 [Default] Stopped
2025-06-19T19:25:13.051Z,1750361113.051 [Default](DEBUG): Aggregate::uninitialize Default
2025-06-19T19:25:13.051Z,1750361113.051 [Default:B.GoToSurface] Stopped
2025-06-19T19:25:13.051Z,1750361113.051 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-06-19T19:25:13.051Z,1750361113.051 [Default:CheckIn] Stopped
2025-06-19T19:25:13.051Z,1750361113.051 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-19T19:25:13.051Z,1750361113.051 [Default:CheckIn:C.Wait] Stopped
2025-06-19T19:25:13.051Z,1750361113.051 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-19T19:25:13.054Z,1750361113.054 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2025-06-19T19:25:13.055Z,1750361113.055 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2025-06-19T19:25:13.055Z,1750361113.055 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2025-06-19T19:25:13.055Z,1750361113.055 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2025-06-19T19:25:13.056Z,1750361113.056 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2025-06-19T19:25:13.056Z,1750361113.056 [BuoyancyServo](INFO): Powering down
2025-06-19T19:25:13.069Z,1750361113.069 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2025-06-19T19:25:13.069Z,1750361113.069 [ElevatorServo](INFO): Powering down
2025-06-19T19:25:13.070Z,1750361113.070 [MassServo](DEBUG): Uninitialize Mass Servo.
2025-06-19T19:25:13.070Z,1750361113.070 [MassServo](INFO): Powering down
2025-06-19T19:25:13.070Z,1750361113.070 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2025-06-19T19:25:13.071Z,1750361113.071 [RudderServo](INFO): Powering down
2025-06-19T19:25:13.071Z,1750361113.071 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2025-06-19T19:25:13.071Z,1750361113.071 [ThrusterHE](INFO): Powering down
2025-06-19T19:25:13.073Z,1750361113.073 [SBIT](DEBUG): Uninitialize SBIT Component.
2025-06-19T19:25:13.073Z,1750361113.073 [IBIT](DEBUG): Uninitialize IBIT Component.
2025-06-19T19:25:13.073Z,1750361113.073 [CBIT](DEBUG): Uninitialize CBIT Component.
2025-06-19T19:25:13.073Z,1750361113.073 [CBIT](DEBUG): Powering off loads.
2025-06-19T19:25:13.084Z,1750361113.084 [CBIT](DEBUG): Disabling WDT.
2025-06-19T19:25:13.097Z,1750361113.097 [GFScanner](DEBUG): Uninitialize GFScanner component.
2025-06-19T19:25:13.097Z,1750361113.097 [GFScanner](DEBUG): Opening all GF detection circuits.
2025-06-19T19:25:13.098Z,1750361113.098 [controlThread ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:13.172Z,1750361113.172 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:13.175Z,1750361113.175 [Onboard ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:13.182Z,1750361113.182 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:13.188Z,1750361113.188 [DAT ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:13.230Z,1750361113.230 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:13.273Z,1750361113.273 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:13.277Z,1750361113.277 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:13.297Z,1750361113.297 [GFScanner](DEBUG): Uninitialize GFScanner component.
2025-06-19T19:25:13.297Z,1750361113.297 [GFScanner](DEBUG): Opening all GF detection circuits.
2025-06-19T19:25:13.313Z,1750361113.313 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2025-06-19T19:25:13.384Z,1750361113.384 [logger ThreadHandler](INFO): Thread cancelled.