HULFT10 の開発時にフォワードプロキシを建てたのですが、go interface の勉強?も兼ねてプロキシにログファイル出力を追加した話をば。

はじめに

今回の記事は、goproxy と言っても環境変数 GOPROXY の事ではなく、goで作成されたプロキシサーバの事です。

最近の開発環境は、インターネット上のリポジトリから情報を取ってきて開発を行うことが多く、いろいろなツール（apt, dnf, docker, git, rust, golang, node...) が、社内プロキシ環境配下で動作し外部にアクセスしています。

この際、問題となるのが、proxy 認証エラーなどです(407 Proxy Authentication Required)

この問題を回避するために、踏み台となるプロキシサーバを経由して、実プロキシサーバへ接続する手法をとりました。

利用したのは、elazarl/goproxy ですが、設定を変えられること、ログを記録することがやりたかったので、interface の勉強もかねて機能を追加してみました。

1. やりたい事

goproxy を使ってプロキシーサーバを建てる場合は、以下のコードを書くだけですみます。

package main

import (
    "github.com/elazarl/goproxy"
    "log"
    "net/http"
)

func main() {
    proxy := goproxy.NewProxyHttpServer()
    proxy.Verbose = true
    log.Fatal(http.ListenAndServe(":8080", proxy))
}

これ元に以下のことができるように機能を追加修正していきます。
実現したいことは以下の通りです。

設定ファイルに指定されたポートで待ち受ける事
設定ファイルに指定されたプロキシサーバへ要求を中継する事
プロキシサーバの多段中継が行える事
アクセスログをファイルに記録する事
Windows build モジュールを作る事

