github.com/honeycombio/honeytail@v1.9.0/leash_test.go (about) 1 package main 2 3 import ( 4 "bytes" 5 "compress/gzip" 6 "context" 7 "encoding/json" 8 "fmt" 9 "io" 10 "io/ioutil" 11 "log" 12 "math/rand" 13 "net/http" 14 "net/http/httptest" 15 "os" 16 "os/exec" 17 "sync" 18 "syscall" 19 "testing" 20 "time" 21 22 "github.com/honeycombio/honeytail/parsers/htjson" 23 24 "github.com/klauspost/compress/zstd" 25 "github.com/sirupsen/logrus" 26 "github.com/stretchr/testify/assert" 27 "golang.org/x/sys/unix" 28 29 "github.com/honeycombio/honeytail/event" 30 "github.com/honeycombio/honeytail/tail" 31 ) 32 33 var tailOptions = tail.TailOptions{ 34 ReadFrom: "start", 35 Stop: true, 36 } 37 38 // defaultOptions is a fully populated GlobalOptions with good defaults to start from 39 var defaultOptions = GlobalOptions{ 40 // each test will have to populate APIHost with the location of its test server 41 APIHost: "", 42 SampleRate: 1, 43 NumSenders: 1, 44 BatchFrequencyMs: 1000, // Longer batch sends to accommodate for slower CI machines 45 Reqs: RequiredOptions{ 46 // using the json parser for everything because we're not testing parsers here. 47 ParserName: "json", 48 WriteKey: "abcabc123123", 49 // each test will specify its own logfile 50 // LogFiles: []string{tmpdir + ""}, 51 Dataset: "pika", 52 }, 53 Tail: tailOptions, 54 StatusInterval: 1, 55 } 56 57 // test testing framework 58 func TestHTTPtest(t *testing.T) { 59 ts := &testSetup{} 60 ts.start(t, &GlobalOptions{}) 61 defer ts.close() 62 ts.rsp.responseBody = "whatup pikachu" 63 res, err := http.Get(ts.server.URL) 64 if err != nil { 65 log.Fatal(err) 66 } 67 greeting, err := ioutil.ReadAll(res.Body) 68 res.Body.Close() 69 if err != nil { 70 log.Fatal(err) 71 } 72 assert.Equal(t, res.StatusCode, 200) 73 assert.Equal(t, string(greeting), "whatup pikachu") 74 assert.Equal(t, ts.rsp.reqCounter, 1) 75 } 76 77 func TestBasicSend(t *testing.T) { 78 opts := defaultOptions 79 ts := &testSetup{} 80 ts.start(t, &opts) 81 defer ts.close() 82 logFileName := ts.tmpdir + "/first.log" 83 fh, err := os.Create(logFileName) 84 if err != nil { 85 t.Fatal(err) 86 } 87 defer fh.Close() 88 fmt.Fprintf(fh, `{"format":"json"}`) 89 opts.Reqs.LogFiles = []string{logFileName} 90 run(context.Background(), opts) 91 assert.Equal(t, ts.rsp.reqCounter, 1) 92 assert.Equal(t, ts.rsp.evtCounter, 1) 93 assert.Contains(t, ts.rsp.reqBody, `{"format":"json"}`) 94 teamID := ts.rsp.req.Header.Get("X-Honeycomb-Team") 95 assert.Equal(t, teamID, "abcabc123123") 96 requestURL := ts.rsp.req.URL.Path 97 assert.Equal(t, requestURL, "/1/batch/pika") 98 } 99 100 func TestMultipleFiles(t *testing.T) { 101 opts := defaultOptions 102 ts := &testSetup{} 103 ts.start(t, &opts) 104 defer ts.close() 105 logFile1 := ts.tmpdir + "/first.log" 106 fh1, err := os.Create(logFile1) 107 if err != nil { 108 t.Fatal(err) 109 } 110 logFile2 := ts.tmpdir + "/second.log" 111 fh2, err := os.Create(logFile2) 112 if err != nil { 113 t.Fatal(err) 114 } 115 defer fh1.Close() 116 fmt.Fprintf(fh1, `{"key1":"val1"}`) 117 defer fh2.Close() 118 fmt.Fprintf(fh2, `{"key2":"val2"}`) 119 opts.Reqs.LogFiles = []string{logFile1, logFile2} 120 run(context.Background(), opts) 121 assert.Equal(t, ts.rsp.reqCounter, 1) 122 assert.Equal(t, ts.rsp.evtCounter, 2) 123 assert.Contains(t, ts.rsp.reqBody, `{"key1":"val1"}`) 124 assert.Contains(t, ts.rsp.reqBody, `{"key2":"val2"}`) 125 teamID := ts.rsp.req.Header.Get("X-Honeycomb-Team") 126 assert.Equal(t, teamID, "abcabc123123") 127 requestURL := ts.rsp.req.URL.Path 128 assert.Equal(t, requestURL, "/1/batch/pika") 129 } 130 131 func TestMultiLineMultiFile(t *testing.T) { 132 opts := GlobalOptions{ 133 NumSenders: 1, 134 Reqs: RequiredOptions{ 135 ParserName: "mysql", 136 WriteKey: "----", 137 Dataset: "---", 138 }, 139 Tail: tailOptions, 140 } 141 ts := &testSetup{} 142 ts.start(t, &opts) 143 defer ts.close() 144 logFile1 := ts.tmpdir + "/first.log" 145 fh1, err := os.Create(logFile1) 146 if err != nil { 147 t.Fatal(err) 148 } 149 fmt.Fprintf(fh1, `# Time: 2016-04-01T00:29:09.817887Z", 150 # administrator command: Close stmt; 151 # User@Host: root[root] @ [10.0.72.76] Id: 432399 152 # Query_time: 0.000114 Lock_time: 0.000000 Rows_sent: 0 Rows_examined: 0 153 SET timestamp=1459470669; 154 SELECT * 155 FROM orders WHERE 156 total > 1000; 157 # Time: 2016-04-01T00:31:09.817887Z 158 SET timestamp=1459470669; 159 show status like 'Uptime';`) 160 logFile2 := ts.tmpdir + "/second.log" 161 fh2, err := os.Create(logFile2) 162 if err != nil { 163 t.Fatal(err) 164 } 165 fmt.Fprintf(fh2, `# User@Host: rails[rails] @ [10.252.9.33] 166 # Query_time: 0.002280 Lock_time: 0.000023 Rows_sent: 0 Rows_examined: 921 167 SET timestamp=1444264264; 168 SELECT certs.* FROM certs WHERE (certs.app_id = 993089) LIMIT 1; 169 # administrator command: Prepare; 170 # User@Host: root[root] @ [10.0.99.122] Id: 432407 171 # Query_time: 0.000122 Lock_time: 0.000033 Rows_sent: 1 Rows_examined: 1 172 SET timestamp=1476702000; 173 SELECT 174 id, team_id, name, description, slug, limit_kb, created_at, updated_at 175 FROM datasets WHERE team_id=17 AND slug='api-prod';`) 176 opts.Reqs.LogFiles = []string{logFile1, logFile2} 177 run(context.Background(), opts) 178 assert.Equal(t, ts.rsp.reqCounter, 1) 179 assert.Equal(t, ts.rsp.evtCounter, 4) 180 assert.Contains(t, ts.rsp.reqBody, `"query":"SELECT * FROM orders`) 181 assert.Contains(t, ts.rsp.reqBody, `"tables":"orders"`) 182 assert.Contains(t, ts.rsp.reqBody, `"query":"show status like 'Uptime'`) 183 assert.Contains(t, ts.rsp.reqBody, `"query":"SELECT certs.* FROM`) 184 assert.Contains(t, ts.rsp.reqBody, `"tables":"certs"`) 185 assert.Contains(t, ts.rsp.reqBody, `"query":"SELECT id, team_id, name`) 186 assert.Contains(t, ts.rsp.reqBody, `"tables":"datasets"`) 187 } 188 189 func TestSetVersion(t *testing.T) { 190 opts := defaultOptions 191 ts := &testSetup{} 192 ts.start(t, &opts) 193 defer ts.close() 194 logFileName := ts.tmpdir + "/setv.log" 195 fh, _ := os.Create(logFileName) 196 defer fh.Close() 197 fmt.Fprintf(fh, `{"format":"json"}`) 198 opts.Reqs.LogFiles = []string{logFileName} 199 run(context.Background(), opts) 200 userAgent := ts.rsp.req.Header.Get("User-Agent") 201 assert.Contains(t, userAgent, "libhoney-go") 202 setVersionUserAgent(false, "fancyParser") 203 run(context.Background(), opts) 204 userAgent = ts.rsp.req.Header.Get("User-Agent") 205 assert.Contains(t, userAgent, "libhoney-go") 206 assert.Contains(t, userAgent, "fancyParser") 207 BuildID = "test" 208 setVersionUserAgent(false, "fancyParser") 209 run(context.Background(), opts) 210 userAgent = ts.rsp.req.Header.Get("User-Agent") 211 assert.Contains(t, userAgent, " honeytail/test") 212 setVersionUserAgent(true, "fancyParser") 213 run(context.Background(), opts) 214 userAgent = ts.rsp.req.Header.Get("User-Agent") 215 assert.Contains(t, userAgent, " honeytail/test") 216 assert.Contains(t, userAgent, "fancyParser backfill") 217 } 218 219 func TestAugmentField(t *testing.T) { 220 opts := defaultOptions 221 ts := &testSetup{} 222 ts.start(t, &opts) 223 defer ts.close() 224 logFileName := ts.tmpdir + "/augment.log" 225 logfh, _ := os.Create(logFileName) 226 defer logfh.Close() 227 damapFileName := ts.tmpdir + "/damap.json" 228 damapfh, _ := os.Create(damapFileName) 229 defer damapfh.Close() 230 fmt.Fprintf(logfh, `{"format":"json"} 231 {"format":"freetext"} 232 {"format":"csv","delimiter":"comma"}`) 233 fmt.Fprintf(damapfh, `{"format":{ 234 "json":{"structured":true}, 235 "freetext":{"structured":false,"annoyance":5} 236 }, 237 "color":{ 238 "red":{"nomatch":"wontappear"} 239 } 240 }`) 241 opts.Reqs.LogFiles = []string{logFileName} 242 opts.DAMapFile = damapFileName 243 run(context.Background(), opts) 244 assert.Equal(t, ts.rsp.reqCounter, 1, "failed count") 245 // json should be identified as structured 246 assert.Contains(t, ts.rsp.reqBody, `{"format":"json","structured":true}`, "faild content") 247 // free text gets two additional fields 248 assert.Contains(t, ts.rsp.reqBody, `{"annoyance":5,"format":"freetext","structured":false}`, "faild content") 249 // csv doesn't exist in the damap, so no change 250 assert.Contains(t, ts.rsp.reqBody, `{"delimiter":"comma","format":"csv"}`, "faild content") 251 } 252 253 func TestDropField(t *testing.T) { 254 opts := defaultOptions 255 ts := &testSetup{} 256 ts.start(t, &opts) 257 defer ts.close() 258 logFileName := ts.tmpdir + "/drop.log" 259 fh, _ := os.Create(logFileName) 260 defer fh.Close() 261 fmt.Fprintf(fh, `{"dropme":"chew","format":"json","reallygone":"notyet"}`) 262 opts.Reqs.LogFiles = []string{logFileName} 263 run(context.Background(), opts) 264 assert.Equal(t, ts.rsp.reqCounter, 1) 265 assert.Contains(t, ts.rsp.reqBody, `{"dropme":"chew","format":"json","reallygone":"notyet"}`) 266 opts.DropFields = []string{"dropme"} 267 run(context.Background(), opts) 268 assert.Equal(t, ts.rsp.reqCounter, 2) 269 assert.Contains(t, ts.rsp.reqBody, `{"format":"json","reallygone":"notyet"}`) 270 opts.DropFields = []string{"dropme", "reallygone"} 271 run(context.Background(), opts) 272 assert.Equal(t, ts.rsp.reqCounter, 3) 273 assert.Contains(t, ts.rsp.reqBody, `{"format":"json"}`) 274 } 275 276 func TestScrubField(t *testing.T) { 277 opts := defaultOptions 278 ts := &testSetup{} 279 ts.start(t, &opts) 280 defer ts.close() 281 logFileName := ts.tmpdir + "/scrub.log" 282 fh, _ := os.Create(logFileName) 283 defer fh.Close() 284 fmt.Fprintf(fh, `{"format":"json","name":"hidden"}`) 285 opts.Reqs.LogFiles = []string{logFileName} 286 opts.ScrubFields = []string{"name"} 287 run(context.Background(), opts) 288 assert.Equal(t, ts.rsp.reqCounter, 1) 289 assert.Contains(t, ts.rsp.reqBody, `{"format":"json","name":"e564b4081d7a9ea4b00dada53bdae70c99b87b6fce869f0c3dd4d2bfa1e53e1c"}`) 290 } 291 292 func TestAddField(t *testing.T) { 293 opts := defaultOptions 294 ts := &testSetup{} 295 ts.start(t, &opts) 296 defer ts.close() 297 logFileName := ts.tmpdir + "/add.log" 298 logfh, _ := os.Create(logFileName) 299 defer logfh.Close() 300 fmt.Fprintf(logfh, `{"format":"json"}`) 301 opts.Reqs.LogFiles = []string{logFileName} 302 opts.AddFields = []string{`newfield=newval`} 303 run(context.Background(), opts) 304 assert.Contains(t, ts.rsp.reqBody, `{"format":"json","newfield":"newval"}`) 305 opts.AddFields = []string{"newfield=newval", "second=new"} 306 run(context.Background(), opts) 307 assert.Contains(t, ts.rsp.reqBody, `{"format":"json","newfield":"newval","second":"new"}`) 308 } 309 310 func TestLinePrefix(t *testing.T) { 311 opts := defaultOptions 312 // linePrefix of "Nov 13 10:19:31 app23 process.port[pid]: " 313 // let's capture timestamp and hostname, skip process.port and pid 314 opts.PrefixRegex = `(?P<server_timestamp>... .. ..:..:..) (?P<hostname>[a-zA-Z0-9]+) [^:]*: ` 315 ts := &testSetup{} 316 ts.start(t, &opts) 317 defer ts.close() 318 logFileName := ts.tmpdir + "/linePrefix.log" 319 logfh, _ := os.Create(logFileName) 320 defer logfh.Close() 321 fmt.Fprintf(logfh, `Nov 13 10:19:31 app23 process.port[pid]: {"format":"json"}`) 322 opts.Reqs.LogFiles = []string{logFileName} 323 run(context.Background(), opts) 324 assert.Contains(t, ts.rsp.reqBody, `{"format":"json","hostname":"app23","server_timestamp":"Nov 13 10:19:31"}`) 325 } 326 327 func TestRequestShapeRaw(t *testing.T) { 328 reqField := "request" 329 opts := defaultOptions 330 opts.RequestShape = []string{"request"} 331 opts.RequestPattern = []string{"/about", "/about/:lang", "/about/:lang/books"} 332 urlsWhitelistQuery := map[string]map[string]interface{}{ 333 "GET /about/en/books HTTP/1.1": { 334 "request_method": "GET", 335 "request_protocol_version": "HTTP/1.1", 336 "request_uri": "/about/en/books", 337 "request_path": "/about/en/books", 338 "request_query": nil, // field missing instead of empty 339 "request_path_lang": "en", 340 "request_shape": "/about/:lang/books", 341 "request_pathshape": "/about/:lang/books", 342 "request_queryshape": nil, // field missing instead of empty 343 }, 344 "GET /about?foo=bar HTTP/1.0": { 345 "request_method": "GET", 346 "request_protocol_version": "HTTP/1.0", 347 "request_uri": "/about?foo=bar", 348 "request_path": "/about", 349 "request_query": "foo=bar", 350 "request_query_foo": "bar", 351 "request_shape": "/about?foo=?", 352 "request_pathshape": "/about", 353 "request_queryshape": "foo=?", 354 }, 355 "/about/en/books": { 356 "request_uri": "/about/en/books", 357 "request_path": "/about/en/books", 358 "request_query": nil, // field missing instead of empty 359 "request_path_lang": "en", 360 "request_shape": "/about/:lang/books", 361 "request_pathshape": "/about/:lang/books", 362 "request_queryshape": nil, // field missing instead of empty 363 }, 364 "/about/en?foo=bar&bar=bar2": { 365 "request_uri": "/about/en?foo=bar&bar=bar2", 366 "request_path": "/about/en", 367 "request_query": "foo=bar&bar=bar2", 368 "request_query_foo": "bar", 369 "request_path_lang": "en", 370 "request_shape": "/about/:lang?bar=?&foo=?", 371 "request_pathshape": "/about/:lang", 372 "request_queryshape": "bar=?&foo=?", 373 }, 374 "/about/en?foo=bar&baz&foo=bend&foo=alpha&bend=beta": { 375 "request_uri": "/about/en?foo=bar&baz&foo=bend&foo=alpha&bend=beta", 376 "request_path": "/about/en", 377 "request_query": "foo=bar&baz&foo=bend&foo=alpha&bend=beta", 378 "request_query_foo": "alpha, bar, bend", 379 "request_query_bend": "beta", 380 "request_path_lang": "en", 381 "request_shape": "/about/:lang?baz=?&bend=?&foo=?&foo=?&foo=?", 382 "request_pathshape": "/about/:lang", 383 "request_queryshape": "baz=?&bend=?&foo=?&foo=?&foo=?", 384 }, 385 } 386 urlsAllQuery := map[string]map[string]interface{}{ 387 "/about/en?foo=bar&bar=bar2": { 388 "request_uri": "/about/en?foo=bar&bar=bar2", 389 "request_path": "/about/en", 390 "request_query": "foo=bar&bar=bar2", 391 "request_query_foo": "bar", 392 "request_query_bar": "bar2", 393 "request_path_lang": "en", 394 "request_shape": "/about/:lang?bar=?&foo=?", 395 "request_pathshape": "/about/:lang", 396 "request_queryshape": "bar=?&foo=?", 397 }, 398 } 399 // test whitelisting keys foo, baz, and bend but not bar 400 opts.RequestQueryKeys = []string{"foo", "baz", "bend"} 401 tbs := make(chan event.Event) 402 output := modifyEventContents(tbs, opts) 403 for input, expectedResult := range urlsWhitelistQuery { 404 ev := event.Event{ 405 Data: map[string]interface{}{ 406 reqField: input, 407 }, 408 } 409 // feed it the sample event 410 tbs <- ev 411 // get the munged event out 412 res := <-output 413 for evKey, expectedVal := range expectedResult { 414 assert.Equal(t, res.Data[evKey], expectedVal) 415 } 416 } 417 close(tbs) 418 419 // change the query parsing rules and get a new output channel - bar should be 420 // included 421 opts.RequestParseQuery = "all" 422 tbs = make(chan event.Event) 423 output = modifyEventContents(tbs, opts) 424 for input, expectedResult := range urlsAllQuery { 425 ev := event.Event{ 426 Data: map[string]interface{}{ 427 reqField: input, 428 }, 429 } 430 // feed it the sample event 431 tbs <- ev 432 // get the munged event out 433 res := <-output 434 for evKey, expectedVal := range expectedResult { 435 assert.Equal(t, res.Data[evKey], expectedVal) 436 } 437 } 438 close(tbs) 439 } 440 441 func TestSampleRate(t *testing.T) { 442 opts := defaultOptions 443 ts := &testSetup{} 444 ts.start(t, &opts) 445 defer ts.close() 446 rand.Seed(1) 447 sampleLogFile := ts.tmpdir + "/sample.log" 448 logfh, _ := os.Create(sampleLogFile) 449 defer logfh.Close() 450 for i := 0; i < 50; i++ { 451 fmt.Fprintf(logfh, `{"format":"json%d"}`+"\n", i) 452 } 453 opts.Reqs.LogFiles = []string{sampleLogFile} 454 opts.TailSample = false 455 456 run(context.Background(), opts) 457 // with no sampling, 50 lines -> 50 events 458 assert.Equal(t, ts.rsp.evtCounter, 50) 459 assert.Contains(t, ts.rsp.reqBody, `{"format":"json49"}`) 460 ts.rsp.reset() 461 462 opts.SampleRate = 3 463 opts.TailSample = true 464 run(context.Background(), opts) 465 // setting a sample rate of 3 gets 17 requests. 466 // tail does the sampling 467 assert.Equal(t, ts.rsp.evtCounter, 17) 468 assert.Contains(t, ts.rsp.reqBody, `{"format":"json49"},"samplerate":3,`) 469 } 470 471 func TestReadFromOffset(t *testing.T) { 472 opts := defaultOptions 473 ts := &testSetup{} 474 ts.start(t, &opts) 475 defer ts.close() 476 offsetLogFile := ts.tmpdir + "/offset.log" 477 offsetStateFile := ts.tmpdir + "/offset.leash.state" 478 logfh, _ := os.Create(offsetLogFile) 479 defer logfh.Close() 480 logStat := unix.Stat_t{} 481 unix.Stat(offsetLogFile, &logStat) 482 for i := 0; i < 10; i++ { 483 fmt.Fprintf(logfh, `{"format":"json%d"}`+"\n", i) 484 } 485 opts.Reqs.LogFiles = []string{offsetLogFile} 486 opts.Tail.ReadFrom = "last" 487 opts.Tail.StateFile = offsetStateFile 488 osf, _ := os.Create(offsetStateFile) 489 defer osf.Close() 490 fmt.Fprintf(osf, `{"INode":%d,"Offset":38}`, logStat.Ino) 491 run(context.Background(), opts) 492 assert.Equal(t, ts.rsp.reqCounter, 1) 493 assert.Equal(t, ts.rsp.evtCounter, 8) 494 } 495 496 // TestLogRotation tests that honeytail continues tailing after log rotation, 497 // with different possible configurations: 498 // * when honeytail polls or uses inotify 499 // * when logs are rotated using rename/reopen, or using copy/truncate. 500 func TestLogRotation(t *testing.T) { 501 for _, poll := range []bool{true, false} { 502 for _, copyTruncate := range []bool{true, false} { 503 t.Run(fmt.Sprintf("polling: %t; copyTruncate: %t", poll, copyTruncate), func(t *testing.T) { 504 wg := &sync.WaitGroup{} 505 opts := defaultOptions 506 opts.BatchFrequencyMs = 1 507 opts.Tail.Stop = false 508 opts.Tail.Poll = poll 509 ts := &testSetup{} 510 ts.start(t, &opts) 511 defer ts.close() 512 logFileName := ts.tmpdir + "/test.log" 513 fh, err := os.Create(logFileName) 514 if err != nil { 515 t.Fatal(err) 516 } 517 opts.Reqs.LogFiles = []string{logFileName} 518 519 // Run honeytail in the background 520 ctx, cancel := context.WithCancel(context.Background()) 521 wg.Add(1) 522 go func() { 523 run(ctx, opts) 524 wg.Done() 525 }() 526 527 // Write a line to the log file, and check that honeytail reads it. 528 fmt.Fprint(fh, "{\"key\":1}\n") 529 fh.Close() 530 sent := expectWithTimeout(func() bool { return ts.rsp.evtCounter == 1 }, time.Second) 531 assert.True(t, sent, "Failed to read first log line") 532 533 // Simulate log rotation 534 if copyTruncate { 535 err = exec.Command("cp", logFileName, ts.tmpdir+"/test.log.1").Run() 536 } else { 537 err = os.Rename(logFileName, ts.tmpdir+"/test.log.1") 538 } 539 assert.NoError(t, err) 540 // Older versions of the inotify implementation in 541 // github.com/hpcloud/tail would fail to reopen a log file 542 // after a rename/reopen (https://github.com/hpcloud/tail/pull/115), 543 // but this delay is necessary to provoke the issue. Don't know why. 544 time.Sleep(100 * time.Millisecond) 545 546 // Write lines to the new log file, and check that honeytail reads them. 547 fh, err = os.Create(logFileName) 548 assert.NoError(t, err) 549 fmt.Fprint(fh, "{\"key\":2}\n") 550 fmt.Fprint(fh, "{\"key\":3}\n") 551 fh.Close() 552 // TODO: when logs are rotated using copy/truncate, we lose the 553 // first line of the new log file. 554 sent = expectWithTimeout(func() bool { return ts.rsp.evtCounter >= 2 }, time.Second) 555 assert.True(t, sent, "Failed to read log lines after rotation") 556 557 // Stop honeytail. 558 cancel() 559 wg.Wait() 560 }) 561 } 562 } 563 } 564 565 // boilerplate to spin up a httptest server, create tmpdir, etc. 566 // to create an environment in which to run these tests 567 type testSetup struct { 568 server *httptest.Server 569 rsp *responder 570 tmpdir string 571 } 572 573 func (t *testSetup) start(tst *testing.T, opts *GlobalOptions) { 574 logrus.SetOutput(ioutil.Discard) 575 t.rsp = &responder{} 576 t.server = httptest.NewServer(http.HandlerFunc(t.rsp.serveResponse)) 577 tmpdir, err := ioutil.TempDir(os.TempDir(), "test") 578 if err != nil { 579 tst.Fatal(err) 580 } 581 t.tmpdir = tmpdir 582 opts.APIHost = t.server.URL 583 t.rsp.responseCode = 200 584 } 585 func (t *testSetup) close() { 586 t.server.Close() 587 os.RemoveAll(t.tmpdir) 588 } 589 590 type responder struct { 591 req *http.Request // the most recent request answered by the server 592 reqBody string // the body sent along with the request 593 reqCounter int // the number of requests answered since last reset 594 evtCounter int // the number of events (<= reqCounter, will be < if events are batched) 595 responseCode int // the http status code with which to respond 596 responseBody string // the body to send as the response 597 } 598 599 func (r *responder) serveResponse(w http.ResponseWriter, req *http.Request) { 600 r.req = req 601 r.reqCounter += 1 602 603 var reader io.ReadCloser 604 switch req.Header.Get("Content-Encoding") { 605 case "gzip": 606 buf := bytes.Buffer{} 607 if _, err := io.Copy(&buf, req.Body); err != nil { 608 panic(err) 609 } 610 gzReader, err := gzip.NewReader(&buf) 611 if err != nil { 612 panic(err) 613 } 614 req.Body.Close() 615 reader = gzReader 616 case "zstd": 617 zReader, _ := zstd.NewReader( 618 nil, 619 zstd.WithDecoderConcurrency(1), 620 zstd.WithDecoderLowmem(true), 621 zstd.WithDecoderMaxMemory(8*1024*1024), 622 ) 623 zReader.Reset(req.Body) 624 reader = zReader.IOReadCloser() 625 default: 626 reader = req.Body 627 } 628 defer reader.Close() 629 630 body, err := ioutil.ReadAll(reader) 631 if err != nil { 632 panic(err) 633 } 634 635 payload := []map[string]interface{}{} 636 if len(body) > 0 { 637 if err := json.Unmarshal(body, &payload); err != nil { 638 r.evtCounter++ // likely not a batch request 639 } else { 640 r.evtCounter += len(payload) 641 } 642 } 643 r.reqBody = string(body) 644 w.WriteHeader(r.responseCode) 645 fmt.Fprintf(w, r.responseBody) 646 } 647 func (r *responder) reset() { 648 r.reqCounter = 0 649 r.evtCounter = 0 650 r.responseCode = 200 651 } 652 653 func expectWithTimeout(condition func() bool, timeout time.Duration) bool { 654 deadline := time.Now().Add(timeout) 655 for deadline.After(time.Now()) { 656 if condition() { 657 return true 658 } 659 } 660 return false 661 662 } 663 664 func TestGetEndLine(t *testing.T) { 665 fileContents := ` 666 {"key1": "value1"} 667 {"key1": "value2"} 668 {"key1": "value3"} 669 {"key1": "END"}` 670 671 f, err := ioutil.TempFile(os.TempDir(), "honeytail-test") 672 assert.Nil(t, err, "failed to open temp file") 673 _, err = f.WriteString(fileContents) 674 assert.Nil(t, err, "failed to write temp file") 675 f.Close() 676 defer syscall.Unlink(f.Name()) 677 678 line := getEndLine(f.Name()) 679 assert.Equal(t, `{"key1": "END"}`, line) 680 } 681 682 func TestRebaseTime(t *testing.T) { 683 baseTime, err := time.Parse("Mon Jan 2 15:04:05 -0700 MST 2006", "Wed Jul 3 15:04:05 -0700 PDT 2018") 684 assert.Nil(t, err) 685 nowTime, err := time.Parse("Mon Jan 2 15:04:05 -0700 MST 2006", "Wed Jul 4 12:00:00 -0700 PDT 2018") 686 assert.Nil(t, err) 687 timestamp, err := time.Parse("Mon Jan 2 15:04:05 -0700 MST 2006", "Wed Jul 3 12:00:05 -0700 PDT 2018") 688 assert.Nil(t, err) 689 // should be three hours, four minutes behind our nowTime 690 expected, err := time.Parse("Mon Jan 2 15:04:05 -0700 MST 2006", "Wed Jul 4 08:56:00 -0700 PDT 2018") 691 assert.Nil(t, err) 692 rebasedTime := rebaseTime(baseTime, nowTime, timestamp) 693 assert.Equal(t, expected, rebasedTime) 694 } 695 696 func TestGetBaseTime(t *testing.T) { 697 fileContents := ` 698 {"key1": "value1", "timestamp": "Wed Jul 3 12:00:05 -0700 PDT 2018"} 699 {"key1": "value2", "timestamp": "Wed Jul 3 13:00:05 -0700 PDT 2018"} 700 {"key1": "value3", "timestamp": "Wed Jul 3 14:00:05 -0700 PDT 2018"} 701 {"key1": "value4", "timestamp": "Wed Jul 3 15:04:05 -0700 PDT 2018"} 702 ` 703 704 f, err := ioutil.TempFile(os.TempDir(), "honeytail-test") 705 assert.Nil(t, err, "failed to open temp file") 706 _, err = f.WriteString(fileContents) 707 assert.Nil(t, err, "failed to write temp file") 708 f.Close() 709 defer syscall.Unlink(f.Name()) 710 711 options := GlobalOptions{ 712 Reqs: RequiredOptions{ 713 LogFiles: []string{f.Name()}, 714 ParserName: "json", 715 }, 716 JSON: htjson.Options{ 717 TimeFieldFormat: "Mon Jan 2 15:04:05 -0700 MST 2006", 718 TimeFieldName: "timestamp", 719 }, 720 } 721 722 expected, err := time.Parse("Mon Jan 2 15:04:05 -0700 MST 2006", "Wed Jul 3 15:04:05 -0700 PDT 2018") 723 assert.Nil(t, err) 724 baseTime, err := getBaseTime(options) 725 assert.Nil(t, err) 726 assert.Equal(t, expected.UTC(), baseTime.UTC()) 727 }