From bc357400f622e1d6fe3363f6065a7f3ec49aeb07 Mon Sep 17 00:00:00 2001 From: Kishan Mohanbhai Sagathiya Date: Tue, 10 Sep 2019 13:59:03 +0700 Subject: [PATCH] API logs for IPFS Proxy --- api/ipfsproxy/config.go | 27 +++++++++++++ api/ipfsproxy/config_test.go | 21 +++++----- api/ipfsproxy/ipfsproxy.go | 29 +++++++++++++- api/ipfsproxy/ipfsproxy_test.go | 68 +++++++++++++++++++++++++++++++++ logging.go | 1 + 5 files changed, 134 insertions(+), 12 deletions(-) diff --git a/api/ipfsproxy/config.go b/api/ipfsproxy/config.go index cacfce57..d42c302d 100644 --- a/api/ipfsproxy/config.go +++ b/api/ipfsproxy/config.go @@ -4,6 +4,7 @@ import ( "encoding/json" "errors" "fmt" + "path/filepath" "time" "github.com/kelseyhightower/envconfig" @@ -46,6 +47,12 @@ type Config struct { // Should we talk to the IPFS API over HTTPS? (experimental, untested) NodeHTTPS bool + // LogFile is path of the file that would save Proxy API logs. If this + // path is empty, logs would be sent to standard output. This path + // should either be absolute or relative to cluster base directory. Its + // default value is empty. + LogFile string + // Maximum duration before timing out reading a full request ReadTimeout time.Duration @@ -90,6 +97,8 @@ type jsonConfig struct { NodeMultiaddress string `json:"node_multiaddress"` NodeHTTPS bool `json:"node_https,omitempty"` + LogFile string `json:"log_file"` + ReadTimeout string `json:"read_timeout"` ReadHeaderTimeout string `json:"read_header_timeout"` WriteTimeout string `json:"write_timeout"` @@ -101,6 +110,20 @@ type jsonConfig struct { ExtractHeadersTTL string `json:"extract_headers_ttl,omitempty"` } +// getLogPath gets full path of the file where proxy logs should be +// saved. +func (cfg *Config) getLogPath() string { + if filepath.IsAbs(cfg.LogFile) { + return cfg.LogFile + } + + if cfg.BaseDir == "" { + return "" + } + + return filepath.Join(cfg.BaseDir, cfg.LogFile) +} + // ConfigKey provides a human-friendly identifier for this type of Config. func (cfg *Config) ConfigKey() string { return configKey @@ -118,6 +141,7 @@ func (cfg *Config) Default() error { } cfg.ListenAddr = proxy cfg.NodeAddr = node + cfg.LogFile = "" cfg.ReadTimeout = DefaultReadTimeout cfg.ReadHeaderTimeout = DefaultReadHeaderTimeout cfg.WriteTimeout = DefaultWriteTimeout @@ -222,6 +246,8 @@ func (cfg *Config) applyJSONConfig(jcfg *jsonConfig) error { } config.SetIfNotDefault(jcfg.NodeHTTPS, &cfg.NodeHTTPS) + config.SetIfNotDefault(jcfg.LogFile, &cfg.LogFile) + err := config.ParseDurations( "ipfsproxy", &config.DurationOpt{Duration: jcfg.ReadTimeout, Dst: &cfg.ReadTimeout, Name: "read_timeout"}, @@ -278,6 +304,7 @@ func (cfg *Config) toJSONConfig() (jcfg *jsonConfig, err error) { jcfg.IdleTimeout = cfg.IdleTimeout.String() jcfg.MaxHeaderBytes = cfg.MaxHeaderBytes jcfg.NodeHTTPS = cfg.NodeHTTPS + jcfg.LogFile = cfg.LogFile jcfg.ExtractHeadersExtra = cfg.ExtractHeadersExtra if cfg.ExtractHeadersPath != DefaultExtractHeadersPath { diff --git a/api/ipfsproxy/config_test.go b/api/ipfsproxy/config_test.go index adab4f7d..6f7e5d41 100644 --- a/api/ipfsproxy/config_test.go +++ b/api/ipfsproxy/config_test.go @@ -9,16 +9,17 @@ import ( var cfgJSON = []byte(` { - "listen_multiaddress": "/ip4/127.0.0.1/tcp/9095", - "node_multiaddress": "/ip4/127.0.0.1/tcp/5001", - "read_timeout": "10m0s", - "read_header_timeout": "5s", - "write_timeout": "10m0s", - "idle_timeout": "1m0s", - "max_header_bytes": 16384, - "extract_headers_extra": [], - "extract_headers_path": "/api/v0/version", - "extract_headers_ttl": "5m" + "listen_multiaddress": "/ip4/127.0.0.1/tcp/9095", + "node_multiaddress": "/ip4/127.0.0.1/tcp/5001", + "log_file": "", + "read_timeout": "10m0s", + "read_header_timeout": "5s", + "write_timeout": "10m0s", + "idle_timeout": "1m0s", + "max_header_bytes": 16384, + "extract_headers_extra": [], + "extract_headers_path": "/api/v0/version", + "extract_headers_ttl": "5m" } `) diff --git a/api/ipfsproxy/ipfsproxy.go b/api/ipfsproxy/ipfsproxy.go index 3d61a96d..1b244ab6 100644 --- a/api/ipfsproxy/ipfsproxy.go +++ b/api/ipfsproxy/ipfsproxy.go @@ -4,10 +4,12 @@ import ( "context" "encoding/json" "fmt" + "io" "net" "net/http" "net/http/httputil" "net/url" + "os" "strconv" "strings" "sync" @@ -17,6 +19,7 @@ import ( "github.com/ipfs/ipfs-cluster/api" "github.com/ipfs/ipfs-cluster/rpcutil" + handlers "github.com/gorilla/handlers" mux "github.com/gorilla/mux" cid "github.com/ipfs/go-cid" logging "github.com/ipfs/go-log" @@ -34,7 +37,10 @@ import ( // DNSTimeout is used when resolving DNS multiaddresses in this module var DNSTimeout = 5 * time.Second -var logger = logging.Logger("ipfsproxy") +var ( + logger = logging.Logger("ipfsproxy") + proxyLogger = logging.Logger("ipfsproxylog") +) // Server offers an IPFS API, hijacking some interesting requests // and forwarding the rest to the ipfs daemon @@ -87,6 +93,14 @@ type ipfsAddResp struct { Size string `json:",omitempty"` } +type logWriter struct { +} + +func (lw logWriter) Write(b []byte) (int, error) { + proxyLogger.Infof(string(b)) + return len(b), nil +} + // New returns and ipfs Proxy component func New(cfg *Config) (*Server, error) { err := cfg.Validate() @@ -148,12 +162,23 @@ func New(cfg *Config) (*Server, error) { } } + var writer io.Writer + if cfg.LogFile != "" { + f, err := os.OpenFile(cfg.getLogPath(), os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644) + if err != nil { + return nil, err + } + writer = f + } else { + writer = logWriter{} + } + s := &http.Server{ ReadTimeout: cfg.ReadTimeout, WriteTimeout: cfg.WriteTimeout, ReadHeaderTimeout: cfg.ReadHeaderTimeout, IdleTimeout: cfg.IdleTimeout, - Handler: handler, + Handler: handlers.LoggingHandler(writer, handler), MaxHeaderBytes: cfg.MaxHeaderBytes, } diff --git a/api/ipfsproxy/ipfsproxy_test.go b/api/ipfsproxy/ipfsproxy_test.go index 8a9d6026..327421b2 100644 --- a/api/ipfsproxy/ipfsproxy_test.go +++ b/api/ipfsproxy/ipfsproxy_test.go @@ -7,6 +7,8 @@ import ( "io/ioutil" "net/http" "net/url" + "os" + "path/filepath" "strings" "testing" "time" @@ -762,3 +764,69 @@ func TestAttackHeaderSize(t *testing.T) { } } } + +func TestProxyLogging(t *testing.T) { + ctx := context.Background() + cfg := &Config{} + cfg.Default() + + logFile, err := filepath.Abs("proxy.log") + if err != nil { + t.Fatal(err) + } + cfg.LogFile = logFile + + proxy, mock := testIPFSProxyWithConfig(t, cfg) + defer os.Remove(cfg.LogFile) + + info, err := os.Stat(cfg.LogFile) + if err != nil { + t.Fatal(err) + } + if info.Size() > 0 { + t.Errorf("expected empty log file") + } + + res, err := http.Post(fmt.Sprintf("%s/version", proxyURL(proxy)), "", nil) + if err != nil { + t.Fatal("should forward requests to ipfs host: ", err) + } + res.Body.Close() + + info, err = os.Stat(cfg.LogFile) + if err != nil { + t.Fatal(err) + } + size1 := info.Size() + if size1 == 0 { + t.Error("did not expect an empty log file") + } + + // Restart proxy and make sure that logs are being appended + mock.Close() + proxy.Shutdown(ctx) + + proxy, mock = testIPFSProxyWithConfig(t, cfg) + defer mock.Close() + defer proxy.Shutdown(ctx) + + res1, err := http.Post(fmt.Sprintf("%s/version", proxyURL(proxy)), "", nil) + if err != nil { + t.Fatal("should forward requests to ipfs host: ", err) + } + res1.Body.Close() + + info, err = os.Stat(cfg.LogFile) + if err != nil { + t.Fatal(err) + } + size2 := info.Size() + if size2 == 0 { + t.Error("did not expect an empty log file") + } + + if !(size2 > size1) { + t.Error("logs were not appended") + } + +} diff --git a/logging.go b/logging.go index dff2dd5d..5126029c 100644 --- a/logging.go +++ b/logging.go @@ -26,6 +26,7 @@ var LoggingFacilities = map[string]string{ "restapi": "INFO", "restapilog": "INFO", "ipfsproxy": "INFO", + "ipfsproxylog": "INFO", "ipfshttp": "INFO", "monitor": "INFO", "dsstate": "INFO",