Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Adding more logs to decipher what's happening #44

Merged
merged 1 commit into from
Oct 18, 2024
Merged

Adding more logs to decipher what's happening #44

Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
22 changes: 12 additions & 10 deletions direct.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -119,7 +119,7 @@ func (d *direct) vet(numberToVet int) {
func (d *direct) vetOne() {
// We're just testing the ability to connect here, destination site doesn't
// really matter
log.Trace("Vetting one")
log.Debug("Vetting one")
unvettedMasquerades := make([]*masquerade, 0, len(d.masquerades))
for _, m := range d.masquerades {
if m.lastSucceeded().IsZero() {
Expand All @@ -140,16 +140,16 @@ func (d *direct) vetOne() {

provider := d.providerFor(m)
if provider == nil {
log.Tracef("Skipping masquerade with disabled/unknown provider id '%s'", m.ProviderID)
log.Debugf("Skipping masquerade with disabled/unknown provider id '%s'", m.ProviderID)
return
}

if !masqueradeGood(postCheck(conn, provider.TestURL)) {
log.Tracef("Unsuccessful vetting with POST request, discarding masquerade")
log.Debugf("Unsuccessful vetting with POST request, discarding masquerade")
return
}

log.Trace("Finished vetting one")
log.Debug("Finished vetting one")
}

// postCheck does a post with invalid data to verify domain-fronting works
Expand Down Expand Up @@ -269,7 +269,7 @@ func (d *direct) RoundTripHijack(req *http.Request) (*http.Response, net.Conn, e
op.FailIf(err)
return nil, nil, err
}
log.Tracef("Translated origin %s -> %s for provider %s...", originHost, frontedHost, m.ProviderID)
log.Debugf("Translated origin %s -> %s for provider %s...", originHost, frontedHost, m.ProviderID)

reqi, err := cloneRequestWith(req, frontedHost, getBody())
if err != nil {
Expand Down Expand Up @@ -340,11 +340,13 @@ func (d *direct) dialWith(ctx context.Context, masquerades sortedMasquerades) (n
defer cancel()

masqueradesToTry := masquerades.sortedCopy()
totalMasquerades := len(masqueradesToTry)
dialLoop:
for _, m := range masqueradesToTry {
// check to see if we've timed out
select {
case <-ctx.Done():
log.Debugf("Timed out dialing to %v with %v total masquerades", m, totalMasquerades)
break dialLoop
default:
// okay
Expand All @@ -366,15 +368,15 @@ dialLoop:
return good
}
if err == nil {
log.Trace("Returning connection")
log.Debug("Returning connection")
return conn, m, masqueradeGood, err
} else if !retriable {
log.Debugf("Dropping masquerade: non retryable error: %v", err)
masqueradeGood(false)
}
}

return nil, nil, nil, errors.New("could not dial any masquerade?")
return nil, nil, nil, log.Errorf("could not dial any masquerade? tried %v", totalMasquerades)
}

func (d *direct) doDial(m *Masquerade) (conn net.Conn, retriable bool, err error) {
Expand All @@ -386,15 +388,15 @@ func (d *direct) doDial(m *Masquerade) (conn net.Conn, retriable bool, err error
conn, err = d.dialServerWith(m)
if err != nil {
op.FailIf(err)
log.Tracef("Could not dial to %v, %v", m.IpAddress, err)
log.Debugf("Could not dial to %v, %v", m.IpAddress, err)
// Don't re-add this candidate if it's any certificate error, as that
// will just keep failing and will waste connections. We can't access the underlying
// error at this point so just look for "certificate" and "handshake".
if strings.Contains(err.Error(), "certificate") || strings.Contains(err.Error(), "handshake") {
log.Debugf("Not re-adding candidate that failed on error '%v'", err.Error())
retriable = false
} else {
log.Tracef("Unexpected error dialing, keeping masquerade: %v", err)
log.Debugf("Unexpected error dialing, keeping masquerade: %v", err)
retriable = true
}
} else {
Expand All @@ -403,7 +405,7 @@ func (d *direct) doDial(m *Masquerade) (conn net.Conn, retriable bool, err error

log.Debugf("Wrapping connection in idletiming connection: %v", m)
conn = idletiming.Conn(conn, idleTimeout, func() {
log.Tracef("Connection to %v idle for %v, closed", conn.RemoteAddr(), idleTimeout)
log.Debugf("Connection to %v idle for %v, closed", conn.RemoteAddr(), idleTimeout)
})
}
return
Expand Down
Loading