diff --git a/cmd/coraza-spoa/main.go b/cmd/coraza-spoa/main.go index 2490c24..e1583a8 100644 --- a/cmd/coraza-spoa/main.go +++ b/cmd/coraza-spoa/main.go @@ -8,22 +8,33 @@ import ( "github.com/corazawaf/coraza-spoa/config" "github.com/corazawaf/coraza-spoa/internal" + "github.com/corazawaf/coraza-spoa/log" ) func main() { cfg := flag.String("config", "", "configuration file") + //nolint:staticcheck // That's exactly nil check if cfg == nil { - panic("configuration file is not set") + log.Fatal().Msg("configuration file is not set") } + debug := flag.Bool("debug", false, "sets log level to debug") + flag.Parse() + + log.SetDebug(*debug) + + //nolint:staticcheck // Nil is checked above if err := config.InitConfig(*cfg); err != nil { - panic(err) + log.Fatal().Err(err).Msg("Can't initialize configuration") } + + log.InitLogging(config.Global.Log.File, config.Global.Log.Level, config.Global.Log.SpoeLevel) + spoa, err := internal.New(config.Global) if err != nil { - panic(err) + log.Fatal().Err(err).Msg("Can't initialize SPOA") } if err := spoa.Start(config.Global.Bind); err != nil { - panic(err) + log.Fatal().Err(err).Msg("Can't start SPOA") } } diff --git a/config.yaml.default b/config.yaml.default index 4a6cf88..eda6a49 100644 --- a/config.yaml.default +++ b/config.yaml.default @@ -1,6 +1,14 @@ - # The SPOA server bind address bind: 0.0.0.0:9000 +log: + # The log level configuration, one of: debug/info/warn/error/panic/fatal + level: trace + # The log file path, /dev/stderr by default + file: /dev/stdout + # Log WAF errors as SPOA, default is false + waf: true + # The log level of underlying SPOE library (criteo/haproxy-spoe-go), one of: debug/info/warn/error/panic/fatal. Default is info. + spoe_level: info # Process request and response with this application if provided app name is not found. # You can remove or comment out this config param if you don't need "default_application" functionality. @@ -26,7 +34,7 @@ applications: # The maximum number of transactions which can be cached transaction_active_limit: 100000 - # The log level configuration, one of: debug/info/warn/error/panic/fatal + # Deprecated, doesn't work. Use root.log.level log_level: info - # The log file path + # Deprecated, doesn't work. Use root.log.file log_file: /dev/stdout \ No newline at end of file diff --git a/config/config.go b/config/config.go index d5df3f8..490b5de 100644 --- a/config/config.go +++ b/config/config.go @@ -7,6 +7,7 @@ import ( "fmt" "os" + "github.com/corazawaf/coraza-spoa/log" yaml "gopkg.in/yaml.v3" ) @@ -16,14 +17,18 @@ var Global *Config // Config is used to configure coraza-server. type Config struct { Bind string `yaml:"bind"` + Log Log `yaml:"log"` DefaultApplication string `yaml:"default_application"` Applications map[string]*Application `yaml:"applications"` } // Application is used to manage the haproxy configuration and waf rules. type Application struct { - LogLevel string `yaml:"log_level"` - LogFile string `yaml:"log_file"` + // Deprecated: #70: use Config.Log.Level to set up application logging or SecDebugLogLevel to set up Coraza logging + LogLevel string `yaml:"log_level"` + // Deprecated: #70: use Config.Log.File to set up application logging or SecDebugLog to set up Coraza logging + LogFile string `yaml:"log_file"` + NoResponseCheck bool `yaml:"no_response_check"` Directives string `yaml:"directives"` // Deprecated: use directives instead, this will be removed in the near future. @@ -32,6 +37,14 @@ type Application struct { TransactionActiveLimit int `yaml:"transaction_active_limit"` } +// Log is used to manage the SPOA logging. +type Log struct { + Level string `yaml:"level"` + File string `yaml:"file"` + Waf bool `yaml:"waf"` + SpoeLevel string `yaml:"spoe_level"` +} + // InitConfig initializes the configuration. func InitConfig(file string) error { f, err := os.Open(file) @@ -54,11 +67,20 @@ func InitConfig(file string) error { } func validateConfig() error { - fmt.Printf("Loading %d applications\n", len(Global.Applications)) - for _, app := range Global.Applications { - if app.LogLevel == "" { - app.LogLevel = "warn" + log.Info().Msgf("Loading %d applications", len(Global.Applications)) + + for name, app := range Global.Applications { + log.Debug().Str("name", name).Msg("Validating application config") + + // Deprecated: #70: use Config.Log.Level to set up application logging or SecDebugLogLevel to set up Coraza logging + if app.LogLevel != "" { + log.Warn().Msg("'app.log_level' is skipped. For setting application log level use 'log.level' in the root of configuration.") + } + // Deprecated: #70: use Config.Log.File to set up application logging or SecDebugLog to set up Coraza logging + if app.LogFile != "" { + log.Warn().Msg("'app.log_level' is skipped. For setting application log file use 'log.file' in the root of configuration.") } + if app.TransactionTTLMilliseconds < 0 { return fmt.Errorf("SPOA transaction ttl must be greater than 0") } diff --git a/doc/config/haproxy.cfg b/doc/config/haproxy.cfg index 6564bd8..84e337d 100644 --- a/doc/config/haproxy.cfg +++ b/doc/config/haproxy.cfg @@ -6,11 +6,11 @@ defaults log global option httplog timeout client 1m - timeout server 1m - timeout connect 10s - timeout http-keep-alive 2m - timeout queue 15s - timeout tunnel 4h # for websocket + timeout server 1m + timeout connect 10s + timeout http-keep-alive 2m + timeout queue 15s + timeout tunnel 4h # for websocket frontend test mode http @@ -18,6 +18,8 @@ frontend test unique-id-format %[uuid()] unique-id-header X-Unique-ID + log-format "%ci:%cp\ [%t]\ %ft\ %b/%s\ %Th/%Ti/%TR/%Tq/%Tw/%Tc/%Tr/%Tt\ %ST\ %B\ %CC\ %CS\ %tsc\ %ac/%fc/%bc/%sc/%rc\ %sq/%bq\ %hr\ %hs\ %{+Q}r\ %ID\ waf-action:\ %[var(txn.coraza.action)]\ spoe-error:\ %[var(txn.coraza.error)]\ spoa-error:\ %[var(txn.coraza.err_code)]\ %[var(txn.coraza.err_msg)]" + filter spoe engine coraza config /etc/haproxy/coraza.cfg # Currently haproxy cannot use variables to set the code or deny_status, so this needs to be manually configured here @@ -30,10 +32,14 @@ frontend test http-request silent-drop if { var(txn.coraza.action) -m str drop } http-response silent-drop if { var(txn.coraza.action) -m str drop } - # Deny in case of an error, when processing with the Coraza SPOA + # Deny in case of an error, when processing with the Coraza SPOE http-request deny deny_status 504 if { var(txn.coraza.error) -m int gt 0 } http-response deny deny_status 504 if { var(txn.coraza.error) -m int gt 0 } + # Deny in case of an error, when processing with the Coraza SPOA + http-request deny deny_status 504 if { var(txn.coraza.err_code) -m int gt 0 } + http-response deny deny_status 504 if { var(txn.coraza.err_code) -m int gt 0 } + use_backend test_backend backend test_backend diff --git a/docker/haproxy/haproxy.cfg b/docker/haproxy/haproxy.cfg index a654294..75e129e 100644 --- a/docker/haproxy/haproxy.cfg +++ b/docker/haproxy/haproxy.cfg @@ -6,11 +6,11 @@ defaults log global option httplog timeout client 1m - timeout server 1m - timeout connect 10s - timeout http-keep-alive 2m - timeout queue 15s - timeout tunnel 4h # for websocket + timeout server 1m + timeout connect 10s + timeout http-keep-alive 2m + timeout queue 15s + timeout tunnel 4h # for websocket frontend stats mode http @@ -26,7 +26,7 @@ frontend test_frontend bind *:443 ssl crt /usr/local/etc/haproxy/example.com.pem alpn h2,http/1.1 unique-id-format %[uuid()] unique-id-header X-Unique-ID - log-format "%ci:%cp\ [%t]\ %ft\ %b/%s\ %Th/%Ti/%TR/%Tq/%Tw/%Tc/%Tr/%Tt\ %ST\ %B\ %CC\ %CS\ %tsc\ %ac/%fc/%bc/%sc/%rc\ %sq/%bq\ %hr\ %hs\ %{+Q}r\ %ID\ spoa-error:\ %[var(txn.coraza.error)]\ waf-action:\ %[var(txn.coraza.action)]" + log-format "%ci:%cp\ [%t]\ %ft\ %b/%s\ %Th/%Ti/%TR/%Tq/%Tw/%Tc/%Tr/%Tt\ %ST\ %B\ %CC\ %CS\ %tsc\ %ac/%fc/%bc/%sc/%rc\ %sq/%bq\ %hr\ %hs\ %{+Q}r\ %ID\ waf-action:\ %[var(txn.coraza.action)]\ spoe-error:\ %[var(txn.coraza.error)]\ spoa-error:\ %[var(txn.coraza.err_code)]\ %[var(txn.coraza.err_msg)]" filter spoe engine coraza config /usr/local/etc/haproxy/coraza.cfg @@ -40,10 +40,14 @@ frontend test_frontend http-request silent-drop if { var(txn.coraza.action) -m str drop } http-response silent-drop if { var(txn.coraza.action) -m str drop } - # Deny in case of an error, when processing with the Coraza SPOA + # Deny in case of an error, when processing with the Coraza SPOE http-request deny deny_status 504 if { var(txn.coraza.error) -m int gt 0 } http-response deny deny_status 504 if { var(txn.coraza.error) -m int gt 0 } + # Deny in case of an error, when processing with the Coraza SPOA + http-request deny deny_status 504 if { var(txn.coraza.err_code) -m int gt 0 } + http-response deny deny_status 504 if { var(txn.coraza.err_code) -m int gt 0 } + # Deprecated, use action instead of fail #http-request deny deny_status 401 hdr waf-block "request" if { var(txn.coraza.fail) -m int eq 1 } #http-response deny deny_status 401 hdr waf-block "response" if { var(txn.coraza.fail) -m int eq 1 } diff --git a/go.mod b/go.mod index c7faca4..fec1a29 100644 --- a/go.mod +++ b/go.mod @@ -7,20 +7,21 @@ require ( github.com/corazawaf/coraza/v3 v3.0.1 github.com/criteo/haproxy-spoe-go v1.0.6 github.com/magefile/mage v1.15.0 - go.uber.org/zap v1.24.0 + github.com/rs/zerolog v1.29.1 + github.com/sirupsen/logrus v1.9.3 gopkg.in/yaml.v3 v3.0.1 ) require ( github.com/corazawaf/libinjection-go v0.1.2 // indirect + github.com/mattn/go-colorable v0.1.12 // indirect + github.com/mattn/go-isatty v0.0.14 // indirect github.com/petar-dambovaliev/aho-corasick v0.0.0-20211021192214-5ab2d9280aa9 // indirect github.com/pkg/errors v0.9.1 // indirect - github.com/sirupsen/logrus v1.9.3 // indirect + github.com/stretchr/testify v1.8.0 // indirect github.com/tidwall/gjson v1.14.4 // indirect github.com/tidwall/match v1.1.1 // indirect github.com/tidwall/pretty v1.2.1 // indirect - go.uber.org/atomic v1.11.0 // indirect - go.uber.org/multierr v1.11.0 // indirect golang.org/x/net v0.11.0 // indirect golang.org/x/sys v0.9.0 // indirect rsc.io/binaryregexp v0.2.0 // indirect diff --git a/go.sum b/go.sum index b796025..2c49d5f 100644 --- a/go.sum +++ b/go.sum @@ -1,10 +1,10 @@ -github.com/benbjohnson/clock v1.1.0 h1:Q92kusRqC1XV2MjkWETPvjJVqKetz1OzxZB7mHJLju8= github.com/bluele/gcache v0.0.2 h1:WcbfdXICg7G/DGBh1PFfcirkWOQV+v077yF1pSy3DGw= github.com/bluele/gcache v0.0.2/go.mod h1:m15KV+ECjptwSPxKhOhQoAFQVtUFjTVkc3H8o0t/fp0= github.com/corazawaf/coraza/v3 v3.0.1 h1:akPpTofIUhabGU1Zbo+YVBZK/HdcxjGy8yXkjoqVFMQ= github.com/corazawaf/coraza/v3 v3.0.1/go.mod h1:zvldIncYMuW8xmRcOs37OWRhY3CPWBKbTngIGzR5v4Y= github.com/corazawaf/libinjection-go v0.1.2 h1:oeiV9pc5rvJ+2oqOqXEAMJousPpGiup6f7Y3nZj5GoM= github.com/corazawaf/libinjection-go v0.1.2/go.mod h1:OP4TM7xdJ2skyXqNX1AN1wN5nNZEmJNuWbNPOItn7aw= +github.com/coreos/go-systemd/v22 v22.5.0/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc= github.com/creack/pty v1.1.9/go.mod h1:oKZEueFk5CKHvIhNR5MUki03XCEU+Q6VDXinZuGJ33E= github.com/criteo/haproxy-spoe-go v1.0.6 h1:3GDQ8hm/fIkn4wxxI/pN0OoBfKon4ROzvpU5fIriYII= github.com/criteo/haproxy-spoe-go v1.0.6/go.mod h1:o04s69MOZ7SvPthMtUt/tfn1hcorQQAS/nwzKPBlXQU= @@ -12,6 +12,7 @@ github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSs github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= github.com/foxcpp/go-mockdns v1.0.0 h1:7jBqxd3WDWwi/6WhDvacvH1XsN3rOLXyHM1uhvIx6FI= +github.com/godbus/dbus/v5 v5.0.4/go.mod h1:xhWf0FNVPg57R7Z0UbKHbJfkEywrmjJnf7w5xrFpKfA= github.com/konsorten/go-windows-terminal-sequences v1.0.3/go.mod h1:T0+1ngSBFLxvqU3pZ+m/2kptfBszLMUkC4ZK/EgS/cQ= github.com/kr/pretty v0.2.1 h1:Fmg33tUaq4/8ym9TJN1x7sLJnHVwhP33CNkpYV/7rwI= github.com/kr/pretty v0.2.1/go.mod h1:ipq/a2n7PKx3OHsz4KJII5eveXtPO4qwEXGdVfWzfnI= @@ -21,6 +22,10 @@ github.com/kr/text v0.2.0 h1:5Nx0Ya0ZqY2ygV366QzturHI13Jq95ApcVaJBhpS+AY= github.com/kr/text v0.2.0/go.mod h1:eLer722TekiGuMkidMxC/pM04lWEeraHUUmBw8l2grE= github.com/magefile/mage v1.15.0 h1:BvGheCMAsG3bWUDbZ8AyXXpCNwU9u5CB6sM+HNb9HYg= github.com/magefile/mage v1.15.0/go.mod h1:z5UZb/iS3GoOSn0JgWuiw7dxlurVYTu+/jHXqQg881A= +github.com/mattn/go-colorable v0.1.12 h1:jF+Du6AlPIjs2BiUiQlKOX0rt3SujHxPnksPKZbaA40= +github.com/mattn/go-colorable v0.1.12/go.mod h1:u5H1YNBxpqRaxsYJYSkiCWKzEfiAb1Gb520KVy5xxl4= +github.com/mattn/go-isatty v0.0.14 h1:yVuAays6BHfxijgZPzw+3Zlu5yQgKGP2/hcQbHb7S9Y= +github.com/mattn/go-isatty v0.0.14/go.mod h1:7GGIvUiUoEMVVmxf/4nioHXj79iQHKdU27kJ6hsGG94= github.com/miekg/dns v1.1.50 h1:DQUfb9uc6smULcREF09Uc+/Gd46YWqJd5DbpPE9xkcA= github.com/petar-dambovaliev/aho-corasick v0.0.0-20211021192214-5ab2d9280aa9 h1:lL+y4Xv20pVlCGyLzNHRC0I0rIHhIL1lTvHizoS/dU8= github.com/petar-dambovaliev/aho-corasick v0.0.0-20211021192214-5ab2d9280aa9/go.mod h1:EHPiTAKtiFmrMldLUNswFwfZ2eJIYBHktdaUTZxYWRw= @@ -28,13 +33,19 @@ github.com/pkg/errors v0.9.1 h1:FEBLx1zS214owpjy7qsBeixbURkuhQAwrK5UwLGTwt4= github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= +github.com/rs/xid v1.4.0/go.mod h1:trrq9SKmegXys3aeAKXMUTdJsYXVwGY3RLcfgqegfbg= +github.com/rs/zerolog v1.29.1 h1:cO+d60CHkknCbvzEWxP0S9K6KqyTjrCNUy1LdQLCGPc= +github.com/rs/zerolog v1.29.1/go.mod h1:Le6ESbR7hc+DP6Lt1THiV8CQSdkkNrd3R0XbEgp3ZBU= github.com/sirupsen/logrus v1.7.0/go.mod h1:yWOB1SBYBC5VeMP7gHvWumXLIWorT60ONWic61uBYv0= github.com/sirupsen/logrus v1.9.3 h1:dueUQJ1C2q9oE3F7wvmSGAaVtTmUizReu6fjN8uqzbQ= github.com/sirupsen/logrus v1.9.3/go.mod h1:naHLuLoDiP4jHNo9R0sCBMtWGeIprob74mVsIT4qYEQ= github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= +github.com/stretchr/objx v0.4.0/go.mod h1:YvHI0jy2hoMjB+UWwv71VJQ9isScKT/TqJzVSSt89Yw= github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs= github.com/stretchr/testify v1.7.0/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= +github.com/stretchr/testify v1.7.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= github.com/stretchr/testify v1.8.0 h1:pSgiaMZlXftHpm5L7V1+rVB+AZJydKsMxsQBIJw4PKk= +github.com/stretchr/testify v1.8.0/go.mod h1:yNjHg4UonilssWZ8iaSj1OCr/vHnekPRkoO+kdMU+MU= github.com/tidwall/gjson v1.14.4 h1:uo0p8EbA09J7RQaflQ1aBRffTR7xedD2bcIVSYxLnkM= github.com/tidwall/gjson v1.14.4/go.mod h1:/wbyibRr2FHMks5tjHJ5F8dMZh3AcwJEMf5vlfC0lxk= github.com/tidwall/match v1.1.1 h1:+Ho715JplO36QYgwN9PGYNhgZvoUSc9X2c80KVTi+GA= @@ -42,18 +53,13 @@ github.com/tidwall/match v1.1.1/go.mod h1:eRSPERbgtNPcGhD8UCthc6PmLEQXEWd3PRB5JT github.com/tidwall/pretty v1.2.0/go.mod h1:ITEVvHYasfjBbM0u2Pg8T2nJnzm8xPwvNhhsoaGGjNU= github.com/tidwall/pretty v1.2.1 h1:qjsOFOWWQl+N3RsoF5/ssm1pHmJJwhjlSbZ51I6wMl4= github.com/tidwall/pretty v1.2.1/go.mod h1:ITEVvHYasfjBbM0u2Pg8T2nJnzm8xPwvNhhsoaGGjNU= -go.uber.org/atomic v1.11.0 h1:ZvwS0R+56ePWxUNi+Atn9dWONBPp/AUETXlHW0DxSjE= -go.uber.org/atomic v1.11.0/go.mod h1:LUxbIzbOniOlMKjJjyPfpl4v+PKK2cNJn91OQbhoJI0= -go.uber.org/goleak v1.1.11 h1:wy28qYRKZgnJTxGxvye5/wgWr1EKjmUDGYox5mGlRlI= -go.uber.org/multierr v1.11.0 h1:blXXJkSxSSfBVBlC76pxqeO+LN3aDfLQo+309xJstO0= -go.uber.org/multierr v1.11.0/go.mod h1:20+QtiLqy0Nd6FdQB9TLXag12DsQkrbs3htMFfDN80Y= -go.uber.org/zap v1.24.0 h1:FiJd5l1UOLj0wCgbSE0rwwXHzEdAZS6hiiSnxJN/D60= -go.uber.org/zap v1.24.0/go.mod h1:2kMP+WWQ8aoFoedH3T2sq6iJ2yDWpHbP0f6MQbS9Gkg= golang.org/x/mod v0.8.0 h1:LUYupSeNrTNCGzR/hVBk2NHZO4hXcVaW1k4Qx7rjPx8= golang.org/x/net v0.11.0 h1:Gi2tvZIJyBtO9SDr1q9h5hEQCp/4L2RQ+ar0qjx2oNU= golang.org/x/net v0.11.0/go.mod h1:2L/ixqYpgIVXmeoSA/4Lu7BzTG4KIyPIryS4IsOd1oQ= golang.org/x/sys v0.0.0-20191026070338-33540a1f6037/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20210113181707-4bcb84eeeb78/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= +golang.org/x/sys v0.0.0-20210630005230-0f9fa26af87c/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.0.0-20210927094055-39ccf1dd6fa6/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.0.0-20220715151400-c0bba94af5f8/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.9.0 h1:KS/R3tvhPqvJvwcKfnBHJwwthS11LRhmM5D59eEXa0s= golang.org/x/sys v0.9.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= diff --git a/internal/request.go b/internal/request.go index d4b91fd..6086923 100644 --- a/internal/request.go +++ b/internal/request.go @@ -4,9 +4,9 @@ package internal import ( - "fmt" "net" + "github.com/corazawaf/coraza-spoa/log" spoe "github.com/criteo/haproxy-spoe-go" ) @@ -78,22 +78,22 @@ func (req *request) init() error { req.path, err = req.msg.getStringArg("path") if err != nil { - fmt.Println(err.Error()) + log.Trace().Err(err).Msg("Can't get Path from HTTP Request") } req.query, err = req.msg.getStringArg("query") if err != nil { - fmt.Println(err.Error()) + log.Trace().Err(err).Msg("Can't get Query from HTTP Request") } req.version, err = req.msg.getStringArg("version") if err != nil { - fmt.Println(err.Error()) + log.Trace().Err(err).Msg("Can't get Version from HTTP Request") } req.headers, err = req.msg.getStringArg("headers") if err != nil { - fmt.Println(err.Error()) + log.Trace().Err(err).Msg("Can't get Headers from HTTP Request") } req.body, _ = req.msg.getByteArrayArg("body") diff --git a/internal/response.go b/internal/response.go index 79dc162..49ff266 100644 --- a/internal/response.go +++ b/internal/response.go @@ -4,8 +4,7 @@ package internal import ( - "fmt" - + "github.com/corazawaf/coraza-spoa/log" spoe "github.com/criteo/haproxy-spoe-go" ) @@ -46,7 +45,7 @@ func (resp *response) init() error { resp.version, err = resp.msg.getStringArg("version") if err != nil { - fmt.Println(err.Error()) + log.Trace().Err(err).Msg("Can't get Version from HTTP Request") } resp.status, err = resp.msg.getIntArg("status") @@ -56,7 +55,7 @@ func (resp *response) init() error { resp.headers, err = resp.msg.getStringArg("headers") if err != nil { - fmt.Println(err.Error()) + log.Trace().Err(err).Msg("Can't get Headers from HTTP Request") } resp.body, _ = resp.msg.getByteArrayArg("body") diff --git a/internal/spoa.go b/internal/spoa.go index d2a7f37..38b2ab6 100644 --- a/internal/spoa.go +++ b/internal/spoa.go @@ -6,28 +6,22 @@ package internal import ( "fmt" "net/http" - "os" "strings" "time" "github.com/bluele/gcache" "github.com/corazawaf/coraza-spoa/config" + "github.com/corazawaf/coraza-spoa/log" "github.com/corazawaf/coraza/v3" "github.com/corazawaf/coraza/v3/types" spoe "github.com/criteo/haproxy-spoe-go" - "go.uber.org/zap" - "go.uber.org/zap/zapcore" ) -// TODO - in coraza v3 ErrorLogCallback is currently in the internal package -type ErrorLogCallback = func(rule types.MatchedRule) - type application struct { - name string - cfg *config.Application - waf coraza.WAF - cache gcache.Cache - logger *zap.Logger + name string + cfg *config.Application + waf coraza.WAF + cache gcache.Cache } // SPOA store the relevant data for starting SPOA. @@ -38,7 +32,7 @@ type SPOA struct { // Start starts the SPOA to detect the security risks. func (s *SPOA) Start(bind string) error { - // s.logger.Info("Starting SPOA") + log.Debug().Msg("Starting SPOA") agent := spoe.New(func(messages *spoe.MessageIterator) ([]spoe.Action, error) { for messages.Next() { @@ -53,7 +47,6 @@ func (s *SPOA) Start(bind string) error { } return nil, nil }) - defer s.cleanApplications() if err := agent.ListenAndServe(bind); err != nil { return err } @@ -96,6 +89,39 @@ func (s *SPOA) allowAction() []spoe.Action { return act } +func (s *SPOA) error(code int, err error) []spoe.Action { + return []spoe.Action{ + spoe.ActionSetVar{ + Name: "err_code", + Scope: spoe.VarScopeTransaction, + Value: code, + }, + spoe.ActionSetVar{ + Name: "err_msg", + Scope: spoe.VarScopeTransaction, + Value: err.Error(), + }, + } +} + +func (s *SPOA) badRequestError(err error) []spoe.Action { + log.Error().Err(err).Msg("Bad request") + return s.error(1, err) +} + +func (s *SPOA) badResponseError(err error) []spoe.Action { + log.Error().Err(err).Msg("Bad response") + return s.error(2, err) +} + +func (s *SPOA) processRequestError(err error) []spoe.Action { + return s.error(3, err) +} + +func (s *SPOA) processResponseError(err error) []spoe.Action { + return s.error(4, err) +} + func (s *SPOA) readHeaders(headers string) (http.Header, error) { h := http.Header{} hs := strings.Split(headers, "\r\n") @@ -115,84 +141,33 @@ func (s *SPOA) readHeaders(headers string) (http.Header, error) { return h, nil } -func (s *SPOA) cleanApplications() { - for _, app := range s.applications { - if err := app.logger.Sync(); err != nil { - app.logger.Error("failed to sync logger", zap.Error(err)) - } - } -} - -func logError(logger *zap.Logger) ErrorLogCallback { - return func(mr types.MatchedRule) { - data := mr.ErrorLog() - switch mr.Rule().Severity() { - case types.RuleSeverityEmergency: - logger.Error(data) - case types.RuleSeverityAlert: - logger.Error(data) - case types.RuleSeverityCritical: - logger.Error(data) - case types.RuleSeverityError: - logger.Error(data) - case types.RuleSeverityWarning: - logger.Warn(data) - case types.RuleSeverityNotice: - logger.Info(data) - case types.RuleSeverityInfo: - logger.Info(data) - case types.RuleSeverityDebug: - logger.Debug(data) - } - } -} - // New Create a new SPOA instance. func New(conf *config.Config) (*SPOA, error) { apps := make(map[string]*application) for name, cfg := range conf.Applications { - pe := zap.NewProductionEncoderConfig() - - fileEncoder := zapcore.NewJSONEncoder(pe) + wafConf := coraza.NewWAFConfig(). + WithDirectives(cfg.Directives) - pe.EncodeTime = zapcore.ISO8601TimeEncoder - - level, err := zapcore.ParseLevel(cfg.LogLevel) - if err != nil { - level = zap.InfoLevel + if conf.Log.Waf { + wafConf = wafConf.WithErrorCallback(log.WafErrorCallback) } - f, err := os.OpenFile(cfg.LogFile, os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0666) - if err != nil { - return nil, err - } - core := zapcore.NewTee( - zapcore.NewCore(fileEncoder, zapcore.AddSync(f), level), - ) - - logger := zap.New(core) - - conf := coraza.NewWAFConfig(). - WithDirectives(cfg.Directives). - WithErrorCallback(logError(logger)) //nolint:staticcheck // https://github.com/golangci/golangci-lint/issues/741 if len(cfg.Rules) > 0 { // Deprecated: this will soon be removed - logger.Warn("'rules' directive in configuration is deprecated and will be removed soon, use 'directives' instead") - conf = conf.WithDirectives(strings.Join(cfg.Rules, "\n")) + log.Warn().Msg("'rules' directive in configuration is deprecated and will be removed soon, use 'directives' instead") + wafConf = wafConf.WithDirectives(strings.Join(cfg.Rules, "\n")) } - waf, err := coraza.NewWAF(conf) + waf, err := coraza.NewWAF(wafConf) if err != nil { - logger.Error("unable to create waf instance", zap.String("app", name), zap.Error(err)) - return nil, err + return nil, fmt.Errorf("Unable to create WAF instance. app:%s, err:%w", name, err) } app := &application{ - name: name, - cfg: cfg, - waf: waf, - logger: logger, + name: name, + cfg: cfg, + waf: waf, } app.cache = gcache.New(app.cfg.TransactionActiveLimit). @@ -205,7 +180,7 @@ func New(conf *config.Config) (*SPOA, error) { // Process Logging won't do anything if TX was already logged. tx.ProcessLogging() if err := tx.Close(); err != nil { - app.logger.Error("Failed to clean cache", zap.Error(err)) + tx.DebugLogger().Error().Err(err).Msg("Failed to clean cache") } }).LFU().Expiration(time.Millisecond * time.Duration(cfg.TransactionTTLMilliseconds)).Build() @@ -231,7 +206,7 @@ func (s *SPOA) getApplication(appName string) (*application, error) { // Looking for app by default app name app, exist := s.applications[s.defaultApplication] if exist { - app.logger.Debug("application not found, using default", zap.Any("application", appName), zap.String("default", s.defaultApplication)) + log.Debug().Str("application", appName).Str("default app", s.defaultApplication).Msg("Application not found, using default") return app, nil } @@ -253,7 +228,7 @@ func (s *SPOA) processRequest(spoeMsg *spoe.Message) ([]spoe.Action, error) { if tx.IsInterrupted() { tx.ProcessLogging() if err := tx.Close(); err != nil { - app.logger.Error("failed to close transaction", zap.String("transaction_id", tx.ID()), zap.String("error", err.Error())) + tx.DebugLogger().Error().Err(err).Str("transaction_id", tx.ID()).Msg("Failed to close transaction") } } else { if app.cfg.NoResponseCheck { @@ -261,35 +236,35 @@ func (s *SPOA) processRequest(spoeMsg *spoe.Message) ([]spoe.Action, error) { } err := app.cache.SetWithExpire(tx.ID(), tx, time.Millisecond*time.Duration(app.cfg.TransactionTTLMilliseconds)) if err != nil { - app.logger.Error(fmt.Sprintf("failed to cache transaction: %s", err.Error())) + log.Error().Err(err).Msg("failed to cache transaction") } } }() req, err = NewRequest(spoeMsg) if err != nil { - return nil, err + return s.badRequestError(err), nil } app, err = s.getApplication(req.app) if err != nil { - return nil, err + return s.badRequestError(err), nil } tx = app.waf.NewTransactionWithID(req.id) if tx.IsRuleEngineOff() { - app.logger.Warn("Rule engine is Off, Coraza is not going to process any rule") + log.Warn().Msg("Rule engine is Off, Coraza is not going to process any rule") return s.allowAction(), nil } err = req.init() if err != nil { - return nil, err + return s.badRequestError(err), nil } headers, err := s.readHeaders(req.headers) if err != nil { - return nil, err + return s.badRequestError(err), nil } for key, values := range headers { for _, v := range values { @@ -299,7 +274,8 @@ func (s *SPOA) processRequest(spoeMsg *spoe.Message) ([]spoe.Action, error) { it, _, err := tx.WriteRequestBody(req.body) if err != nil { - return nil, err + tx.DebugLogger().Error().Err(err).Str("transaction_id", tx.ID()).Msg("Failed to write request body") + return s.processRequestError(err), nil } if it != nil { return s.processInterruption(it), nil @@ -315,7 +291,8 @@ func (s *SPOA) processRequest(spoeMsg *spoe.Message) ([]spoe.Action, error) { it, err = tx.ProcessRequestBody() if err != nil { - return nil, err + tx.DebugLogger().Error().Err(err).Str("transaction_id", tx.ID()).Msg("Failed to process request body") + return s.processRequestError(err), nil } if it != nil { return s.processInterruption(it), nil @@ -337,12 +314,12 @@ func (s *SPOA) processResponse(spoeMsg *spoe.Message) ([]spoe.Action, error) { resp, err = NewResponse(spoeMsg) if err != nil { - return nil, err + return s.badResponseError(err), nil } app, err = s.getApplication(resp.app) if err != nil { - return nil, err + return s.badResponseError(err), nil } txInterface, err := app.cache.Get(resp.id) @@ -356,12 +333,12 @@ func (s *SPOA) processResponse(spoeMsg *spoe.Message) ([]spoe.Action, error) { err = resp.init() if err != nil { - return nil, err + return s.badResponseError(err), nil } headers, err := s.readHeaders(resp.headers) if err != nil { - return nil, err + return s.badResponseError(err), nil } for key, values := range headers { for _, v := range values { @@ -371,7 +348,8 @@ func (s *SPOA) processResponse(spoeMsg *spoe.Message) ([]spoe.Action, error) { it, _, err := tx.WriteResponseBody(resp.body) if err != nil { - return nil, err + tx.DebugLogger().Error().Err(err).Str("transaction_id", tx.ID()).Msg("Failed to write response body") + return s.processResponseError(err), nil } if it != nil { return s.processInterruption(it), nil @@ -384,7 +362,8 @@ func (s *SPOA) processResponse(spoeMsg *spoe.Message) ([]spoe.Action, error) { it, err = tx.ProcessResponseBody() if err != nil { - return nil, err + tx.DebugLogger().Error().Err(err).Str("transaction_id", tx.ID()).Msg("Failed to process response body") + return s.processResponseError(err), nil } if it != nil { return s.processInterruption(it), nil diff --git a/log/log.go b/log/log.go new file mode 100644 index 0000000..a0a63a1 --- /dev/null +++ b/log/log.go @@ -0,0 +1,130 @@ +// Copyright The OWASP Coraza contributors +// SPDX-License-Identifier: Apache-2.0 + +package log + +import ( + "io" + "os" + + "github.com/corazawaf/coraza/v3/types" + "github.com/rs/zerolog" + spoelog "github.com/sirupsen/logrus" +) + +var Logger = zerolog.New(os.Stderr).Level(zerolog.InfoLevel).With().Timestamp().Logger() + +var WafErrorCallback = func(mr types.MatchedRule) { + Logger. + WithLevel(convert(mr.Rule().Severity())). + Msg(mr.ErrorLog()) +} + +// InitLogging initializes the logging. +func InitLogging(file, level, spoeLevel string) { + if level == "" && file == "" { + Debug().Msg("Nothing to configure, using standard logger") + return + } + + logger := Logger + + if file != "" { + out, err := resolveLogPath(file) + if err != nil { + Error().Err(err).Msg("Can't open log file, using standard") + } else { + logger = logger.Output(out) + } + } + + currentLevel := Logger.GetLevel() + targetLevel, err := zerolog.ParseLevel(level) + if err != nil { + Error().Err(err).Msgf("Can't parse log level, using '%v' log level", currentLevel) + + } else if targetLevel < currentLevel { + Debug().Msgf("Setting up '%v' log level", targetLevel) + logger = logger.Level(targetLevel) + } + + Logger = logger + + // Setting up criteo/haproxy-spoe-go logging + currentSpoeLevel := spoelog.GetLevel() + targetSpoeLevel, err := spoelog.ParseLevel(spoeLevel) + if err != nil { + Error().Err(err).Msgf("Can't parse SPOE log level, using '%v' log level", currentSpoeLevel) + + } else { + Debug().Msgf("Setting up '%v' SPOE log level", targetSpoeLevel) + spoelog.SetLevel(targetSpoeLevel) + } +} + +func SetDebug(debug bool) { + if debug && Logger.GetLevel() != zerolog.DebugLevel { + Logger = Logger.Level(zerolog.DebugLevel) + Debug().Msgf("Using '%v' log level", zerolog.DebugLevel) + } +} + +func Trace() *zerolog.Event { + return Logger.Trace() +} + +func Debug() *zerolog.Event { + return Logger.Debug() +} + +func Info() *zerolog.Event { + return Logger.Info() +} + +func Warn() *zerolog.Event { + return Logger.Warn() +} + +func Error() *zerolog.Event { + return Logger.Error() +} + +func Fatal() *zerolog.Event { + return Logger.Fatal() +} +func Panic() *zerolog.Event { + return Logger.Panic() +} + +func resolveLogPath(path string) (io.Writer, error) { + switch path { + case "": + return io.Discard, nil + + case "/dev/stdout": + return os.Stdout, nil + + case "/dev/stderr": + return os.Stderr, nil + + default: + return os.OpenFile(path, os.O_RDWR|os.O_CREATE|os.O_APPEND, 0666) + } +} + +func convert(severity types.RuleSeverity) zerolog.Level { + switch severity { + case types.RuleSeverityEmergency, types.RuleSeverityAlert, types.RuleSeverityCritical, types.RuleSeverityError: + return zerolog.ErrorLevel + + case types.RuleSeverityWarning: + return zerolog.WarnLevel + + case types.RuleSeverityNotice, types.RuleSeverityInfo: + return zerolog.InfoLevel + + case types.RuleSeverityDebug: + return zerolog.DebugLevel + } + return zerolog.Disabled +}