構成イメージ

                     forward-proxy           internal-proxy(社内プロキシー
                      10.0.0.10:6060          proxy:8080
+-------------+      +---------------+         +---------------+
| docker      | ---->| goproxy-relay | --...-->|               | ----> internet
| git,go,rust |      +---------------+         +---------------+ 
+-------------+        config.yml
                        listen: 6060
                        proxy: http://proxy:8080
                              A
+-------------+               |
| docker      | --------------+
+-------------+               |
+-------------+               |
| docker      | --------------+
+-------------+

2. 設定ファイルを読み込む

設定は、yaml 形式で書かれた config.yml から読み込み、待ち受けポートと、ターゲットとなるプロキシサーバを取得するようにします。

import (
	"os"
	"gopkg.in/yaml.v3"
)

type Config struct {
	Listen string `yaml:"listen"`
	Proxy  string `yaml:"proxy"`
}

func loadConfig(file string) (Config, error) {
	config := Config{}
	data, err := os.ReadFile(file)
	if err != nil {
		return config, err
	}

	err = yaml.Unmarshal(data, &config)
	if err != nil {
		return config, err
	}

	return config, nil
}

3. 任意のプロキシーサーバに中継する

例えば、http://10.0.0.20:6060 を経由する場合には、NewConnectDialToProxy() に以下のように指定しするだけで済むようです。

package main

import (
    "github.com/elazarl/goproxy"
    "log"
    "net/http"
)

func main() {
    proxy := goproxy.NewProxyHttpServer()
    proxy.Verbose = true
    proxy.ConnectDial = proxy.NewConnectDialToProxy("http://10.0.0.20:6060")
    log.Fatal(http.ListenAndServe(":8080", proxy))
}

プロキシーサーバ指定なしだと、環境変数に指定されたプロキシーサーバへ接続するように作られてます

https://github.com/elazarl/goproxy/blob/master/proxy.go#L152

4. ログをファイルに書き出す

goproxy を実行するとわかるのですが、起動するとログが標準出力として端末に出力されるので、アクセスログを後で確認する事が難しくなります。

最低限以下のことが行えるようにします

時間を記録する (Datetime yyyy/mm/dd hh:mm:ss)
ログレベルを記録する
ログ切り替えを行い複数世代記録する

4.1. elazarl/goproxy - Logger interface

調べてみると、 Added logger interface to allow usage of custom loggers #323 のcommit で、Logger interface が commit されていました。

package goproxy

type Logger interface {
	Printf(format string, v ...interface{})
}

4.2. goplus-playground - logger

golpus-playground で使われている loggerをベースに、ファイルに書き出す処理を追加してみます

変更したコードは以下。
エラー処理などが抜けてますが、やっつけで良いので良しとします。

--- logger.go	2024-12-10 11:55:39.087717151 +0900
+++ logger.go	2024-12-10 12:02:08.438687352 +0900
@@ -1,12 +1,16 @@
 // Copyright 2017 The Go Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style
 // license that can be found in the LICENSE file.
+//
+// golang playground logger.go
 
 package main
 
 import (
-	stdlog "log"
+	"fmt"
+	"log"
 	"os"
+	"time"
 )
 
 type logger interface {
@@ -19,26 +23,91 @@
 // There is no need to specify a date/time prefix since stdout and stderr
 // are logged in StackDriver with those values already present.
 type stdLogger struct {
-	stderr *stdlog.Logger
-	stdout *stdlog.Logger
+	stdout    *log.Logger
+	size      int
+	maxsize   int
+	file      os.File
+	is_opened bool
+	filename  string
+}
+
+type loggerConfig struct {
+	maxsize  int
+	filename string
+}
+
+func newStdLogger(config loggerConfig) (*stdLogger, error) {
+	file, err := openFile(config.filename)
+	is_opened := true
+	if err != nil {
+		file = os.Stdout
+		is_opened = false
+	}
+	return &stdLogger{
+		file:      *file,
+		is_opened: is_opened,
+		filename:  config.filename,
+		stdout:    log.New(file, "", 0),
+		size:      0,
+		maxsize:   config.maxsize,
+	}, err
 }
 
-func newStdLogger() *stdLogger {
-	return &stdLogger{
-		stdout: stdlog.New(os.Stdout, "", 0),
-		stderr: stdlog.New(os.Stderr, "", 0),
+func openFile(filename string) (*os.File, error) {
+	return os.OpenFile(filename, os.O_RDWR|os.O_CREATE|os.O_APPEND, 0666)
+}
+
+
+func (l *stdLogger) filerotate() (bool, error) {
+	if l.is_opened {
+		l.file.Close()
+		l.is_opened = false
+	}
+	for i := 9; i > 1; i-- {
+		f := fmt.Sprintf("%s.%d", l.filename, i-1)
+		t := fmt.Sprintf("%s.%d", l.filename, i)
+		// file.8 -> file.9
+		// file.7 -> file.8
+		// file.1 -> file.2
+		os.Rename(f, t)
 	}
+	// file -> file.1
+	os.Rename(l.filename, fmt.Sprintf("%s.1", l.filename))
+	file, err := openFile(l.filename)
+	if err != nil {
+		fmt.Printf("%v", err)
+		l.stdout = log.New(os.Stdout, "", 0)
+		return false, err
+	}
+	l.file = *file
+	l.stdout = log.New(file, "", 0)
+	l.is_opened = true
+	return true, nil
+}
+
+func (l *stdLogger) output(level string, format string, args ...interface{}) {
+	t := time.Now().Format(time.DateTime)
+	line := fmt.Sprintf("%v,%v,%v", t, level, fmt.Sprintf(format, args...))
+	l.size += len(line)
+	if l.size > l.maxsize {
+		l.filerotate()
+		l.size = 0
+	}
+	l.stdout.Printf("%v", line)
 }
 
 func (l *stdLogger) Printf(format string, args ...interface{}) {
-	l.stdout.Printf(format, args...)
+	l.output("", format, args...)
+}
+
+func (l *stdLogger) Infof(format string, args ...interface{}) {
+	l.output("INFO", format, args...)
 }
 
 func (l *stdLogger) Errorf(format string, args ...interface{}) {
-	l.stderr.Printf(format, args...)
+	l.output("ERROR", format, args...)
 }
 
 func (l *stdLogger) Fatalf(format string, args ...interface{}) {
-	l.stderr.Fatalf(format, args...)
+	l.output("FATAL", format, args...)
 }
-

5. メイン

作ったコードを組み合わせた結果が以下です。起動すると受け付けた内容がログに書き出され、指定サイズを超過するとファイルの切り替えが行われます。

func main() {
	logger, err := newStdLogger(
		loggerConfig{
			filename: "proxy.log",
			maxsize:  1024*1024,
		})
	if err != nil {
		log.Printf("failed open log %v", err)
		os.Exit(1)
	}

	config, err := loadConfig("config.yml")
	if err != nil {
		log.Printf("load config %v", err)
		os.Exit(1)
	}

	proxy := goproxy.NewProxyHttpServer()
	proxy.Logger = logger // 置き換え
	proxy.Verbose = true
	proxy.OnRequest().HandleConnectFunc(func(host string, ctx *goproxy.ProxyCtx) (*goproxy.ConnectAction, string) {
		logger.Infof("%s => %s %s", ctx.Req.Method, config.Proxy, ctx.Req.URL)
		return goproxy.OkConnect, host
	})

	if len(config.Proxy) > 0 {
		log.Printf("forward_proxy: %s", config.Proxy)
		proxy.ConnectDial = proxy.NewConnectDialToProxy(config.Proxy)
	}
	http.ListenAndServe(fmt.Sprintf("0.0.0.0:" + config.Listen), proxy)
}

proxy.Logger = loggerの部分が、置き換えている個所

6. Windows モジュール

windows 上で動かしたかったため、クロスコンパイルしてみましたが、go は楽ですね

ターゲットosだけでこんなにあります

$ go tool dist list | awk -F / '{print $1}' | sort | uniq | cat -n
     1  aix
     2  android
     3  darwin
     4  dragonfly
     5  freebsd
     6  illumos
     7  ios
     8  js
     9  linux
    10  netbsd
    11  openbsd
    12  plan9
    13  solaris
    14  wasip1
    15  windows

windows で絞り込み

$ go tool dist list | grep windows
windows/386
windows/amd64
windows/arm
windows/arm64

得られた情報を GOOS と GOARCH にあたえて build

$ GOOS=windows GOARCH=amd64 go build

file magic を見ると、きちんと生成されていいて windows 上での実行も可能です

$ file goproxy-relay.exe
goproxy-relay.exe: PE32+ executable (console) x86-64, for MS Windows, 15 sections

7. まとめ

goproxy のログ出力がLogger interface として定義されていたので、助かりました。

go はインターフェイスさえ守っておけば、既存のコードを変えなくても柔軟に機能を生やすことができるので、go の良さを改めて感じた瞬間でした。

また、クロスコンパイルの簡易さも驚きでした。

作成したモジュールは依存もなく1バイナリーになっているので配布も楽なところです。

参考