Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

T864 - Separate log file for unparsed queries #295

Merged
merged 16 commits into from
Dec 27, 2018
13 changes: 12 additions & 1 deletion acra-censor/acra-censor_configuration_provider.go
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,7 @@ package acracensor
import (
"github.com/cossacklabs/acra/acra-censor/handlers"
"gopkg.in/yaml.v2"
"os"
"strings"
)

Expand All @@ -39,7 +40,8 @@ type Config struct {
Patterns []string
Filepath string
}
IgnoreParseError bool `yaml:"ignore_parse_error"`
IgnoreParseError bool `yaml:"ignore_parse_error"`
ParseErrorsLog string `yaml:"parse_errors_log"`
}

// LoadConfiguration loads configuration of AcraCensor
Expand All @@ -50,6 +52,15 @@ func (acraCensor *AcraCensor) LoadConfiguration(configuration []byte) error {
return err
}
acraCensor.ignoreParseError = censorConfiguration.IgnoreParseError
acraCensor.parseErrorsLogPath = censorConfiguration.ParseErrorsLog
if acraCensor.parseErrorsLogPath != "" {
openedFile, err := os.OpenFile(acraCensor.parseErrorsLogPath, os.O_APPEND|os.O_RDWR|os.O_CREATE, 0600)
if err != nil {
return err
}
defer openedFile.Close()
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

if we doesn't use this file after creation we can close it here without defer. but better to store file descriptor as censor field to avoid opening every write operation and reduce count of syscalls (open/close)

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

When and where should I close it is such case when acraserver stops?

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

just here) openedFile.Close() instead defer openedFile.Close() because this file doesn't used anywhere after creation. As I understand here we just create file and check that we can do this and close it before next write.
But if we will store opened file in censor then we don't need .Close() here even with defer

}

