Skip to content

Commit

Permalink
simplize log
Browse files Browse the repository at this point in the history
  • Loading branch information
linyows committed Aug 21, 2023
1 parent 6addaf2 commit 8861343
Show file tree
Hide file tree
Showing 3 changed files with 82 additions and 44 deletions.
28 changes: 25 additions & 3 deletions integration_test.go
Original file line number Diff line number Diff line change
@@ -1,6 +1,9 @@
package warp

import (
"bytes"
"fmt"
"log"
"testing"
)

Expand All @@ -14,17 +17,31 @@ func TestIntegration(t *testing.T) {
smtpPort := 11025
hostname := "example.local"

var (
warpLog bytes.Buffer
smtpLog bytes.Buffer
)

go func() {
specifiedDstIP = ip
specifiedDstPort = smtpPort
w := &Server{Addr: ip, Port: warpPort}
w := &Server{
Addr: ip,
Port: warpPort,
log: log.New(&warpLog, "", log.Ldate|log.Ltime|log.Lmicroseconds),
}
if err := w.Start(); err != nil {
t.Errorf("warp raised error: %s", err)
}
}()

go func() {
s := &SMTPServer{IP: ip, Port: smtpPort, Hostname: hostname}
s := &SMTPServer{
IP: ip,
Port: smtpPort,
Hostname: hostname,
log: log.New(&smtpLog, "", log.Ldate|log.Ltime|log.Lmicroseconds),
}
if err := s.Serve(); err != nil {
t.Errorf("smtp server raised error: %s", err)
}
Expand All @@ -34,7 +51,12 @@ func TestIntegration(t *testing.T) {
WaitForServerListen(ip, smtpPort)

c := &SMTPClient{IP: ip, Port: warpPort}
if err := c.SendEmail(); err != nil {
err := c.SendEmail()

fmt.Printf("\nWarp Server:\n%s", &warpLog)
fmt.Printf("\nSMTP Server:\n%s\n", &smtpLog)

if err != nil {
t.Errorf("smtp client raised error: %s", err)
}
}
26 changes: 16 additions & 10 deletions server.go
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@ import (
"fmt"
"log"
"net"
"os"
"syscall"
"time"
)
Expand All @@ -14,6 +15,7 @@ type Server struct {
Addr string
Port int
Hooks []Hook
log *log.Logger
}

// These are global variables for integration test.
Expand All @@ -23,6 +25,10 @@ var (
)

func (s *Server) Start() error {
if s.log == nil {
s.log = log.New(os.Stderr, "", log.Ldate|log.Ltime|log.Lmicroseconds)
}

hooks, err := loadPlugins()
if err != nil {
return err
Expand All @@ -39,17 +45,17 @@ func (s *Server) Start() error {
return err
}
defer ln.Close()
log.Printf("warp listens to %s:%d", s.Addr, s.Port)
s.log.Printf("warp listens to %s:%d", s.Addr, s.Port)

for {
conn, err := ln.Accept()
if err != nil {
log.Printf("accept error(is the warp port open globally?): %#v", err)
s.log.Printf("accept error(is the warp port open globally?): %#v", err)
continue
}
if s.Addr == conn.RemoteAddr().String() {
conn.Close()
log.Printf("closed connection due to same ip(looping requests to warp?): %s", conn.RemoteAddr())
s.log.Printf("closed connection due to same ip(looping requests to warp?): %s", conn.RemoteAddr())
continue
}
go s.HandleConnection(conn)
Expand All @@ -58,18 +64,18 @@ func (s *Server) Start() error {

func (s *Server) HandleConnection(conn net.Conn) {
uuid := GenID().String()
log.Printf("[%s] %s %s connected from %s", time.Now().Format(TimeFormat), uuid, onPxy, conn.RemoteAddr())
s.log.Printf("%s %s connected from %s", uuid, onPxy, conn.RemoteAddr())

raddr, err := s.OriginalAddrDst(conn)
if err != nil {
log.Printf("[%s] %s %s original addr error: %#v", time.Now().Format(TimeFormat), uuid, onPxy, err)
s.log.Printf("%s %s original addr error: %#v", uuid, onPxy, err)
return
}

go func() {
now := time.Now()
b := []byte(fmt.Sprintf("connecting to %s", raddr))
log.Printf("[%s] %s %s %s", now.Format(TimeFormat), uuid, onPxy, b)
s.log.Printf("%s %s %s", uuid, onPxy, b)
for _, hook := range s.Hooks {
hook.AfterComm(&AfterCommData{
ConnID: uuid,
Expand All @@ -82,13 +88,13 @@ func (s *Server) HandleConnection(conn net.Conn) {

laddr, err := net.ResolveTCPAddr("tcp", fmt.Sprintf("%s:0", s.Addr))
if err != nil {
log.Printf("[%s] %s %s resolve tcp addr error: %#v", time.Now().Format(TimeFormat), uuid, onPxy, err)
s.log.Printf("%s %s resolve tcp addr error: %#v", uuid, onPxy, err)
return
}
dialer := &net.Dialer{LocalAddr: laddr}
dstConn, err := dialer.Dial("tcp", raddr.String())
if err != nil {
log.Printf("[%s] %s %s dial `%s` error: %#v", time.Now().Format(TimeFormat), uuid, onPxy, raddr, err)
s.log.Printf("%s %s dial `%s` error: %#v", uuid, onPxy, raddr, err)
return
}

Expand All @@ -100,7 +106,7 @@ func (s *Server) HandleConnection(conn net.Conn) {
}
p.afterCommHook = func(b Data, to Direction) {
now := time.Now()
log.Printf("[%s] %s %s %s", now.Format(TimeFormat), p.id, to, p.escapeCRLF(b))
s.log.Printf("%s %s %s", p.id, to, p.escapeCRLF(b))
for _, hook := range s.Hooks {
hook.AfterComm(&AfterCommData{
ConnID: p.id,
Expand All @@ -113,7 +119,7 @@ func (s *Server) HandleConnection(conn net.Conn) {
p.afterConnHook = func() {
now := time.Now()
elapse := p.elapse()
log.Printf("[%s] %s from:%s to:%s elapse:%s", now.Format(TimeFormat), p.id, p.sMailAddr, p.rMailAddr, elapse)
s.log.Printf("%s from:%s to:%s elapse:%s", p.id, p.sMailAddr, p.rMailAddr, elapse)
for _, hook := range s.Hooks {
hook.AfterConn(&AfterConnData{
ConnID: p.id,
Expand Down
72 changes: 41 additions & 31 deletions smtp.go
Original file line number Diff line number Diff line change
Expand Up @@ -3,14 +3,22 @@ package warp
import (
"bufio"
"crypto/tls"
"errors"
"fmt"
"io"
"log"
"net"
"net/smtp"
"os"
"strings"
"time"
)

const (
outgoing Direction = "->"
incomming Direction = "<-"
)

func WaitForServerListen(ip string, port int) {
host := fmt.Sprintf("%s:%d", ip, port)
fmt.Printf("Wait for port %d listen...", port)
Expand All @@ -36,34 +44,27 @@ type SMTPClient struct {
func (c *SMTPClient) SendEmail() error {
s, err := smtp.Dial(fmt.Sprintf("%s:%d", c.IP, c.Port))
if err != nil {
log.Println("smtp dial error")
return err
return fmt.Errorf("smtp.Dial(%s:%d): %#v", c.IP, c.Port, err)
}
if err := s.Mail("[email protected]"); err != nil {
log.Println("smtp mail error")
return err
return fmt.Errorf("smtp mail error: %#v", err)
}
if err := s.Rcpt("[email protected]"); err != nil {
log.Println("smtp rcpt error")
return err
return fmt.Errorf("smtp rcpt error: %#v", err)
}
wc, err := s.Data()
if err != nil {
log.Println("smtp data error")
return err
return fmt.Errorf("smtp data error: %#v", err)
}
_, err = fmt.Fprintf(wc, "This is the email body")
if err != nil {
log.Println("smtp data print error")
return err
return fmt.Errorf("smtp data print error: %#v", err)
}
if err = wc.Close(); err != nil {
log.Println("smtp close print error")
return err
return fmt.Errorf("smtp close print error: %#v", err)
}
if err = s.Quit(); err != nil {
log.Println("smtp quit error")
return err
return fmt.Errorf("smtp quit error: %#v", err)
}
return nil
}
Expand All @@ -72,24 +73,29 @@ type SMTPServer struct {
IP string
Port int
Hostname string
log *log.Logger
}

func (s *SMTPServer) Serve() error {
if s.log == nil {
s.log = log.New(os.Stderr, "", log.LstdFlags)
}

listener, err := net.Listen("tcp", fmt.Sprintf(":%d", s.Port))
if err != nil {
return fmt.Errorf("net.Listen(tcp) error: %#v", err)
}
defer listener.Close()

log.Printf("SMTP server is listening on :%d\n", s.Port)
s.log.Printf("SMTP server is listening on :%d\n", s.Port)

for {
conn, err := listener.Accept()
if err != nil {
log.Println("Accept error:", err)
s.log.Println("Accept error:", err)
continue
}
c := &SMTPConn{hostname: s.Hostname}
c := &SMTPConn{hostname: s.Hostname, id: GenID().String(), log: s.log}
go c.handle(conn)
}

Expand All @@ -99,16 +105,10 @@ func (s *SMTPServer) Serve() error {
type SMTPConn struct {
reader *bufio.Reader
writer *bufio.Writer
data bool
id string
hostname string
}

func (c *SMTPConn) writeStringWithLog(str string) {
_, err := c.writer.WriteString(str + crlf)
if err != nil {
log.Printf("WriteString error: %#v", err)
}
log.Println(strings.ReplaceAll(str, crlf, "\\r\\n"))
data bool
log *log.Logger
}

func (c *SMTPConn) handle(conn net.Conn) {
Expand All @@ -117,18 +117,20 @@ func (c *SMTPConn) handle(conn net.Conn) {
c.reader = bufio.NewReader(conn)
c.writer = bufio.NewWriter(conn)

c.writeStringWithLog(fmt.Sprintf("220 %s ESMTP Server (Go)", c.hostname))
c.writeStringWithLog(fmt.Sprintf("220 %s ESMTP Server", c.hostname))
c.writer.Flush()
c.data = false

for {
line, err := c.reader.ReadString('\n')
if err != nil {
log.Println("already server port listen!")
if !errors.Is(err, io.EOF) {
c.log.Printf("%s %s conn ReadString error: %#v", c.id, "--", err)
}
return
}

log.Printf("<=== %s", line)
c.log.Printf("%s %s %s", c.id, incomming, line)
line = strings.TrimSpace(line)
parts := strings.Fields(line)
if len(parts) == 0 {
Expand Down Expand Up @@ -171,7 +173,7 @@ func (c *SMTPConn) handle(conn net.Conn) {
return
case ".":
c.data = false
c.writeStringWithLog("250 2.0.0 Ok: queued as AAAAAAAAAA")
c.writeStringWithLog("250 2.0.0 Ok: queued")
case "RSET":
c.writeStringWithLog("250 2.0.0 Ok")
case "NOOP":
Expand All @@ -193,10 +195,18 @@ func (c *SMTPConn) handle(conn net.Conn) {
}
}

func (c *SMTPConn) writeStringWithLog(str string) {
_, err := c.writer.WriteString(str + crlf)
if err != nil {
c.log.Printf("%s %s WriteString error: %#v", c.id, outgoing, err)
}
c.log.Printf("%s %s %s", c.id, outgoing, strings.ReplaceAll(str, crlf, "\\r\\n"))
}

func (c *SMTPConn) startTLS(conn net.Conn) {
cert, err := tls.LoadX509KeyPair("testdata/server.crt", "testdata/server.key")
if err != nil {
fmt.Printf("Error loading server certificate: %#v", err)
c.log.Printf("%s %s Error loading server certificate: %#v", c.id, "--", err)
return
}
tlsConfig := &tls.Config{Certificates: []tls.Certificate{cert}}
Expand Down

0 comments on commit 8861343

Please sign in to comment.