Skip to content

fix retry mechanism #362

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

Merged
merged 1 commit into from
Aug 14, 2022
Merged

fix retry mechanism #362

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
43 changes: 15 additions & 28 deletions client/client_connect.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -5,7 +5,6 @@ import (
"errors"
"fmt"
"io"
"net"
"strings"
"time"

Expand All @@ -22,7 +21,7 @@ func (c *Client) connectionLoop(ctx context.Context) error {
//connection loop!
b := &backoff.Backoff{Max: c.config.MaxRetryInterval}
for {
connected, retry, err := c.connectionOnce(ctx)
connected, err := c.connectionOnce(ctx)
//reset backoff after successful connections
if connected {
b.Reset()
Expand All @@ -38,16 +37,16 @@ func (c *Client) connectionLoop(ctx context.Context) error {
if err != nil && err != io.EOF {
msg := fmt.Sprintf("Connection error: %s", err)
if attempt > 0 {
msg += fmt.Sprintf(" (Attempt: %d", attempt)
if maxAttempt > 0 {
msg += fmt.Sprintf("/%d", maxAttempt)
maxAttemptVal := fmt.Sprint(maxAttempt)
if maxAttempt < 0 {
maxAttemptVal = "unlimited";
}
msg += ")"
msg += fmt.Sprintf(" (Attempt: %d/%s)", attempt, maxAttemptVal)
}
c.Infof(msg)
}
//give up?
if !retry || (maxAttempt >= 0 && attempt >= maxAttempt) {
if maxAttempt >= 0 && attempt >= maxAttempt {
c.Infof("Give up")
break
}
Expand All @@ -66,11 +65,11 @@ func (c *Client) connectionLoop(ctx context.Context) error {
}

//connectionOnce connects to the chisel server and blocks
func (c *Client) connectionOnce(ctx context.Context) (connected, retry bool, err error) {
func (c *Client) connectionOnce(ctx context.Context) (connected bool, err error) {
//already closed?
select {
case <-ctx.Done():
return false, false, errors.New("Cancelled")
return false, errors.New("Cancelled")
default:
//still open
}
Expand All @@ -87,12 +86,12 @@ func (c *Client) connectionOnce(ctx context.Context) (connected, retry bool, err
//optional proxy
if p := c.proxyURL; p != nil {
if err := c.setProxy(p, &d); err != nil {
return false, false, err
return false, err
}
}
wsConn, _, err := d.DialContext(ctx, c.server, c.config.Headers)
if err != nil {
return false, true, err
return false, err
}
conn := cnet.NewWebSocketConn(wsConn)
// perform SSH handshake on net.Conn
Expand All @@ -103,18 +102,10 @@ func (c *Client) connectionOnce(ctx context.Context) (connected, retry bool, err
if strings.Contains(e, "unable to authenticate") {
c.Infof("Authentication failed")
c.Debugf(e)
retry = false
} else if strings.Contains(e, "connection abort") {
c.Infof("retriable: %s", e)
retry = true
} else if n, ok := err.(net.Error); ok && !n.Temporary() {
c.Infof(e)
retry = false
} else {
c.Infof("retriable: %s", e)
retry = true
c.Infof(e)
}
return false, retry, err
return false, err
}
defer sshConn.Close()
// chisel client handshake (reverse of server handshake)
Expand All @@ -128,19 +119,15 @@ func (c *Client) connectionOnce(ctx context.Context) (connected, retry bool, err
)
if err != nil {
c.Infof("Config verification failed")
return false, false, err
return false, err
}
if len(configerr) > 0 {
return false, false, errors.New(string(configerr))
return false, errors.New(string(configerr))
}
c.Infof("Connected (Latency %s)", time.Since(t0))
//connected, handover ssh connection for tunnel to use, and block
retry = true
err = c.tunnel.BindSSH(ctx, sshConn, reqs, chans)
if n, ok := err.(net.Error); ok && !n.Temporary() {
retry = false
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Removing the retry flag all together seems pretty hacky, better to get to the bottom of the issue. Maybe n.Temporary isn’t accurate…

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

we saw this issue when the remote host was unavailable for some reason (easy to reproduce - just block with iptables).
when it became available again - chisel did not reconnect...

Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yep, I think I’ve seen it before too, just hoping to keep the retry flags - and instead of find the false-negative case

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@jpillora Any chance you can merge this please?
Thanks

Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Removing the retry flag all together seems pretty hacky

Can we keep the retry variable, I think the fix is just to remove this block:

	if n, ok := err.(net.Error); ok && !n.Temporary() {
 		retry = false
	}

Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

for for info, see golang/go#45729

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@jpillora I removed only the condition you mentioned, and tried the following simple scenario:

  1. run chisel client -> connected to host
  2. blocked the host in iptables (with DROP rule)
  3. chisel client disconnected after a few minutes:
2022/08/14 04:43:02 client: Connection error: read tcp ...: read: connection timed out
2022/08/14 04:43:02 client: Give up
2022/08/14 04:43:02 client: tun: Unbound proxies
  1. remove the DROP rules from iptables - i.e. the host is accessible again
  2. chisel client did not re-try, and remained disconnected (I think this is the "Give up" message).

So it looks the retry flag doesn't really work...I think it should be removed

Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

With respect, retry definitely works under certain circumstances:

Server:
$ docker run --name chisel -p 8080:8080 --rm -it jpillora/chisel server socks
2022/08/14 14:52:32 server: Fingerprint WtF6u45xORDyMD+kLAZc42H33hijiPhjou4IOp8Ssvo=
2022/08/14 14:52:32 server: Listening on http://0.0.0.0:8080
2022/08/14 14:52:45 server: session#6: Client version (1.7.7) differs from server version (v1.7.7)
-ctrl-c
$ docker run --name chisel -p 8080:8080 --rm -it jpillora/chisel server socks
2022/08/14 14:52:53 server: Fingerprint IZvG3hhx/9GqHSrfq1eI6WDgeAD1cZiJzSvP4wdWeFE=
2022/08/14 14:52:53 server: Listening on http://0.0.0.0:8080
2022/08/14 14:52:53 server: session#1: Client version (1.7.7) differs from server version (v1.7.7)

Client:
$ chisel client http://127.0.0.1:8080 socks
2022/08/14 15:52:45 client: Connecting to ws://127.0.0.1:8080
2022/08/14 15:52:45 client: tun: proxy#127.0.0.1:1080=>socks: Listening
2022/08/14 15:52:45 client: Connected (Latency 1.3523ms)
2022/08/14 15:52:50 client: Disconnected
2022/08/14 15:52:50 client: Connection error: websocket: close 1006 (abnormal closure): unexpected EOF
2022/08/14 15:52:50 client: Retrying in 100ms...
2022/08/14 15:52:50 client: Connection error: dial tcp 127.0.0.1:8080: connect: connection refused (Attempt: 1)
2022/08/14 15:52:50 client: Retrying in 200ms...
2022/08/14 15:52:50 client: Connection error: dial tcp 127.0.0.1:8080: connect: connection refused (Attempt: 2)
2022/08/14 15:52:50 client: Retrying in 400ms...
2022/08/14 15:52:50 client: Connection error: dial tcp 127.0.0.1:8080: connect: connection refused (Attempt: 3)
2022/08/14 15:52:50 client: Retrying in 800ms...
2022/08/14 15:52:51 client: Connection error: dial tcp 127.0.0.1:8080: connect: connection refused (Attempt: 4)
2022/08/14 15:52:51 client: Retrying in 1.6s...
2022/08/14 15:52:53 client: Connected (Latency 1.2117ms)

As you can see, the client disconnects when the server isn't there, retries till it's back and then reconnects.
Perhaps it responds to the iptables DROP rule by assuming it'll never be able to access the server and so gives up...?

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I didn't say it never works...But if it only works in certain scenarios - it's a bug.
The DROP rule was just an example, we saw the same issue in other cases as well where the host was temporarily unavailable.

Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Okay thanks for looking into it

merged

}
c.Infof("Disconnected")
connected = time.Since(t0) > 5*time.Second
return connected, retry, err
return connected, err
}