Files
OpsLog/internal/extsvc/manager.go
T
rouggy bd9e091e65 fix: serialise auto-uploads so a burst doesn't 403 and leave QSOs at R
A QSO logged via UDP / ADIF-import fired `go m.upload` per QSO, so a pileup or
an ADIF-import burst hit a service with dozens of concurrent requests at once.
Club Log's nginx answers that burst with 403; the upload counts as failed and
the QSO stays at "R" while a lucky few go through — the real cause behind the
"it's uploaded but shows R" report (not the earlier display race).

Route all immediate/delayed auto-uploads through a single serialised worker
(one at a time, 250ms apart) so no burst ever trips a per-IP rate limiter.
upload() now reports whether a failure is transient (HTTP/rate-limit) vs
permanent (not eligible, wrong station callsign, no record); transient ones
are retried with exponential back-off (up to 4 attempts, 1s/2s/4s), so a QSO
that hit a momentary 403 ends up marked instead of stuck at R. A full queue
falls back to a goroutine rather than dropping an upload.
2026-07-19 03:05:02 +02:00

488 lines
17 KiB
Go
Raw Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
package extsvc
import (
"context"
"fmt"
"math/rand"
"net/http"
"strings"
"sync"
"time"
)
// baseCall extracts the operator's base callsign from a possibly-affixed call:
// for slashed forms (F4BPO/P, FW/F4BPO, 9A/F4BPO/P) it returns the longest
// token, which is the real call; otherwise the call itself. Upper-cased.
func baseCall(s string) string {
s = strings.ToUpper(strings.TrimSpace(s))
if !strings.Contains(s, "/") {
return s
}
best := ""
for _, part := range strings.Split(s, "/") {
if len(part) > len(best) {
best = part
}
}
return best
}
// sameBaseCall reports whether two callsigns belong to the same operator,
// ignoring portable prefixes/suffixes (F4BPO/P == F4BPO, FW/F4BPO == F4BPO).
func sameBaseCall(a, b string) bool {
return baseCall(a) == baseCall(b)
}
// SameBaseCall is the exported form of sameBaseCall, so the host app can apply
// the same "same operator?" rule when filtering an on-close upload batch by the
// active logbook's callsign.
func SameBaseCall(a, b string) bool { return sameBaseCall(a, b) }
// Deps are the host-app callbacks the Manager needs. Keeping them as
// function fields decouples extsvc from the qso/adif/settings packages and
// keeps the upload-scheduling logic testable.
type Deps struct {
Client *http.Client
// BuildADIF returns the ADIF record for a QSO id, with STATION_CALLSIGN
// overridden by forceCall when non-empty. ok=false means "skip silently"
// (row gone, missing required fields, …).
BuildADIF func(id int64, forceCall string) (record string, ok bool)
// MarkUploaded stamps the per-service upload status on the QSO row and
// notifies the UI. Called once, on success.
MarkUploaded func(svc Service, id int64, logID string)
// NotifyError surfaces a failed upload (logging + optional UI event).
NotifyError func(svc Service, id int64, err error)
// ShouldUpload reports whether a QSO is eligible for upload to this
// service, based on its sent status: QRZ/Club Log upload anything not
// yet "Y"; LoTW uploads only QSOs whose lotw_sent matches the configured
// Upload flag ("N" or "R"), à la Log4OM. Returning false skips the QSO.
ShouldUpload func(svc Service, id int64) bool
// StationCallOf returns the QSO's STATION_CALLSIGN. Used to guard against
// uploading a QSO into a logbook for a different callsign (the force-call
// option would otherwise silently relabel it). "" → no station call known.
StationCallOf func(id int64) string
// CloseUploadIDs returns the QSO ids to upload for a service when the app
// closes — scanning the WHOLE logbook, not just this session: LoTW returns
// rows whose lotw_sent matches the configured status set; QRZ/Club Log
// return anything not yet "Y". This is what makes an imported ADIF (old
// QSOs still marked unsent) upload on close. nil → nothing to do.
CloseUploadIDs func(svc Service) []int64
// Logf is an optional diagnostic logger.
Logf func(format string, args ...any)
}
// Manager owns the external-service config snapshot and schedules uploads
// when a QSO is logged. Immediate uploads run in their own goroutine;
// delayed uploads use a timer with a random 12 minute fuse.
type Manager struct {
deps Deps
mu sync.Mutex
cfg ExternalServices
rnd *rand.Rand
// uploadCh serialises immediate auto-uploads through a single worker. Firing a
// goroutine per QSO meant a pileup / ADIF-import burst hit a service with dozens
// of concurrent requests at once — Club Log's nginx answers that with 403, the
// upload is counted as failed and the QSO stays at "R" despite the others going
// through. One-at-a-time with a small gap keeps every upload under the limit.
uploadCh chan uploadJob
}
// uploadJob is one queued auto-upload.
type uploadJob struct {
svc Service
id int64
cfg ServiceConfig
attempt int // 0 on first try; incremented on each retry
}
// uploadGap spaces serialized uploads so a burst never trips a service's per-IP
// rate limiter. maxUploadAttempts bounds retries of a transient failure.
const (
uploadGap = 250 * time.Millisecond
maxUploadAttempts = 4
)
func NewManager(deps Deps) *Manager {
if deps.Client == nil {
deps.Client = &http.Client{Timeout: 20 * time.Second}
}
m := &Manager{
deps: deps,
// Seeded from the clock; the delay only needs to be unpredictable
// enough to spread bursts, not cryptographically random.
rnd: rand.New(rand.NewSource(time.Now().UnixNano())),
uploadCh: make(chan uploadJob, 4096),
}
go m.uploadWorker()
return m
}
// uploadWorker drains the queue one upload at a time, spacing them so a burst of
// freshly-logged QSOs can't hammer (and get 403'd by) a service. A transient
// failure is re-queued with an exponential back-off, so a QSO that hit a
// momentary rate-limit still ends up marked instead of stuck at "R".
func (m *Manager) uploadWorker() {
for job := range m.uploadCh {
ok, retryable := m.upload(job.svc, job.id, job.cfg)
if !ok && retryable && job.attempt+1 < maxUploadAttempts {
next := job
next.attempt++
backoff := time.Duration(1<<uint(job.attempt)) * time.Second // 1s, 2s, 4s…
m.logf("extsvc: %s upload of QSO %d will retry (attempt %d) in %s", job.svc, job.id, next.attempt+1, backoff)
time.AfterFunc(backoff, func() { m.enqueueJob(next) })
}
time.Sleep(uploadGap)
}
}
// enqueueUpload queues a first-attempt upload without blocking the logging path.
func (m *Manager) enqueueUpload(svc Service, id int64, cfg ServiceConfig) {
m.enqueueJob(uploadJob{svc: svc, id: id, cfg: cfg})
}
// enqueueJob queues a job (possibly a retry). If the queue is somehow full (an
// enormous burst), it falls back to a goroutine rather than dropping the upload —
// a dropped upload would leave the QSO stuck at "R".
func (m *Manager) enqueueJob(job uploadJob) {
select {
case m.uploadCh <- job:
default:
go m.upload(job.svc, job.id, job.cfg)
}
}
func (m *Manager) logf(format string, args ...any) {
if m.deps.Logf != nil {
m.deps.Logf(format, args...)
}
}
// SetConfig replaces the active config snapshot (called after the user
// saves the External Services settings).
func (m *Manager) SetConfig(cfg ExternalServices) {
m.mu.Lock()
defer m.mu.Unlock()
cfg.QRZ = cfg.QRZ.normalised()
cfg.Clublog = cfg.Clublog.normalised()
cfg.LoTW = cfg.LoTW.normalised()
cfg.HRDLog = cfg.HRDLog.normalised()
cfg.EQSL = cfg.EQSL.normalised()
m.cfg = cfg
}
// Config returns the current snapshot.
func (m *Manager) Config() ExternalServices {
m.mu.Lock()
defer m.mu.Unlock()
return m.cfg
}
// delaySeconds returns a random 60120s fuse for delayed uploads.
func (m *Manager) delaySeconds() time.Duration {
m.mu.Lock()
d := 60 + m.rnd.Intn(61) // [60, 120]
m.mu.Unlock()
return time.Duration(d) * time.Second
}
// OnQSOLogged is called after a QSO is inserted (manual entry or UDP
// auto-log). It fans out to every enabled, auto-upload service in the
// configured timing mode. Returns immediately.
func (m *Manager) OnQSOLogged(id int64) {
cfg := m.Config()
// QRZ.com
if qrz := cfg.QRZ; qrz.AutoUpload && qrz.APIKey != "" {
m.route(ServiceQRZ, id, qrz)
}
// Club Log — email + password + callsign are enough (no API key).
if cl := cfg.Clublog; cl.AutoUpload && cl.Email != "" && cl.Password != "" {
m.route(ServiceClublog, id, cl)
}
// LoTW — needs TQSL + a station location.
if lt := cfg.LoTW; lt.AutoUpload && lt.TQSLPath != "" && lt.StationLocation != "" {
m.route(ServiceLoTW, id, lt)
}
// HRDLog — needs the station callsign + the account upload code.
if h := cfg.HRDLog; h.AutoUpload && h.Callsign != "" && h.Code != "" {
m.route(ServiceHRDLog, id, h)
}
// eQSL — needs the account username (callsign) + password.
if e := cfg.EQSL; e.AutoUpload && e.Username != "" && e.Password != "" {
m.route(ServiceEQSL, id, e)
}
}
// route sends a logged QSO down the configured timing path: queue it for the
// app-close batch, or schedule an immediate / delayed upload.
func (m *Manager) route(svc Service, id int64, cfg ServiceConfig) {
if cfg.UploadMode == ModeOnClose {
// Nothing to queue: on-close upload sweeps the whole logbook from the
// database at shutdown (see FlushOnClose), so this QSO is picked up by
// its sent-status then — no in-memory tracking needed.
return
}
m.scheduleUpload(svc, id, cfg)
}
// scheduleUpload either queues the upload now (immediate) or arms a timer that
// queues it later (delayed). Both go through the serialised worker so uploads are
// never fired concurrently in a burst.
func (m *Manager) scheduleUpload(svc Service, id int64, cfg ServiceConfig) {
if cfg.UploadMode == ModeDelayed {
d := m.delaySeconds()
m.logf("extsvc: %s upload of QSO %d scheduled in %s", svc, id, d)
time.AfterFunc(d, func() { m.enqueueUpload(svc, id, cfg) })
return
}
m.enqueueUpload(svc, id, cfg)
}
// onCloseServices returns the services configured for on-close auto-upload,
// with the minimum credentials to actually run.
func (m *Manager) onCloseServices() []Service {
cfg := m.Config()
var out []Service
if q := cfg.QRZ; q.AutoUpload && q.UploadMode == ModeOnClose && q.APIKey != "" {
out = append(out, ServiceQRZ)
}
if c := cfg.Clublog; c.AutoUpload && c.UploadMode == ModeOnClose && c.Email != "" && c.Password != "" {
out = append(out, ServiceClublog)
}
if l := cfg.LoTW; l.AutoUpload && l.UploadMode == ModeOnClose && l.TQSLPath != "" && l.StationLocation != "" {
out = append(out, ServiceLoTW)
}
if h := cfg.HRDLog; h.AutoUpload && h.UploadMode == ModeOnClose && h.Callsign != "" && h.Code != "" {
out = append(out, ServiceHRDLog)
}
if e := cfg.EQSL; e.AutoUpload && e.UploadMode == ModeOnClose && e.Username != "" && e.Password != "" {
out = append(out, ServiceEQSL)
}
return out
}
// CloseUploadCount returns how many QSOs across the whole logbook would be
// uploaded at app close (sum over every on-close service). The shutdown
// sequence uses it to decide whether to show the upload step and its label.
func (m *Manager) CloseUploadCount() int {
if m.deps.CloseUploadIDs == nil {
return 0
}
n := 0
for _, svc := range m.onCloseServices() {
n += len(m.deps.CloseUploadIDs(svc))
}
return n
}
// FlushOnClose uploads every QSO due for an on-close push, scanning the whole
// logbook (not just this session). Called from the shutdown sequence. QRZ/Club
// Log go one-by-one (fast HTTP); LoTW is signed and uploaded as a single TQSL
// batch. Returns the number of QSOs uploaded successfully.
func (m *Manager) FlushOnClose() int {
if m.deps.CloseUploadIDs == nil {
return 0
}
cfg := m.Config()
uploaded := 0
for _, svc := range m.onCloseServices() {
ids := m.deps.CloseUploadIDs(svc)
if len(ids) == 0 {
continue
}
switch svc {
case ServiceLoTW:
uploaded += m.flushLoTWBatch(ids, cfg.LoTW)
case ServiceQRZ:
for _, id := range ids {
if ok, _ := m.upload(svc, id, cfg.QRZ); ok {
uploaded++
}
}
case ServiceClublog:
for _, id := range ids {
if ok, _ := m.upload(svc, id, cfg.Clublog); ok {
uploaded++
}
}
case ServiceHRDLog:
for _, id := range ids {
if ok, _ := m.upload(svc, id, cfg.HRDLog); ok {
uploaded++
}
}
case ServiceEQSL:
for _, id := range ids {
if ok, _ := m.upload(svc, id, cfg.EQSL); ok {
uploaded++
}
}
}
}
return uploaded
}
// flushLoTWBatch signs+uploads all queued LoTW QSOs in one TQSL run, then
// stamps each as uploaded on success.
func (m *Manager) flushLoTWBatch(ids []int64, cfg ServiceConfig) int {
var records []string
var kept []int64
for _, id := range ids {
// Skip QSOs not eligible (sent status doesn't match Upload flag).
if m.deps.ShouldUpload != nil && !m.deps.ShouldUpload(ServiceLoTW, id) {
continue
}
// Override STATION_CALLSIGN so /P etc. signs against the base cert.
if rec, ok := m.deps.BuildADIF(id, cfg.ForceStationCallsign); ok {
records = append(records, rec)
kept = append(kept, id)
}
}
if len(records) == 0 {
return 0
}
res, err := UploadLoTW(context.Background(), cfg, "", strings.Join(records, "\n"))
if err != nil || !res.OK {
if err == nil {
err = errFromResult(res)
}
m.logf("extsvc: lotw batch upload (%d QSOs) failed: %v", len(kept), err)
if m.deps.NotifyError != nil {
m.deps.NotifyError(ServiceLoTW, 0, err)
}
return 0
}
m.logf("extsvc: lotw batch upload OK (%d QSOs)", len(kept))
if m.deps.MarkUploaded != nil {
for _, id := range kept {
m.deps.MarkUploaded(ServiceLoTW, id, res.LogID)
}
}
return len(kept)
}
// upload performs the actual push and returns true on success. It builds a
// fresh, lifecycle-independent context so a delayed upload still completes
// even if it fires close to shutdown.
// upload performs one upload. It returns ok=true when the QSO was uploaded (and
// marked), and retryable=true when it failed in a way worth retrying later (an
// HTTP/service error such as a rate-limit 403) as opposed to a permanent skip
// (not eligible, wrong station callsign, no record).
func (m *Manager) upload(svc Service, id int64, cfg ServiceConfig) (ok bool, retryable bool) {
// Skip QSOs that aren't eligible (already sent, or sent status doesn't
// match the configured Upload flag).
if m.deps.ShouldUpload != nil && !m.deps.ShouldUpload(svc, id) {
m.logf("extsvc: %s upload of QSO %d skipped (not eligible)", svc, id)
return false, false
}
// Station-callsign guard. Each logbook belongs to one callsign:
// QRZ/LoTW → the ForceStationCallsign (the call this logbook signs as)
// Club Log → the logbook Callsign param
// If the QSO's own STATION_CALLSIGN is a DIFFERENT operator, uploading
// would push it into the wrong logbook (and the force-call option would
// silently relabel it). Block it with a clear error. Portable variants of
// the SAME call (F4BPO/P, FW/F4BPO…) are allowed.
owner := ""
switch svc {
case ServiceQRZ, ServiceLoTW:
owner = cfg.ForceStationCallsign
case ServiceClublog, ServiceHRDLog:
owner = cfg.Callsign
case ServiceEQSL:
owner = cfg.Username
}
if owner != "" && m.deps.StationCallOf != nil {
qcall := m.deps.StationCallOf(id)
if qcall != "" && !sameBaseCall(qcall, owner) {
err := fmt.Errorf("station callsign %s does not match %s logbook %s — not uploaded",
strings.ToUpper(qcall), svc, strings.ToUpper(owner))
m.logf("extsvc: %s upload of QSO %d BLOCKED: %v", svc, id, err)
if m.deps.NotifyError != nil {
m.deps.NotifyError(svc, id, err)
}
return false, false
}
}
ctx, cancel := context.WithTimeout(context.Background(), 30*time.Second)
defer cancel()
var res UploadResult
var err error
switch svc {
case ServiceQRZ:
// QRZ rewrites STATION_CALLSIGN to the registered call.
record, ok := m.deps.BuildADIF(id, cfg.ForceStationCallsign)
if !ok {
m.logf("extsvc: %s upload of QSO %d skipped (no record)", svc, id)
return false, false
}
res, err = UploadQRZ(ctx, m.deps.Client, cfg.APIKey, record)
case ServiceClublog:
// Club Log takes the logbook callsign as a separate param, so the
// ADIF keeps the QSO's own station call (no override).
record, ok := m.deps.BuildADIF(id, "")
if !ok {
m.logf("extsvc: %s upload of QSO %d skipped (no record)", svc, id)
return false, false
}
res, err = UploadClublog(ctx, m.deps.Client, cfg, record)
case ServiceLoTW:
// LoTW signs via TQSL; an optional force-call overrides STATION_CALLSIGN
// so the same cert can sign F4BPO, F4BPO/P, TM2Q… per profile.
record, ok := m.deps.BuildADIF(id, cfg.ForceStationCallsign)
if !ok {
m.logf("extsvc: %s upload of QSO %d skipped (no record)", svc, id)
return false, false
}
res, err = UploadLoTW(ctx, cfg, "", record)
case ServiceHRDLog:
// HRDLog takes the station callsign as a separate param, so the ADIF
// keeps the QSO's own station call (no override), like Club Log.
record, ok := m.deps.BuildADIF(id, "")
if !ok {
m.logf("extsvc: %s upload of QSO %d skipped (no record)", svc, id)
return false, false
}
res, err = UploadHRDLog(ctx, m.deps.Client, cfg.Callsign, cfg.Code, record)
case ServiceEQSL:
// eQSL keeps the QSO's own station call; the account is identified by
// the Username + Password, with an optional QTH nickname.
record, ok := m.deps.BuildADIF(id, "")
if !ok {
m.logf("extsvc: %s upload of QSO %d skipped (no record)", svc, id)
return false, false
}
res, err = UploadEQSL(ctx, m.deps.Client, cfg.Username, cfg.Password, cfg.QTHNickname, record)
default:
return false, false
}
if err != nil || !res.OK {
if err == nil {
err = errFromResult(res)
}
m.logf("extsvc: %s upload of QSO %d failed: %v", svc, id, err)
if m.deps.NotifyError != nil {
m.deps.NotifyError(svc, id, err)
}
return false, true // transient (rate-limit / network) → worth a retry
}
m.logf("extsvc: %s upload of QSO %d OK (logid=%q)", svc, id, res.LogID)
if m.deps.MarkUploaded != nil {
m.deps.MarkUploaded(svc, id, res.LogID)
}
return true, false
}