chore(nat, upnp): Make failure logging less reptitive (ref #9324) (#9785)

Currently we log on every single one of 10 retries deep in the upnp
stack. However we also return the failure as an error, which is bubbled
up a while until it's logged at debug level. Switch that around, such
that the repeat logging happens at debug level but the top-level happens
at info. There's some chance that this will newly log errors from
nat-pmp that were previously hidden in debug level - I hope those are
useful and not too numerous.

Also potentially this can even close #9324, my (very limited)
understanding of the reports/discussion there is that there's likely no
problem with syncthing beyond the excessive logging, it's some weird
router behaviour.
This commit is contained in:
Simon Frei 2024-10-25 23:04:22 +02:00 committed by GitHub
parent 9ffddb1923
commit ff7e4fef55
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
2 changed files with 6 additions and 5 deletions

View File

@ -259,7 +259,7 @@ func (s *Service) verifyExistingLocked(ctx context.Context, mapping *Mapping, na
// entry always has the external port.
responseAddrs, err := s.tryNATDevice(ctx, nat, mapping.address, extAddrs[0].Port, leaseTime)
if err != nil {
l.Debugf("Failed to renew %s -> %v open port on %s", mapping, extAddrs, id)
l.Infof("Failed to renew %s -> %v open port on %s: %s", mapping, extAddrs, id, err)
mapping.removeAddressLocked(id)
change = true
continue
@ -311,7 +311,7 @@ func (s *Service) acquireNewLocked(ctx context.Context, mapping *Mapping, nats m
addrs, err := s.tryNATDevice(ctx, nat, mapping.address, 0, leaseTime)
if err != nil {
l.Debugf("Failed to acquire %s open port on %s", mapping, id)
l.Infof("Failed to acquire %s open port on %s: %s", mapping, id, err)
continue
}
@ -359,7 +359,7 @@ func (s *Service) tryNATDevice(ctx context.Context, natd Device, intAddr Address
extPort = port
goto findIP
}
l.Debugln("Error extending lease on", natd.ID(), err)
l.Debugf("Error extending lease on %v (external port %d -> internal port %d): %v", natd.ID(), extPort, intAddr.Port, err)
}
for i := 0; i < 10; i++ {
@ -377,7 +377,8 @@ func (s *Service) tryNATDevice(ctx context.Context, natd Device, intAddr Address
extPort = port
goto findIP
}
l.Debugf("Error getting new lease on %s: %s", natd.ID(), err)
err = fmt.Errorf("getting new lease on %s (external port %d -> internal port %d): %w", natd.ID(), extPort, intAddr.Port, err)
l.Debugf("Error %s", err)
}
return nil, err

View File

@ -206,7 +206,7 @@ func (s *IGDService) AddPortMapping(ctx context.Context, protocol nat.Protocol,
}
err = fmt.Errorf("UPnP Error: %s (%d)", envelope.ErrorDescription, envelope.ErrorCode)
l.Infof("Couldn't add port mapping for %s (external port %d -> internal port %d/%s): %s", s.LocalIPv4, externalPort, internalPort, protocol, err)
l.Debugf("Couldn't add port mapping for %s (external port %d -> internal port %d/%s): %s", s.LocalIPv4, externalPort, internalPort, protocol, err)
}
return externalPort, err