API logs for IPFS Proxy

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 {

api/ipfsproxy/config_test.go

@@ -11,6 +11,7 @@ var cfgJSON = []byte(`
 {
 	"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",

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,
 	}
 

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")
+	}
+
+}

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",