for _, handlerConfiguration := range censorConfiguration.Handlers {
switch handlerConfiguration.Handler {
case WhitelistConfigStr:
Expand Down
32 changes: 29 additions & 3 deletions acra-censor/acra-censor_implementation.go
Original file line number Diff line number Diff line change
Expand Up @@ -20,23 +20,26 @@ import (
"github.com/cossacklabs/acra/acra-censor/common"
"github.com/cossacklabs/acra/acra-censor/handlers"
log "github.com/sirupsen/logrus"
"os"
)

// ServiceName to use in logs
const ServiceName = "acra-censor"

// AcraCensor describes censor data: query handler, logger and reaction on parsing errors.
type AcraCensor struct {
handlers []QueryHandlerInterface
ignoreParseError bool
logger *log.Entry
handlers []QueryHandlerInterface
ignoreParseError bool
parseErrorsLogPath string
logger *log.Entry
}

// NewAcraCensor creates new censor object.
func NewAcraCensor() *AcraCensor {
acraCensor := &AcraCensor{}
acraCensor.logger = log.WithField("service", ServiceName)
acraCensor.ignoreParseError = false
acraCensor.parseErrorsLogPath = ""
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

we don't need such initialization because it's already initialized with empty string. Above assigning is redundant too

return acraCensor
}

Expand Down Expand Up @@ -72,6 +75,13 @@ func (acraCensor *AcraCensor) HandleQuery(rawQuery string) error {
normalizedQuery, queryWithHiddenValues, parsedQuery, err := common.HandleRawSQLQuery(rawQuery)
if err == common.ErrQuerySyntaxError {
acraCensor.logger.WithError(err).Warning("Failed to parse input query")
if acraCensor.parseErrorsLogPath != "" {
err := acraCensor.saveQuery(rawQuery)
if err != nil {
acraCensor.logger.WithError(err).Errorf("An error occurred while saving unparsable query")
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

use Errorln to append '\n' at end of log msg. Errorf useful to create msg with some format of string

return err
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think if censor configured with acracensor.ignoreParseError then we should not stop processing on error related with unparsed query and enough log error and try to save without stopping processing.

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@vixentael what you think about this?

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

agree, if acracensor.ignoreParseError is true, then log error and move forward

}
}
if acraCensor.ignoreParseError {
acraCensor.logger.Infof("Unparsed query has been allowed")
return nil
Expand Down Expand Up @@ -110,3 +120,19 @@ func (acraCensor *AcraCensor) HandleQuery(rawQuery string) error {
acraCensor.logger.Infof("Allowed query: '%s'", queryWithHiddenValues)
return nil
}

func (acraCensor *AcraCensor) saveQuery(rawQuery string) error {
openedFile, err := os.OpenFile(acraCensor.parseErrorsLogPath, os.O_APPEND|os.O_RDWR|os.O_CREATE, 0600)
if err != nil {
return err
}

defer openedFile.Close()

_, err = openedFile.WriteString(rawQuery + "\n")
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

here we will have same problem which we had with querycapture handler where we try to buffer data before dumping to file to avoid slow write on each query. here we will have same problem with situation when client will use not supported queries. plus we don't need repeated queries, only unique. maybe would be good to write some QueryWriter (and use in querycapture if we can to avoid duplicated code) which will do this logic with buffered write and timeouts and store unique queries in memory to avoid repeated queries

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ok, I will write additional handler for this (with functionality like QueryCapture)

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

agree, it makes sense to allocate same functionality into some object lke QueryWriter and use it for both QueryCapture and here

if err != nil {
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

return err enough imho :)

plus better to use opened file on loading configuration and use it to avoid open/close on every save

return err
}

return nil
}
79 changes: 78 additions & 1 deletion acra-censor/acra-censor_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -23,6 +23,7 @@ limitations under the License.
package acracensor

import (
"bufio"
"github.com/cossacklabs/acra/acra-censor/common"
"io/ioutil"
"os"
Expand Down Expand Up @@ -1734,6 +1735,10 @@ func TestConfigurationProvider(t *testing.T) {
if err != nil {
t.Fatal(err)
}
err = os.Remove("unparsed_queries_log")
if err != nil {
t.Fatal(err)
}
}()
err = acraCensor.LoadConfiguration(configuration)
if err != nil {
Expand Down Expand Up @@ -1771,13 +1776,14 @@ func TestConfigurationProvider(t *testing.T) {
"SELECT EMP_ID, LAST_NAME FROM EMPLOYEE WHERE CITY = 'Seattle' ORDER BY EMP_ID;",
//"SELECT EMP_ID, LAST_NAME FROM EMPLOYEE AS EMPL WHERE CITY = 'Seattle' ORDER BY EMP_ID;",
}
//acracensor should block those structures
//acracensor should block those queries by pattern
for _, queryToBlock := range testQueries {
err = acraCensor.HandleQuery(queryToBlock)
if err != common.ErrBlacklistPatternMatch {
t.Fatal(err)
}
}

for _, currentHandler := range acraCensor.handlers {
original, ok := currentHandler.(*handlers.QueryCaptureHandler)
if ok {
Expand Down Expand Up @@ -1894,3 +1900,74 @@ func TestIgnoringQueryParseErrors(t *testing.T) {
// check when censor with two handlers and each one will return query parse error
checkHandler([]QueryHandlerInterface{whitelist, blacklist}, nil)
}
func TestLogUnparsedQueries(t *testing.T) {
var err error

configuration := `ignore_parse_error: true
parse_errors_log: unparsed_queries_log
handlers:
- handler: query_capture
filepath: censor_log
- handler: query_ignore
queries:
- ROLLBACK
- COMMIT
- BEGIN
- handler: blacklist
queries:
- INSERT INTO SalesStaff1 VALUES (1, 'Stephen', 'Jiang');
- SELECT AVG(Price) FROM Products;
tables:
- EMPLOYEE_TBL
- Customers
patterns:
- SELECT EMP_ID, LAST_NAME FROM EMPLOYEE %%WHERE%%;`

acraCensor := NewAcraCensor()
defer func() {
acraCensor.ReleaseAll()
err = os.Remove("censor_log")
if err != nil {
t.Fatal(err)
}
err = os.Remove("unparsed_queries_log")
if err != nil {
t.Fatal(err)
}
}()
err = acraCensor.LoadConfiguration([]byte(configuration))
if err != nil {
t.Fatal(err)
}

testQueries := []string{
"select * from x )))(((unparsable query",
"qwerty",
}

for _, query := range testQueries {
err = acraCensor.HandleQuery(query)
if err != nil {
t.Fatal(err)
}
}

file, err := os.Open("unparsed_queries_log")
if err != nil {
t.Fatal(err)
}
defer file.Close()

i := 0
scanner := bufio.NewScanner(file)
for scanner.Scan() {
if scanner.Text() != testQueries[i] {
t.Fatal("Scanned: " + scanner.Text() + ", expected: " + testQueries[i])
}
i++
}

if err := scanner.Err(); err != nil {
t.Fatal(err)
}
}
1 change: 1 addition & 0 deletions configs/acra-censor.example.yaml
Original file line number Diff line number Diff line change
@@ -1,4 +1,5 @@
ignore_parse_error: false
parse_errors_log: unparsed_queries_log
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

what about uparsed_queries.log name? to add some common extension to avoid meaning some binary file without extension on linux

handlers:
- handler: query_capture
filepath: censor_log
Expand Down