diff --git a/README.md b/README.md index d318f9c..151a558 100644 --- a/README.md +++ b/README.md @@ -18,31 +18,31 @@ This will connect to freenode and join `#go-nuts` by default, so be careful ;-) Synopsis: - import irc "github.com/fluffle/goirc/client" - func main() { - c := irc.New("nick", "ident", "real name") - // Optionally, turn on debugging - c.Debug = true - // Optionally, enable SSL - c.SSL = true + import irc "github.com/fluffle/goirc/client" + func main() { + c := irc.New("nick", "ident", "real name") + // Optionally, turn on debugging + c.Debug = true + // Optionally, enable SSL + c.SSL = true // Add handlers to do things here! // e.g. join a channel on connect. c.AddHandler("connected", func(conn *irc.Conn, line *irc.Line) { conn.Join("#channel") }) - + // And a signal on disconnect + quit := make(chan bool) + c.AddHandler("disconnected), + func(conn *irc.Conn, line *irc.Line) { quit <- true } + // Tell client to connect if err := c.Connect("irc.freenode.net"); err != nil { - fmt.Printf("Connection error: %s\n", err.String()) - } + fmt.Printf("Connection error: %s\n", err.String()) + } - // Loop until client gets disconnected, printing any errors - for c.Connected { - if err := <-c.Err; err != nil { - fmt.Printf("goirc error: %s", err.String()) - } - } - } + // Wait for disconnect + <-quit + } The test client provides a good (if basic) example of how to use the framework. Reading `client/handlers.go` gives a more in-depth look at how handlers can be diff --git a/client.go b/client.go index 3a56b4b..a27555a 100644 --- a/client.go +++ b/client.go @@ -11,7 +11,6 @@ import ( func main() { // create new IRC connection c := irc.New("GoTest", "gotest", "GoBot") - c.Debug = true c.AddHandler("connected", func(conn *irc.Conn, line *irc.Line) { conn.Join("#go-nuts") }) @@ -20,12 +19,6 @@ func main() { c.AddHandler("disconnected", func(conn *irc.Conn, line *irc.Line) { quit <- true }) - // connect to server - if err := c.Connect("irc.freenode.net"); err != nil { - fmt.Printf("Connection error: %s\n", err) - return - } - // set up a goroutine to read commands from stdin in := make(chan string, 4) reallyquit := false @@ -80,17 +73,13 @@ func main() { }() for !reallyquit { - select { - case err := <-c.Err: - fmt.Printf("goirc error: %s\n", err) - case <-quit: - if !reallyquit { - fmt.Println("Reconnecting...") - if err := c.Connect("irc.freenode.net"); err != nil { - fmt.Printf("Connection error: %s\n", err) - reallyquit = true - } - } + // connect to server + if err := c.Connect("irc.freenode.net"); err != nil { + fmt.Printf("Connection error: %s\n", err) + return } + + // wait on quit channel + <-quit } } diff --git a/client/connection.go b/client/connection.go index 1f10573..22ad09a 100644 --- a/client/connection.go +++ b/client/connection.go @@ -4,6 +4,7 @@ import ( "bufio" "crypto/tls" "github.com/fluffle/goirc/event" + "github.com/fluffle/goirc/logging" "fmt" "net" "os" @@ -16,7 +17,6 @@ const ( ) // An IRC connection is represented by this struct. -// Once connected, any errors encountered are piped down *Conn.Err. type Conn struct { // Connection Hostname and Nickname Host string @@ -44,9 +44,6 @@ type Conn struct { // Control channels to goroutines cSend, cLoop chan bool - // Error channel to transmit any fail back to the user - Err chan os.Error - // Misc knobs to tweak client behaviour: // Are we connecting via SSL? Do we care about certificate validity? SSL bool @@ -60,13 +57,6 @@ type Conn struct { // Internal counters for flood protection badness, lastsent int64 - - // Function which returns a *time.Time for use as a timestamp - Timestamp func() *time.Time - - // Enable debugging? Set format for timestamps on debug output. - Debug bool - TSFormat string } // Creates a new IRC connection object, but doesn't connect to anything so @@ -78,7 +68,6 @@ func New(nick, user, name string) *Conn { Dispatcher: reg, in: make(chan *Line, 32), out: make(chan string, 32), - Err: make(chan os.Error, 4), cSend: make(chan bool), cLoop: make(chan bool), SSL: false, @@ -87,8 +76,6 @@ func New(nick, user, name string) *Conn { Flood: false, badness: 0, lastsent: 0, - Timestamp: time.LocalTime, - TSFormat: "15:04:05", } conn.initialise() conn.SetupHandlers() @@ -126,6 +113,7 @@ func (conn *Conn) Connect(host string, pass ...string) os.Error { if !hasPort(host) { host += ":6697" } + logging.Info("irc.Connect(): Connecting to %s with SSL.", host) if s, err := tls.Dial("tcp", host, conn.SSLConfig); err == nil { conn.sock = s } else { @@ -135,6 +123,7 @@ func (conn *Conn) Connect(host string, pass ...string) os.Error { if !hasPort(host) { host += ":6667" } + logging.Info("irc.Connect(): Connecting to %s without SSL.", host) if s, err := net.Dial("tcp", host); err == nil { conn.sock = s } else { @@ -164,11 +153,6 @@ func (conn *Conn) postConnect() { go conn.runLoop() } -// dispatch a nicely formatted os.Error to the error channel -func (conn *Conn) error(s string, a ...interface{}) { - conn.Err <- os.NewError(fmt.Sprintf(s, a...)) -} - // copied from http.client for great justice func hasPort(s string) bool { return strings.LastIndex(s, ":") > strings.LastIndex(s, "]") @@ -192,18 +176,15 @@ func (conn *Conn) recv() { for { s, err := conn.io.ReadString('\n') if err != nil { - conn.error("irc.recv(): %s", err.String()) + logging.Error("irc.recv(): %s", err.String()) conn.shutdown() - break + return } s = strings.Trim(s, "\r\n") - t := conn.Timestamp() - if conn.Debug { - fmt.Println(t.Format(conn.TSFormat) + " <- " + s) - } + logging.Debug("<- %s", s) if line := parseLine(s); line != nil { - line.Time = t + line.Time = time.LocalTime() conn.in <- line } } @@ -230,14 +211,12 @@ func (conn *Conn) write(line string) { } if _, err := conn.io.WriteString(line + "\r\n"); err != nil { - conn.error("irc.send(): %s", err.String()) + logging.Error("irc.send(): %s", err.String()) conn.shutdown() return } conn.io.Flush() - if conn.Debug { - fmt.Println(conn.Timestamp().Format(conn.TSFormat) + " -> " + line) - } + logging.Debug("-> %s", line) } // Implement Hybrid's flood control algorithm to rate-limit outgoing lines. @@ -255,6 +234,8 @@ func (conn *Conn) rateLimit(chars int64) { // calculation above, then we're at risk of "Excess Flood". if conn.badness > 10*second && !conn.Flood { // so sleep for the current line's time value before sending it + logging.Debug("irc.rateLimit(): Flood! Sleeping for %.2f secs.", + float64(linetime)/float64(second)) time.Sleep(linetime) } } @@ -263,6 +244,7 @@ func (conn *Conn) shutdown() { // Guard against double-call of shutdown() if we get an error in send() // as calling sock.Close() will cause recv() to recieve EOF in readstring() if conn.Connected { + logging.Info("irc.shutdown(): Disconnected from server.") conn.Dispatcher.Dispatch("disconnected", conn, &Line{}) conn.Connected = false conn.sock.Close() diff --git a/client/connection_test.go b/client/connection_test.go index 3315445..c4b5b9e 100644 --- a/client/connection_test.go +++ b/client/connection_test.go @@ -1,11 +1,18 @@ package client import ( + "github.com/fluffle/goirc/logging" "strings" "testing" "time" ) +func init() { + // We have Error level logging that is printed on socket shutdown + // which we don't care too much about when testing with a mock conn... + logging.SetLogLevel(logging.LogFatal) +} + func setUp(t *testing.T) (*mockNetConn, *Conn) { c := New("test", "test", "Testing IRC") c.State = t @@ -39,33 +46,7 @@ func setUp(t *testing.T) (*mockNetConn, *Conn) { } func tearDown(m *mockNetConn, c *Conn) { - // This is enough to cause all the associated goroutines in m and c stop - // (tested below in TestShutdown to make sure this is the case) - m.Close() -} - -func (conn *Conn) ExpectError() { - // With the current error handling, we could block on reading the Err - // channel, so ensure we don't wait forever with a 5ms timeout. - t := conn.State.(*testing.T) - timer := time.NewTimer(5e6) - select { - case <-timer.C: - t.Errorf("Error expected on Err channel, none received.") - case <-conn.Err: - timer.Stop() - } -} - -func (conn *Conn) ExpectNoErrors() { - t := conn.State.(*testing.T) - timer := time.NewTimer(5e6) - select { - case <-timer.C: - case err := <-conn.Err: - timer.Stop() - t.Errorf("No error expected on Err channel, received:\n\t%s", err) - } + c.shutdown() } func TestShutdown(t *testing.T) { @@ -78,18 +59,6 @@ func TestShutdown(t *testing.T) { // Call shutdown manually c.shutdown() - // Check that we get an EOF from Read() - timer := time.NewTimer(5e6) - select { - case <-timer.C: - t.Errorf("No error received for shutdown.") - case err := <-c.Err: - timer.Stop() - if err.String() != "irc.recv(): EOF" { - t.Errorf("Expected EOF, got: %s", err) - } - } - // Verify that the connection no longer thinks it's connected if c.Connected { t.Errorf("Conn still thinks it's connected to the server.") @@ -116,17 +85,9 @@ func TestEOF(t *testing.T) { // Simulate EOF from server m.Close() - // Check that we get an EOF from Read() - timer := time.NewTimer(5e6) - select { - case <-timer.C: - t.Errorf("No error received for shutdown.") - case err := <-c.Err: - timer.Stop() - if err.String() != "irc.recv(): EOF" { - t.Errorf("Expected EOF, got: %s", err) - } - } + // Since things happen in different internal goroutines, we need to wait + // 1 ms should be enough :-) + time.Sleep(1e6) // Verify that the connection no longer thinks it's connected if c.Connected { diff --git a/client/handlers.go b/client/handlers.go index eb74e27..0923f4d 100644 --- a/client/handlers.go +++ b/client/handlers.go @@ -5,6 +5,7 @@ package client import ( "github.com/fluffle/goirc/event" + "github.com/fluffle/goirc/logging" "strings" ) @@ -75,7 +76,7 @@ func (conn *Conn) h_NICK(line *Line) { if n := conn.GetNick(line.Nick); n != nil { n.ReNick(line.Args[0]) } else { - conn.error("irc.NICK(): buh? unknown nick %s.", line.Nick) + logging.Warn("irc.NICK(): unknown nick %s.", line.Nick) } } @@ -96,9 +97,8 @@ func (conn *Conn) h_JOIN(line *Line) { // first we've seen of this channel, so should be us joining it // NOTE this will also take care of n == nil && ch == nil if n != conn.Me { - conn.error("irc.JOIN(): buh? JOIN to unknown channel %s recieved"+ - "from (non-me) nick %s", - line.Args[0], line.Nick) + logging.Warn("irc.JOIN(): JOIN to unknown channel %s recieved "+ + "from (non-me) nick %s", line.Args[0], line.Nick) return } ch = conn.NewChannel(line.Args[0]) @@ -128,11 +128,11 @@ func (conn *Conn) h_PART(line *Line) { if _, ok := ch.Nicks[n]; ok { ch.DelNick(n) } else { - conn.error("irc.PART(): nick %s is not on channel %s", + logging.Warn("irc.PART(): nick %s is not on channel %s", line.Nick, line.Args[0]) } } else { - conn.error("irc.PART(): buh? PART of channel %s by nick %s", + logging.Warn("irc.PART(): PART of channel %s by nick %s", line.Args[0], line.Nick) } } @@ -147,11 +147,11 @@ func (conn *Conn) h_KICK(line *Line) { if _, ok := ch.Nicks[n]; ok { ch.DelNick(n) } else { - conn.error("irc.KICK(): nick %s is not on channel %s", + logging.Warn("irc.KICK(): nick %s is not on channel %s", line.Nick, line.Args[0]) } } else { - conn.error("irc.KICK(): buh? KICK from channel %s of nick %s", + logging.Warn("irc.KICK(): KICK from channel %s of nick %s", line.Args[0], line.Args[1]) } } @@ -161,7 +161,7 @@ func (conn *Conn) h_QUIT(line *Line) { if n := conn.GetNick(line.Nick); n != nil { n.Delete() } else { - conn.error("irc.QUIT(): buh? QUIT from unknown nick %s", line.Nick) + logging.Warn("irc.QUIT(): QUIT from unknown nick %s", line.Nick) } } @@ -173,12 +173,14 @@ func (conn *Conn) h_MODE(line *Line) { } else if n := conn.GetNick(line.Args[0]); n != nil { // nick mode change, should be us if n != conn.Me { - conn.error("irc.MODE(): buh? recieved MODE %s for (non-me) nick %s", line.Args[0], n.Nick) + logging.Warn("irc.MODE(): recieved MODE %s for (non-me) nick %s", + line.Args[0], n.Nick) return } conn.ParseNickModes(n, line.Args[1]) } else { - conn.error("irc.MODE(): buh? not sure what to do with MODE %s", strings.Join(line.Args, " ")) + logging.Warn("irc.MODE(): not sure what to do with MODE %s", + strings.Join(line.Args, " ")) } } @@ -187,7 +189,8 @@ func (conn *Conn) h_TOPIC(line *Line) { if ch := conn.GetChannel(line.Args[0]); ch != nil { ch.Topic = line.Args[1] } else { - conn.error("irc.TOPIC(): buh? topic change on unknown channel %s", line.Args[0]) + logging.Warn("irc.TOPIC(): topic change on unknown channel %s", + line.Args[0]) } } @@ -198,7 +201,8 @@ func (conn *Conn) h_311(line *Line) { n.Host = line.Args[3] n.Name = line.Args[5] } else { - conn.error("irc.311(): buh? received WHOIS info for unknown nick %s", line.Args[1]) + logging.Warn("irc.311(): received WHOIS info for unknown nick %s", + line.Args[1]) } } @@ -207,7 +211,8 @@ func (conn *Conn) h_324(line *Line) { if ch := conn.GetChannel(line.Args[1]); ch != nil { conn.ParseChannelModes(ch, line.Args[2], line.Args[3:]) } else { - conn.error("irc.324(): buh? received MODE settings for unknown channel %s", line.Args[1]) + logging.Warn("irc.324(): received MODE settings for unknown channel %s", + line.Args[1]) } } @@ -216,7 +221,8 @@ func (conn *Conn) h_332(line *Line) { if ch := conn.GetChannel(line.Args[1]); ch != nil { ch.Topic = line.Args[2] } else { - conn.error("irc.332(): buh? received TOPIC value for unknown channel %s", line.Args[1]) + logging.Warn("irc.332(): received TOPIC value for unknown channel %s", + line.Args[1]) } } @@ -237,7 +243,8 @@ func (conn *Conn) h_352(line *Line) { n.Modes.Invisible = true } } else { - conn.error("irc.352(): buh? got WHO reply for unknown nick %s", line.Args[5]) + logging.Warn("irc.352(): received WHO reply for unknown nick %s", + line.Args[5]) } } @@ -280,7 +287,8 @@ func (conn *Conn) h_353(line *Line) { } } } else { - conn.error("irc.353(): buh? received NAMES list for unknown channel %s", line.Args[2]) + logging.Warn("irc.353(): received NAMES list for unknown channel %s", + line.Args[2]) } } @@ -289,7 +297,8 @@ func (conn *Conn) h_671(line *Line) { if n := conn.GetNick(line.Args[1]); n != nil { n.Modes.SSL = true } else { - conn.error("irc.671(): buh? received WHOIS SSL info for unknown nick %s", line.Args[1]) + logging.Warn("irc.671(): received WHOIS SSL info for unknown nick %s", + line.Args[1]) } } diff --git a/client/handlers_test.go b/client/handlers_test.go index 9386630..7e806ae 100644 --- a/client/handlers_test.go +++ b/client/handlers_test.go @@ -73,8 +73,7 @@ func TestNICK(t *testing.T) { // Call handler with a NICK line changing "our" nick to test1. c.h_NICK(parseLine(":test!test@somehost.com NICK :test1")) - // Should generate no errors and no response to server - c.ExpectNoErrors() + // Should generate no response to server m.ExpectNothing() // Verify that our Nick has changed @@ -87,7 +86,6 @@ func TestNICK(t *testing.T) { // Call handler with a NICK line changing user1 to somebody c.h_NICK(parseLine(":user1!ident1@host1.com NICK :somebody")) - c.ExpectNoErrors() m.ExpectNothing() if c.GetNick("user1") != nil { @@ -99,7 +97,6 @@ func TestNICK(t *testing.T) { // Send a NICK line for an unknown nick. c.h_NICK(parseLine(":blah!moo@cows.com NICK :milk")) - c.ExpectError() m.ExpectNothing() } @@ -135,9 +132,7 @@ func TestJOIN(t *testing.T) { // significant effort to move Conn to being a mockable interface type // instead of a concrete struct. I'm not sure how feasible this is :-/ // - // Instead, in this test we (so far) just verify the correct code paths - // are followed and trust that the unit tests for the various methods - // ensure that they do the right thing. + // Soon, we'll find out :-) m, c := setUp(t) defer tearDown(m, c) @@ -146,9 +141,6 @@ func TestJOIN(t *testing.T) { // Call handler with JOIN by test to #test1 c.h_JOIN(parseLine(":test!test@somehost.com JOIN :#test1")) - // Ensure we aren't triggering an error here - c.ExpectNoErrors() - // Verify that the MODE and WHO commands are sent correctly m.Expect("MODE #test1") m.Expect("WHO #test1") @@ -162,9 +154,6 @@ func TestJOIN(t *testing.T) { // OK, now #test1 exists, JOIN another user we don't know about c.h_JOIN(parseLine(":user1!ident1@host1.com JOIN :#test1")) - // Again, expect no errors - c.ExpectNoErrors() - // Verify that the WHO command is sent correctly m.Expect("WHO user1") @@ -179,7 +168,6 @@ func TestJOIN(t *testing.T) { c.h_JOIN(parseLine(":user2!ident2@host2.com JOIN :#test1")) // We already know about this user and channel, so nothing should be sent - c.ExpectNoErrors() m.ExpectNothing() // Simple verification that the state tracking has actually been done @@ -189,12 +177,10 @@ func TestJOIN(t *testing.T) { // Test error paths -- unknown channel, unknown nick c.h_JOIN(parseLine(":blah!moo@cows.com JOIN :#test2")) - c.ExpectError() m.ExpectNothing() // unknown channel, known nick that isn't Me. c.h_JOIN(parseLine(":user2!ident2@host2.com JOIN :#test2")) - c.ExpectError() m.ExpectNothing() } @@ -217,8 +203,7 @@ func TestPART(t *testing.T) { // Then make them PART c.h_PART(parseLine(":user1!ident1@host1.com PART #test1 :Bye!")) - // Expect no errors or output - c.ExpectNoErrors() + // Expect no output m.ExpectNothing() // Quick check of tracking code @@ -229,19 +214,15 @@ func TestPART(t *testing.T) { // Test error states. // Part a known user from a known channel they are not on. c.h_PART(parseLine(":user1!ident1@host1.com PART #test1 :Bye!")) - c.ExpectError() // Part an unknown user from a known channel. c.h_PART(parseLine(":user2!ident2@host2.com PART #test1 :Bye!")) - c.ExpectError() // Part a known user from an unknown channel. c.h_PART(parseLine(":user1!ident1@host1.com PART #test3 :Bye!")) - c.ExpectError() // Part an unknown user from an unknown channel. c.h_PART(parseLine(":user2!ident2@host2.com PART #test3 :Bye!")) - c.ExpectError() } // Test the handler for KICK messages @@ -264,8 +245,7 @@ func TestKICK(t *testing.T) { // Then kick them! c.h_KICK(parseLine(":test!test@somehost.com KICK #test1 user1 :Bye!")) - // Expect no errors or output - c.ExpectNoErrors() + // Expect no output m.ExpectNothing() // Quick check of tracking code @@ -276,19 +256,15 @@ func TestKICK(t *testing.T) { // Test error states. // Kick a known user from a known channel they are not on. c.h_KICK(parseLine(":test!test@somehost.com KICK #test1 user1 :Bye!")) - c.ExpectError() // Kick an unknown user from a known channel. c.h_KICK(parseLine(":test!test@somehost.com KICK #test2 user2 :Bye!")) - c.ExpectError() // Kick a known user from an unknown channel. c.h_KICK(parseLine(":test!test@somehost.com KICK #test3 user1 :Bye!")) - c.ExpectError() // Kick an unknown user from an unknown channel. c.h_KICK(parseLine(":test!test@somehost.com KICK #test4 user2 :Bye!")) - c.ExpectError() } // Test the handler for QUIT messages @@ -310,8 +286,7 @@ func TestQUIT(t *testing.T) { // Have user1 QUIT c.h_QUIT(parseLine(":user1!ident1@host1.com QUIT :Bye!")) - // Expect no errors or output - c.ExpectNoErrors() + // Expect no output m.ExpectNothing() // Quick check of tracking code @@ -326,11 +301,9 @@ func TestQUIT(t *testing.T) { // Have user1 QUIT again, expect ERRORS! c.h_QUIT(parseLine(":user1!ident1@host1.com QUIT :Bye!")) - c.ExpectError() // Have a previously unmentioned user quit, expect an error c.h_QUIT(parseLine(":user2!ident2@host2.com QUIT :Bye!")) - c.ExpectError() } // Test the handler for MODE messages @@ -354,9 +327,8 @@ func TestMODE(t *testing.T) { // Send a channel mode line c.h_MODE(parseLine(":user1!ident1@host1.com MODE #test1 +kisvo somekey test user1")) - // Shouldn't get any errors or output + // Expect no output m.ExpectNothing() - c.ExpectNoErrors() // Verify expected state afterwards. if cp := user1.Channels[test1]; !(cp.Op || c.Me.Channels[test1].Voice || @@ -373,7 +345,6 @@ func TestMODE(t *testing.T) { // Send a nick mode line c.h_MODE(parseLine(":test!test@somehost.com MODE test +ix")) m.ExpectNothing() - c.ExpectNoErrors() // Verify the two modes we expect to change did so if !nm.Invisible || nm.WallOps || !nm.HiddenHost { @@ -383,12 +354,10 @@ func TestMODE(t *testing.T) { // Check error paths -- send a valid user mode that's not us c.h_MODE(parseLine(":user1!ident1@host1.com MODE user1 +w")) m.ExpectNothing() - c.ExpectError() // Send a random mode for an unknown channel c.h_MODE(parseLine(":user1!ident1@host1.com MODE #test2 +is")) m.ExpectNothing() - c.ExpectError() } // Test the handler for TOPIC messages @@ -407,7 +376,6 @@ func TestTOPIC(t *testing.T) { // Send a TOPIC line c.h_TOPIC(parseLine(":user1!ident1@host1.com TOPIC #test1 :something something")) m.ExpectNothing() - c.ExpectNoErrors() // Make sure the channel's topic has been changed if test1.Topic != "something something" { @@ -417,7 +385,6 @@ func TestTOPIC(t *testing.T) { // Check error paths -- send a topic for an unknown channel c.h_TOPIC(parseLine(":user1!ident1@host1.com TOPIC #test2 :dark side")) m.ExpectNothing() - c.ExpectError() } // Test the handler for 311 / RPL_WHOISUSER @@ -431,7 +398,6 @@ func Test311(t *testing.T) { // Send a 311 reply c.h_311(parseLine(":irc.server.org 311 test user1 ident1 host1.com * :name")) m.ExpectNothing() - c.ExpectNoErrors() // Verify we now know more about user1 if user1.Ident != "ident1" || @@ -443,7 +409,6 @@ func Test311(t *testing.T) { // Check error paths -- send a 311 for an unknown nick c.h_311(parseLine(":irc.server.org 311 test user2 ident2 host2.com * :dongs")) m.ExpectNothing() - c.ExpectError() } // Test the handler for 324 / RPL_CHANNELMODEIS @@ -463,7 +428,6 @@ func Test324(t *testing.T) { // Send a 324 reply c.h_324(parseLine(":irc.server.org 324 test #test1 +snk somekey")) m.ExpectNothing() - c.ExpectNoErrors() // Make sure the modes we expected to be set were set and vice versa if !cm.Secret || !cm.NoExternalMsg || cm.Moderated || cm.Key != "somekey" { @@ -473,7 +437,6 @@ func Test324(t *testing.T) { // Check unknown channel causes an error c.h_324(parseLine(":irc.server.org 324 test #test2 +pmt")) m.ExpectNothing() - c.ExpectError() } // Test the handler for 332 / RPL_TOPIC @@ -492,7 +455,6 @@ func Test332(t *testing.T) { // Send a 332 reply c.h_332(parseLine(":irc.server.org 332 test #test1 :something something")) m.ExpectNothing() - c.ExpectNoErrors() // Make sure the channel's topic has been changed if test1.Topic != "something something" { @@ -502,7 +464,6 @@ func Test332(t *testing.T) { // Check unknown channel causes an error c.h_324(parseLine(":irc.server.org 332 test #test2 :dark side")) m.ExpectNothing() - c.ExpectError() } // Test the handler for 352 / RPL_WHOREPLY @@ -516,7 +477,6 @@ func Test352(t *testing.T) { // Send a 352 reply c.h_352(parseLine(":irc.server.org 352 test #test1 ident1 host1.com irc.server.org user1 G :0 name")) m.ExpectNothing() - c.ExpectNoErrors() // Verify we now know more about user1 if user1.Ident != "ident1" || @@ -530,7 +490,6 @@ func Test352(t *testing.T) { // Check that modes are set correctly from WHOREPLY c.h_352(parseLine(":irc.server.org 352 test #test1 ident1 host1.com irc.server.org user1 H* :0 name")) m.ExpectNothing() - c.ExpectNoErrors() if !user1.Modes.Invisible || !user1.Modes.Oper { t.Errorf("WHO modes of user1 not set correctly.") @@ -539,7 +498,6 @@ func Test352(t *testing.T) { // Check error paths -- send a 352 for an unknown nick c.h_352(parseLine(":irc.server.org 352 test #test2 ident2 host2.com irc.server.org user2 G :0 fooo")) m.ExpectNothing() - c.ExpectError() } // Test the handler for 353 / RPL_NAMREPLY @@ -575,7 +533,6 @@ func Test353(t *testing.T) { c.h_353(parseLine(":irc.server.org 353 test = #test1 :test @user1 user2 +voice ")) c.h_353(parseLine(":irc.server.org 353 test = #test1 :%halfop @op &admin ~owner ")) m.ExpectNothing() - c.ExpectNoErrors() if len(test1.Nicks) != 8 { t.Errorf("Unexpected number of nicks in test channel after 353.") @@ -616,7 +573,6 @@ func Test353(t *testing.T) { // Check unknown channel causes an error c.h_324(parseLine(":irc.server.org 353 test = #test2 :test ~user3")) m.ExpectNothing() - c.ExpectError() } // Test the handler for 671 (unreal specific) @@ -633,7 +589,6 @@ func Test671(t *testing.T) { // Send a 671 reply c.h_671(parseLine(":irc.server.org 671 test user1 :some ignored text")) m.ExpectNothing() - c.ExpectNoErrors() // Ensure user1 is now known to be on an SSL connection if !user1.Modes.SSL { @@ -643,5 +598,4 @@ func Test671(t *testing.T) { // Check error paths -- send a 671 for an unknown nick c.h_671(parseLine(":irc.server.org 671 test user2 :some ignored text")) m.ExpectNothing() - c.ExpectError() } diff --git a/client/line.go b/client/line.go index e9d7695..26d21ce 100644 --- a/client/line.go +++ b/client/line.go @@ -1,6 +1,7 @@ package client import ( + "github.com/fluffle/goirc/logging" "strings" "time" ) @@ -33,6 +34,7 @@ func parseLine(s string) *Line { line.Src, s = s[1:idx], s[idx+1:] } else { // pretty sure we shouldn't get here ... + logging.Warn("Parsing of line '%s' didn't go well.", s) line.Src = s[1:] return line } diff --git a/client/nickchan.go b/client/nickchan.go index e1ab45c..cb8664c 100644 --- a/client/nickchan.go +++ b/client/nickchan.go @@ -5,7 +5,7 @@ package client import ( "fmt" - "os" + "github.com/fluffle/goirc/logging" "reflect" "strconv" ) @@ -25,12 +25,6 @@ type stateTracker struct { chans map[string]*Channel // Map of nicks we know about nicks map[string]*Nick - - // A pointer to the connection whose state this tracks - conn *Conn - - // Logging interface - l Logger } @@ -122,9 +116,54 @@ func (st *stateTracker) GetChannel(c string) *Channel { return nil } +/******************************************************************************\ + * Channel methods for state management +\******************************************************************************/ + +func (ch *Channel) initialise() { + ch.Modes = new(ChanMode) + ch.Nicks = make(map[*Nick]*ChanPrivs) +} + +// Associates an *irc.Nick with an *irc.Channel using a shared *irc.ChanPrivs +func (ch *Channel) AddNick(n *Nick) { + if _, ok := ch.Nicks[n]; !ok { + ch.Nicks[n] = new(ChanPrivs) + n.Channels[ch] = ch.Nicks[n] + } else { + logging.Warn("irc.Channel.AddNick(): trying to add already-present "+ + "nick %s to channel %s", n.Nick, ch.Name) + } +} + +// Disassociates an *irc.Nick from an *irc.Channel. Will call ch.Delete() if +// the *irc.Nick being removed is the connection's nick. Will also call +// n.DelChannel(ch) to remove the association from the perspective of *irc.Nick. +func (ch *Channel) DelNick(n *Nick) { + if _, ok := ch.Nicks[n]; ok { + if n == n.conn.Me { + // we're leaving the channel, so remove all state we have about it + ch.Delete() + } else { + ch.Nicks[n] = nil, false + n.DelChannel(ch) + } + } // no else here ... + // we call Channel.DelNick() and Nick.DelChan() from each other to ensure + // consistency, and this would mean spewing an error message every delete +} + +// Stops the channel from being tracked by state tracking handlers. Also calls +// n.DelChannel(ch) for all nicks that are associated with the channel. +func (ch *Channel) Delete() { + for n, _ := range ch.Nicks { + n.DelChannel(ch) + } + ch.conn.chans[ch.Name] = nil, false +} // Parses mode strings for a channel -func (ch *Channel) ParseModes(modes string, modeargs []string) os.Error { +func (ch *Channel) ParseModes(modes string, modeargs []string) { var modeop bool // true => add mode, false => remove mode var modestr string for i := 0; i < len(modes); i++ { @@ -157,9 +196,8 @@ func (ch *Channel) ParseModes(modes string, modeargs []string) os.Error { } else if !modeop { ch.Modes.Key = "" } else { - return os.NewError(fmt.Sprintf( - "irc.ParseChanModes(): buh? not enough arguments to process MODE %s %s%s", - ch.Name, modestr, m)) + logging.Warn("Channel.ParseModes(): not enough arguments to "+ + "process MODE %s %s%s", ch.Name, modestr, m) } case 'l': if modeop && len(modeargs) != 0 { @@ -167,10 +205,9 @@ func (ch *Channel) ParseModes(modes string, modeargs []string) os.Error { modeargs = modeargs[1:] } else if !modeop { ch.Modes.Limit = 0 - } - return os.NewError(fmt.Sprintf( - "Channel.ParseModes(): buh? not enough arguments to process MODE %s %s%s", - ch.Name, modestr, m)) + } else { + logging.Warn("Channel.ParseModes(): not enough arguments to "+ + "process MODE %s %s%s", ch.Name, modestr, m) } case 'q', 'a', 'o', 'h', 'v': if len(modeargs) != 0 { @@ -190,86 +227,18 @@ func (ch *Channel) ParseModes(modes string, modeargs []string) os.Error { } modeargs = modeargs[1:] } else { - return os.NewError(fmt.Sprintf( - "Channel.ParseModes(): MODE %s %s%s %s: buh? state tracking failure.", - ch.Name, modestr, m, modeargs[0])) + logging.Warn("Channel.ParseModes(): untracked nick %s "+ + "recieved MODE on channel %s", modeargs[0], ch.Name) } } else { - conn.error("Channel.ParseModes(): buh? not enough arguments to process MODE %s %s%s", ch.Name, modestr, m) + logging.Warn("Channel.ParseModes(): not enough arguments to "+ + "process MODE %s %s%s", ch.Name, modestr, m) } } } return nil } -// Parse mode strings for a nick -func (n *Nick) ParseModes(modes string) { - var modeop bool // true => add mode, false => remove mode - for i := 0; i < len(modes); i++ { - switch m := modes[i]; m { - case '+': - modeop = true - case '-': - modeop = false - case 'i': - n.Modes.Invisible = modeop - case 'o': - n.Modes.Oper = modeop - case 'w': - n.Modes.WallOps = modeop - case 'x': - n.Modes.HiddenHost = modeop - case 'z': - n.Modes.SSL = modeop - } - } -} - -/******************************************************************************\ - * Channel methods for state management -\******************************************************************************/ - -func (ch *Channel) initialise() { - ch.Modes = new(ChanMode) - ch.Nicks = make(map[*Nick]*ChanPrivs) -} - -// Associates an *irc.Nick with an *irc.Channel using a shared *irc.ChanPrivs -func (ch *Channel) AddNick(n *Nick) { - if _, ok := ch.Nicks[n]; !ok { - ch.Nicks[n] = new(ChanPrivs) - n.Channels[ch] = ch.Nicks[n] - } else { - ch.conn.error("irc.Channel.AddNick() warning: trying to add already-present nick %s to channel %s", n.Nick, ch.Name) - } -} - -// Disassociates an *irc.Nick from an *irc.Channel. Will call ch.Delete() if -// the *irc.Nick being removed is the connection's nick. Will also call -// n.DelChannel(ch) to remove the association from the perspective of *irc.Nick. -func (ch *Channel) DelNick(n *Nick) { - if _, ok := ch.Nicks[n]; ok { - if n == n.conn.Me { - // we're leaving the channel, so remove all state we have about it - ch.Delete() - } else { - ch.Nicks[n] = nil, false - n.DelChannel(ch) - } - } // no else here ... - // we call Channel.DelNick() and Nick.DelChan() from each other to ensure - // consistency, and this would mean spewing an error message every delete -} - -// Stops the channel from being tracked by state tracking handlers. Also calls -// n.DelChannel(ch) for all nicks that are associated with the channel. -func (ch *Channel) Delete() { - for n, _ := range ch.Nicks { - n.DelChannel(ch) - } - ch.conn.chans[ch.Name] = nil, false -} - /******************************************************************************\ * Nick methods for state management \******************************************************************************/ @@ -282,13 +251,14 @@ func (n *Nick) initialise() { // // Very slightly different to irc.Channel.AddNick() in that it tests for a // pre-existing association within the *irc.Nick object rather than the -// *irc.Channel object before associating the two. +// *irc.Channel object before associating the two. func (n *Nick) AddChannel(ch *Channel) { if _, ok := n.Channels[ch]; !ok { ch.Nicks[n] = new(ChanPrivs) n.Channels[ch] = ch.Nicks[n] } else { - n.conn.error("irc.Nick.AddChannel() warning: trying to add already-present channel %s to nick %s", ch.Name, n.Nick) + logging.Warn("irc.Nick.AddChannel(): trying to add already-present "+ + "channel %s to nick %s", ch.Name, n.Nick) } } @@ -326,6 +296,29 @@ func (n *Nick) Delete() { } } +// Parse mode strings for a nick +func (n *Nick) ParseModes(modes string) { + var modeop bool // true => add mode, false => remove mode + for i := 0; i < len(modes); i++ { + switch m := modes[i]; m { + case '+': + modeop = true + case '-': + modeop = false + case 'i': + n.Modes.Invisible = modeop + case 'o': + n.Modes.Oper = modeop + case 'w': + n.Modes.WallOps = modeop + case 'x': + n.Modes.HiddenHost = modeop + case 'z': + n.Modes.SSL = modeop + } + } +} + /******************************************************************************\ * String() methods for all structs in this file for ease of debugging. \******************************************************************************/ @@ -438,7 +431,7 @@ func (n *Nick) String() string { // +npk key func (cm *ChanMode) String() string { str := "+" - a := make([]string, 2) + a := make([]string, 0) v := reflect.Indirect(reflect.ValueOf(cm)) t := v.Type() for i := 0; i < v.NumField(); i++ { @@ -450,12 +443,12 @@ func (cm *ChanMode) String() string { case reflect.String: if f.String() != "" { str += ChanModeToString[t.Field(i).Name] - a[0] = f.String() + a = append(a, f.String()) } case reflect.Int, reflect.Int8, reflect.Int16, reflect.Int32, reflect.Int64: if f.Int() != 0 { str += ChanModeToString[t.Field(i).Name] - a[1] = fmt.Sprintf("%d", f.Int()) + a = append(a, fmt.Sprintf("%d", f.Int())) } } } diff --git a/logging/log.go b/logging/log.go new file mode 100644 index 0000000..ac631fb --- /dev/null +++ b/logging/log.go @@ -0,0 +1,195 @@ +package logging + +import ( + "flag" + "fmt" + "io" + "log" + "os" + "sync" +) + +// A simple level-based logging system. +// Note that higher levels of logging are still usable via Log() +// Also, remember to call flag.Parse() near the start of your func main() +const ( + LogFatal = iota - 1 + LogError + LogWarn + LogInfo + LogDebug +) + +var ( + file = flag.String("log.file", "", + "Log to this file rather than STDERR") + level = flag.Int("log.level", LogError, + "Level of logging to be output") + only = flag.Bool("log.only", false, + "Only log output at the selected level") + + // Shortcut flags for great justice + quiet = flag.Bool("log.quiet", false, + "Only fatal output (equivalent to -v -1)") + warn = flag.Bool("log.warn", false, + "Warning output (equivalent to -v 1)") + info = flag.Bool("log.info", false, + "Info output (equivalent to -v 2)") + debug = flag.Bool("log.debug", false, + "Debug output (equivalent to -v 3)") +) + +type Logger interface { + // Log at a given level + Log(int, string, ...interface{}) + // Log at level 3 + Debug(string, ...interface{}) + // Log at level 2 + Info(string, ...interface{}) + // Log at level 1 + Warn(string, ...interface{}) + // Log at level 0 + Error(string, ...interface{}) + // Log at level -1, to STDERR always, and exit after logging. + Fatal(string, ...interface{}) + // Change the current log display level + SetLogLevel(int) +} + +// A struct to implement the above interface +type logger struct { + // We wrap a log.Logger for most of the heavy lifting + // but it can't be anonymous thanks to the conflicting definitions of Fatal + log *log.Logger + level int + only bool + *sync.Mutex // to ensure changing levels/flags is atomic +} + +var internal *logger + +func init() { + /// Hopefully this won't cause pain and suffering + flag.Parse() + + // Where are we logging to? + var out io.Writer + if *file != "" { + fh, err := os.OpenFile(*file, os.O_WRONLY|os.O_CREATE|os.O_APPEND, 0644) + if err != nil { + log.Fatalf("Error opening log file: %s", err) + } else { + out = fh + } + } else { + out = os.Stderr + } + + // What are we logging? + var lv int + // The shortcut flags prioritize by level, but an + // explicit level flag takes first precedence. + // I think the switch looks cleaner than if/else if, meh :-) + switch { + case *level != 0: + lv = *level + case *quiet: + lv = LogFatal + case *warn: + lv = LogWarn + case *info: + lv = LogInfo + case *debug: + lv = LogDebug + } + + internal = New(out, lv, *only) +} + +func New(out io.Writer, level int, only bool) *logger { + l := log.New(out, "", log.LstdFlags) + return &logger{l, level, only, &sync.Mutex{}} +} + +// Internal function all others call to ensure identical call depth +func (l *logger) write(lv int, fm string, v ...interface{}) { + if lv > l.level { + // Your logs are not important to us, goodnight + return + } + + l.Lock() + defer l.Unlock() + lineno := bool((l.log.Flags() & log.Lshortfile) > 0) + // Enable logging file:line if LogWarn level or worse + if lv <= LogWarn && !lineno { + l.log.SetFlags(log.LstdFlags | log.Lshortfile) + } else if lv > LogWarn && lineno { + l.log.SetFlags(log.LstdFlags) + } + // Writing the log is deceptively simple + l.log.Output(3, fmt.Sprintf(fm, v...)) + if lv == LogFatal { + // Always fatal to stderr too. + log.Fatalf(fm, v...) + } +} + +func (l *logger) Log(lv int, fm string, v ...interface{}) { + l.write(lv, fm, v...) +} + +func Log(lv int, fm string, v ...interface{}) { + internal.write(lv, fm, v...) +} + +// Helper functions for specific levels +func (l *logger) Debug(fm string, v ...interface{}) { + l.write(LogDebug, fm, v...) +} + +func Debug(fm string, v ...interface{}) { + internal.write(LogDebug, fm, v...) +} + +func (l *logger) Info(fm string, v ...interface{}) { + l.write(LogInfo, fm, v...) +} + +func Info(fm string, v ...interface{}) { + internal.write(LogInfo, fm, v...) +} + +func (l *logger) Warn(fm string, v ...interface{}) { + l.write(LogWarn, fm, v...) +} + +func Warn(fm string, v ...interface{}) { + internal.write(LogWarn, fm, v...) +} + +func (l *logger) Error(fm string, v ...interface{}) { + l.write(LogError, fm, v...) +} + +func Error(fm string, v ...interface{}) { + internal.write(LogError, fm, v...) +} + +func (l *logger) Fatal(fm string, v ...interface{}) { + l.write(LogFatal, fm, v...) +} + +func Fatal(fm string, v ...interface{}) { + internal.write(LogFatal, fm, v...) +} + +func (l *logger) SetLogLevel(lv int) { + l.Lock() + defer l.Unlock() + l.level = lv +} + +func SetLogLevel(lv int) { + internal.SetLogLevel(lv) +} diff --git a/logging/log_test.go b/logging/log_test.go new file mode 100644 index 0000000..7575fa0 --- /dev/null +++ b/logging/log_test.go @@ -0,0 +1,32 @@ +package logging + +import ( + "os" + "testing" +) + +type mockWriter struct { + written []byte +} + +func (w *mockWriter) Write(p []byte) (n int, err os.Error) { + w.written = append(w.written, p...) + return len(p), nil +} + +func TestDefaultLogging(t *testing.T) { + w := &mockWriter{make([]byte, 0)} + l := New(w, LogError, false) + l.Log(4, "Nothing should be logged yet") + l.Log(LogDebug, "or yet...") + l.Log(LogWarn, "or yet!") + if len(w.written) > 0 { + t.Errorf("Unexpected low-level logging output.") + } + l.Log(LogError, "Error!") + // Note: the below is deliberately fragile to ensure + // the right file:line is logged on errors. Sorry! + if s := string(w.written); s[20:] != "log_test.go:26: Error!\n" { + t.Errorf("Error incorrectly logged (check line numbers!)") + } +}