From 2e296dc623530be3d48fe7d72af74ef4a3474824 Mon Sep 17 00:00:00 2001 From: James McGuire Date: Sat, 27 May 2017 00:20:28 -0700 Subject: [PATCH] Add logic for verifying PONGS from server --- client/connection.go | 62 ++++++++++++++++++++++++++++++++++----- client/connection_test.go | 55 ++++++++++++++++++++++++++++++++-- client/handlers.go | 12 ++++++++ 3 files changed, 119 insertions(+), 10 deletions(-) diff --git a/client/connection.go b/client/connection.go index f84621a..07be5f1 100644 --- a/client/connection.go +++ b/client/connection.go @@ -50,6 +50,9 @@ type Conn struct { // Internal counters for flood protection badness time.Duration lastsent time.Time + + // This is for communicating the pongs we get back from our pings. + pongResponses chan string } // Config contains options that can be passed to Client to change the @@ -90,6 +93,10 @@ type Config struct { // Set to 0 to disable client-side pings. PingFreq time.Duration + // Number of failed pings that we will ignore before closing down the connection. + // Set to 0 to disable verifying pong responses. + FailedPings int + // The duration before a connection timeout is triggered. Defaults to 1m. // Set to 0 to wait indefinitely. Timeout time.Duration @@ -118,12 +125,13 @@ type Config struct { // name, but these are optional. func NewConfig(nick string, args ...string) *Config { cfg := &Config{ - Me: &state.Nick{Nick: nick}, - PingFreq: 3 * time.Minute, - NewNick: func(s string) string { return s + "_" }, - Recover: (*Conn).LogPanic, // in dispatch.go - SplitLen: defaultSplit, - Timeout: 60 * time.Second, + Me: &state.Nick{Nick: nick}, + PingFreq: 2 * time.Minute, + FailedPings: 3, + NewNick: func(s string) string { return s + "_" }, + Recover: (*Conn).LogPanic, // in dispatch.go + SplitLen: defaultSplit, + Timeout: 60 * time.Second, } cfg.Me.Ident = "goirc" if len(args) > 0 && args[0] != "" { @@ -266,6 +274,7 @@ func (conn *Conn) initialise() { conn.in = make(chan *Line, 32) conn.out = make(chan string, 32) conn.die = make(chan struct{}) + conn.pongResponses = make(chan string) if conn.st != nil { conn.st.Wipe() } @@ -440,14 +449,51 @@ func (conn *Conn) recv() { // ping is started as a goroutine after a connection is established, as // long as Config.PingFreq >0. It pings the server every PingFreq seconds. func (conn *Conn) ping() { - defer conn.wg.Done() tick := time.NewTicker(conn.cfg.PingFreq) + var sentPings []string + for { select { case <-tick.C: - conn.Ping(fmt.Sprintf("%d", time.Now().UnixNano())) + logging.Debug("irc.ping(): Current outstanding pings: %d/%d", + len(sentPings), conn.cfg.FailedPings) + // If we haven't cleared this by now it's time to bail. + if conn.cfg.FailedPings > 0 && len(sentPings) >= conn.cfg.FailedPings { + logging.Error("irc.ping(): Failed to recieve %d pings, closing down the connection.", + conn.cfg.FailedPings) + tick.Stop() + conn.wg.Done() + conn.Close() + return + } + + currentPing := fmt.Sprintf("%d", time.Now().UnixNano()) + sentPings = append(sentPings, currentPing) + + conn.Ping(currentPing) + case pong := <-conn.pongResponses: + // No need to waste the cycles if we aren't tracking the number of failed pings. + if conn.cfg.FailedPings == 0 { + continue + } + + logging.Debug("irc.ping(): Processing Pong: %s", pong) + + // See if ping matches + shouldClear := false + for _, sentPing := range sentPings { + if strings.Contains(pong, sentPing) { + shouldClear = true + break + } + } + // We found a matching ping, reset the count! + if shouldClear { + sentPings = sentPings[:0] + } case <-conn.die: // control channel closed, bail out + conn.wg.Done() tick.Stop() return } diff --git a/client/connection_test.go b/client/connection_test.go index acf4713..179336c 100644 --- a/client/connection_test.go +++ b/client/connection_test.go @@ -390,7 +390,7 @@ func TestPing(t *testing.T) { } // Set a low ping frequency for testing. - c.cfg.PingFreq = 10 * res + c.cfg.PingFreq = 30 * res // reader is a helper to do a "non-blocking" read of c.out reader := func() string { @@ -433,7 +433,7 @@ func TestPing(t *testing.T) { // This is a short window in which the ping should happen // This may result in flaky tests; sorry (and file a bug) if so. - <-time.After(2 * res) + <-time.After(40 * res) if s := reader(); s == "" || !strings.HasPrefix(s, "PING :") { t.Errorf("Line not output after another %s.", 2*res) } @@ -453,6 +453,57 @@ func TestPing(t *testing.T) { } } +func TestPingPassFail(t *testing.T) { + // Passing a second value to setUp stops goroutines from starting + c, s := setUp(t, false) + defer s.tearDown() + + res := time.Millisecond + + // Windows has a timer resolution of 15.625ms by default. + // This means the test will be slower on windows, but + // should at least stop most of the flakiness... + // https://github.com/fluffle/goirc/issues/88 + if runtime.GOOS == "windows" { + res = 15625 * time.Microsecond + } + + // Set a low ping frequency for testing. + c.cfg.PingFreq = 10 * res + + // reader is a helper to do a "non-blocking" read of c.out + reader := func() string { + select { + case <-time.After(res): + case s := <-c.out: + return s + } + return "" + } + + // Start ping loop. + exited := callCheck(t) + // ping() will decrement the WaitGroup, so we must increment it. + c.wg.Add(1) + go func() { + c.ping() + exited.call() + }() + + for i := 0; i <= 10; i++ { + <-time.After(c.cfg.PingFreq + 1) + s := reader() + if strings.HasPrefix(s, "PING :") { + c.pongResponses <- strings.TrimPrefix(s, "PING :") + } + } + exited.assertNotCalled("Exited before pongs stopped.") + + <-time.After(c.cfg.PingFreq * 4) + + exited.assertWasCalled("Didn't exit after pongs stopped.") +} + func TestRunLoop(t *testing.T) { // Passing a second value to setUp stops goroutines from starting c, s := setUp(t, false) diff --git a/client/handlers.go b/client/handlers.go index b538579..caeb1ea 100644 --- a/client/handlers.go +++ b/client/handlers.go @@ -16,6 +16,7 @@ var intHandlers = map[string]HandlerFunc{ CTCP: (*Conn).h_CTCP, NICK: (*Conn).h_NICK, PING: (*Conn).h_PING, + PONG: (*Conn).h_PONG, } func (conn *Conn) addIntHandlers() { @@ -31,6 +32,17 @@ func (conn *Conn) h_PING(line *Line) { conn.Pong(line.Args[0]) } +// Send all pongs to the internal tracker +func (conn *Conn) h_PONG(line *Line) { + // Going by the RFC this makes zero sense, but every IRCd I can find implements + // it this way. + // + // PING :12345 + // :dreamhack.se.quakenet.org PONG dreamhack.se.quakenet.org :12345 + + conn.pongResponses <- line.Text() +} + // Handler for initial registration with server once tcp connection is made. func (conn *Conn) h_REGISTER(line *Line) { if conn.cfg.Pass != "" {