github.com/taylorchu/nomad@v0.5.3-rc1.0.20170407200202-db11e7dd7b55/command/agent/fs_endpoint_test.go (about) 1 package agent 2 3 import ( 4 "bytes" 5 "fmt" 6 "io" 7 "io/ioutil" 8 "log" 9 "math" 10 "net/http" 11 "net/http/httptest" 12 "os" 13 "path/filepath" 14 "reflect" 15 "runtime" 16 "strconv" 17 "strings" 18 "testing" 19 "time" 20 21 "github.com/hashicorp/nomad/client/allocdir" 22 "github.com/hashicorp/nomad/testutil" 23 "github.com/ugorji/go/codec" 24 ) 25 26 func TestAllocDirFS_List_MissingParams(t *testing.T) { 27 httpTest(t, nil, func(s *TestServer) { 28 req, err := http.NewRequest("GET", "/v1/client/fs/ls/", nil) 29 if err != nil { 30 t.Fatalf("err: %v", err) 31 } 32 respW := httptest.NewRecorder() 33 34 _, err = s.Server.DirectoryListRequest(respW, req) 35 if err != allocIDNotPresentErr { 36 t.Fatalf("expected err: %v, actual: %v", allocIDNotPresentErr, err) 37 } 38 }) 39 } 40 41 func TestAllocDirFS_Stat_MissingParams(t *testing.T) { 42 httpTest(t, nil, func(s *TestServer) { 43 req, err := http.NewRequest("GET", "/v1/client/fs/stat/", nil) 44 if err != nil { 45 t.Fatalf("err: %v", err) 46 } 47 respW := httptest.NewRecorder() 48 49 _, err = s.Server.FileStatRequest(respW, req) 50 if err != allocIDNotPresentErr { 51 t.Fatalf("expected err: %v, actual: %v", allocIDNotPresentErr, err) 52 } 53 54 req, err = http.NewRequest("GET", "/v1/client/fs/stat/foo", nil) 55 if err != nil { 56 t.Fatalf("err: %v", err) 57 } 58 respW = httptest.NewRecorder() 59 60 _, err = s.Server.FileStatRequest(respW, req) 61 if err != fileNameNotPresentErr { 62 t.Fatalf("expected err: %v, actual: %v", allocIDNotPresentErr, err) 63 } 64 65 }) 66 } 67 68 func TestAllocDirFS_ReadAt_MissingParams(t *testing.T) { 69 httpTest(t, nil, func(s *TestServer) { 70 req, err := http.NewRequest("GET", "/v1/client/fs/readat/", nil) 71 if err != nil { 72 t.Fatalf("err: %v", err) 73 } 74 respW := httptest.NewRecorder() 75 76 _, err = s.Server.FileReadAtRequest(respW, req) 77 if err == nil { 78 t.Fatal("expected error") 79 } 80 81 req, err = http.NewRequest("GET", "/v1/client/fs/readat/foo", nil) 82 if err != nil { 83 t.Fatalf("err: %v", err) 84 } 85 respW = httptest.NewRecorder() 86 87 _, err = s.Server.FileReadAtRequest(respW, req) 88 if err == nil { 89 t.Fatal("expected error") 90 } 91 92 req, err = http.NewRequest("GET", "/v1/client/fs/readat/foo?path=/path/to/file", nil) 93 if err != nil { 94 t.Fatalf("err: %v", err) 95 } 96 respW = httptest.NewRecorder() 97 98 _, err = s.Server.FileReadAtRequest(respW, req) 99 if err == nil { 100 t.Fatal("expected error") 101 } 102 }) 103 } 104 105 type WriteCloseChecker struct { 106 io.WriteCloser 107 Closed bool 108 } 109 110 func (w *WriteCloseChecker) Close() error { 111 w.Closed = true 112 return w.WriteCloser.Close() 113 } 114 115 // This test checks, that even if the frame size has not been hit, a flush will 116 // periodically occur. 117 func TestStreamFramer_Flush(t *testing.T) { 118 // Create the stream framer 119 r, w := io.Pipe() 120 wrappedW := &WriteCloseChecker{WriteCloser: w} 121 hRate, bWindow := 100*time.Millisecond, 100*time.Millisecond 122 sf := NewStreamFramer(wrappedW, false, hRate, bWindow, 100) 123 sf.Run() 124 125 // Create a decoder 126 dec := codec.NewDecoder(r, jsonHandle) 127 128 f := "foo" 129 fe := "bar" 130 d := []byte{0xa} 131 o := int64(10) 132 133 // Start the reader 134 resultCh := make(chan struct{}) 135 go func() { 136 for { 137 var frame StreamFrame 138 if err := dec.Decode(&frame); err != nil { 139 t.Fatalf("failed to decode") 140 } 141 142 if frame.IsHeartbeat() { 143 continue 144 } 145 146 if reflect.DeepEqual(frame.Data, d) && frame.Offset == o && frame.File == f && frame.FileEvent == fe { 147 resultCh <- struct{}{} 148 return 149 } 150 151 } 152 }() 153 154 // Write only 1 byte so we do not hit the frame size 155 if err := sf.Send(f, fe, d, o); err != nil { 156 t.Fatalf("Send() failed %v", err) 157 } 158 159 select { 160 case <-resultCh: 161 case <-time.After(10 * time.Duration(testutil.TestMultiplier()) * bWindow): 162 t.Fatalf("failed to flush") 163 } 164 165 // Close the reader and wait. This should cause the runner to exit 166 if err := r.Close(); err != nil { 167 t.Fatalf("failed to close reader") 168 } 169 170 select { 171 case <-sf.ExitCh(): 172 case <-time.After(10 * time.Duration(testutil.TestMultiplier()) * hRate): 173 t.Fatalf("exit channel should close") 174 } 175 176 sf.Destroy() 177 if !wrappedW.Closed { 178 t.Fatalf("writer not closed") 179 } 180 } 181 182 // This test checks that frames will be batched till the frame size is hit (in 183 // the case that is before the flush). 184 func TestStreamFramer_Batch(t *testing.T) { 185 // Create the stream framer 186 r, w := io.Pipe() 187 wrappedW := &WriteCloseChecker{WriteCloser: w} 188 // Ensure the batch window doesn't get hit 189 hRate, bWindow := 100*time.Millisecond, 500*time.Millisecond 190 sf := NewStreamFramer(wrappedW, false, hRate, bWindow, 3) 191 sf.Run() 192 193 // Create a decoder 194 dec := codec.NewDecoder(r, jsonHandle) 195 196 f := "foo" 197 fe := "bar" 198 d := []byte{0xa, 0xb, 0xc} 199 o := int64(10) 200 201 // Start the reader 202 resultCh := make(chan struct{}) 203 go func() { 204 for { 205 var frame StreamFrame 206 if err := dec.Decode(&frame); err != nil { 207 t.Fatalf("failed to decode") 208 } 209 210 if frame.IsHeartbeat() { 211 continue 212 } 213 214 if reflect.DeepEqual(frame.Data, d) && frame.Offset == o && frame.File == f && frame.FileEvent == fe { 215 resultCh <- struct{}{} 216 return 217 } 218 } 219 }() 220 221 // Write only 1 byte so we do not hit the frame size 222 if err := sf.Send(f, fe, d[:1], o); err != nil { 223 t.Fatalf("Send() failed %v", err) 224 } 225 226 // Ensure we didn't get any data 227 select { 228 case <-resultCh: 229 t.Fatalf("Got data before frame size reached") 230 case <-time.After(bWindow / 2): 231 } 232 233 // Write the rest so we hit the frame size 234 if err := sf.Send(f, fe, d[1:], o); err != nil { 235 t.Fatalf("Send() failed %v", err) 236 } 237 238 // Ensure we get data 239 select { 240 case <-resultCh: 241 case <-time.After(10 * time.Duration(testutil.TestMultiplier()) * bWindow): 242 t.Fatalf("Did not receive data after batch size reached") 243 } 244 245 // Close the reader and wait. This should cause the runner to exit 246 if err := r.Close(); err != nil { 247 t.Fatalf("failed to close reader") 248 } 249 250 select { 251 case <-sf.ExitCh(): 252 case <-time.After(10 * time.Duration(testutil.TestMultiplier()) * hRate): 253 t.Fatalf("exit channel should close") 254 } 255 256 sf.Destroy() 257 if !wrappedW.Closed { 258 t.Fatalf("writer not closed") 259 } 260 } 261 262 func TestStreamFramer_Heartbeat(t *testing.T) { 263 // Create the stream framer 264 r, w := io.Pipe() 265 wrappedW := &WriteCloseChecker{WriteCloser: w} 266 hRate, bWindow := 100*time.Millisecond, 100*time.Millisecond 267 sf := NewStreamFramer(wrappedW, false, hRate, bWindow, 100) 268 sf.Run() 269 270 // Create a decoder 271 dec := codec.NewDecoder(r, jsonHandle) 272 273 // Start the reader 274 resultCh := make(chan struct{}) 275 go func() { 276 for { 277 var frame StreamFrame 278 if err := dec.Decode(&frame); err != nil { 279 t.Fatalf("failed to decode") 280 } 281 282 if frame.IsHeartbeat() { 283 resultCh <- struct{}{} 284 return 285 } 286 } 287 }() 288 289 select { 290 case <-resultCh: 291 case <-time.After(10 * time.Duration(testutil.TestMultiplier()) * hRate): 292 t.Fatalf("failed to heartbeat") 293 } 294 295 // Close the reader and wait. This should cause the runner to exit 296 if err := r.Close(); err != nil { 297 t.Fatalf("failed to close reader") 298 } 299 300 select { 301 case <-sf.ExitCh(): 302 case <-time.After(10 * time.Duration(testutil.TestMultiplier()) * hRate): 303 t.Fatalf("exit channel should close") 304 } 305 306 sf.Destroy() 307 if !wrappedW.Closed { 308 t.Fatalf("writer not closed") 309 } 310 } 311 312 // This test checks that frames are received in order 313 func TestStreamFramer_Order(t *testing.T) { 314 // Create the stream framer 315 r, w := io.Pipe() 316 wrappedW := &WriteCloseChecker{WriteCloser: w} 317 // Ensure the batch window doesn't get hit 318 hRate, bWindow := 100*time.Millisecond, 10*time.Millisecond 319 sf := NewStreamFramer(wrappedW, false, hRate, bWindow, 10) 320 sf.Run() 321 322 // Create a decoder 323 dec := codec.NewDecoder(r, jsonHandle) 324 325 files := []string{"1", "2", "3", "4", "5"} 326 input := bytes.NewBuffer(make([]byte, 0, 100000)) 327 for i := 0; i <= 1000; i++ { 328 str := strconv.Itoa(i) + "," 329 input.WriteString(str) 330 } 331 332 expected := bytes.NewBuffer(make([]byte, 0, 100000)) 333 for _, _ = range files { 334 expected.Write(input.Bytes()) 335 } 336 receivedBuf := bytes.NewBuffer(make([]byte, 0, 100000)) 337 338 // Start the reader 339 resultCh := make(chan struct{}) 340 go func() { 341 for { 342 var frame StreamFrame 343 if err := dec.Decode(&frame); err != nil { 344 t.Fatalf("failed to decode") 345 } 346 347 if frame.IsHeartbeat() { 348 continue 349 } 350 351 receivedBuf.Write(frame.Data) 352 353 if reflect.DeepEqual(expected, receivedBuf) { 354 resultCh <- struct{}{} 355 return 356 } 357 } 358 }() 359 360 // Send the data 361 b := input.Bytes() 362 shards := 10 363 each := len(b) / shards 364 for _, f := range files { 365 for i := 0; i < shards; i++ { 366 l, r := each*i, each*(i+1) 367 if i == shards-1 { 368 r = len(b) 369 } 370 371 if err := sf.Send(f, "", b[l:r], 0); err != nil { 372 t.Fatalf("Send() failed %v", err) 373 } 374 } 375 } 376 377 // Ensure we get data 378 select { 379 case <-resultCh: 380 case <-time.After(10 * time.Duration(testutil.TestMultiplier()) * bWindow): 381 if reflect.DeepEqual(expected, receivedBuf) { 382 got := receivedBuf.String() 383 want := expected.String() 384 t.Fatalf("Got %v; want %v", got, want) 385 } 386 } 387 388 // Close the reader and wait. This should cause the runner to exit 389 if err := r.Close(); err != nil { 390 t.Fatalf("failed to close reader") 391 } 392 393 select { 394 case <-sf.ExitCh(): 395 case <-time.After(10 * time.Duration(testutil.TestMultiplier()) * hRate): 396 t.Fatalf("exit channel should close") 397 } 398 399 sf.Destroy() 400 if !wrappedW.Closed { 401 t.Fatalf("writer not closed") 402 } 403 } 404 405 // This test checks that frames are received in order 406 func TestStreamFramer_Order_PlainText(t *testing.T) { 407 // Create the stream framer 408 r, w := io.Pipe() 409 wrappedW := &WriteCloseChecker{WriteCloser: w} 410 // Ensure the batch window doesn't get hit 411 hRate, bWindow := 100*time.Millisecond, 10*time.Millisecond 412 sf := NewStreamFramer(wrappedW, true, hRate, bWindow, 10) 413 sf.Run() 414 415 files := []string{"1", "2", "3", "4", "5"} 416 input := bytes.NewBuffer(make([]byte, 0, 100000)) 417 for i := 0; i <= 1000; i++ { 418 str := strconv.Itoa(i) + "," 419 input.WriteString(str) 420 } 421 422 expected := bytes.NewBuffer(make([]byte, 0, 100000)) 423 for _, _ = range files { 424 expected.Write(input.Bytes()) 425 } 426 receivedBuf := bytes.NewBuffer(make([]byte, 0, 100000)) 427 428 // Start the reader 429 resultCh := make(chan struct{}) 430 go func() { 431 OUTER: 432 for { 433 if _, err := receivedBuf.ReadFrom(r); err != nil { 434 if strings.Contains(err.Error(), "closed pipe") { 435 resultCh <- struct{}{} 436 return 437 } 438 t.Fatalf("bad read: %v", err) 439 } 440 441 if expected.Len() != receivedBuf.Len() { 442 continue 443 } 444 expectedBytes := expected.Bytes() 445 actualBytes := receivedBuf.Bytes() 446 for i, e := range expectedBytes { 447 if a := actualBytes[i]; a != e { 448 continue OUTER 449 } 450 } 451 resultCh <- struct{}{} 452 return 453 454 } 455 }() 456 457 // Send the data 458 b := input.Bytes() 459 shards := 10 460 each := len(b) / shards 461 for _, f := range files { 462 for i := 0; i < shards; i++ { 463 l, r := each*i, each*(i+1) 464 if i == shards-1 { 465 r = len(b) 466 } 467 468 if err := sf.Send(f, "", b[l:r], 0); err != nil { 469 t.Fatalf("Send() failed %v", err) 470 } 471 } 472 } 473 474 // Ensure we get data 475 select { 476 case <-resultCh: 477 case <-time.After(10 * time.Duration(testutil.TestMultiplier()) * bWindow): 478 if expected.Len() != receivedBuf.Len() { 479 t.Fatalf("Got %v; want %v", expected.Len(), receivedBuf.Len()) 480 } 481 expectedBytes := expected.Bytes() 482 actualBytes := receivedBuf.Bytes() 483 for i, e := range expectedBytes { 484 if a := actualBytes[i]; a != e { 485 t.Fatalf("Index %d; Got %q; want %q", i, a, e) 486 } 487 } 488 } 489 490 // Close the reader and wait. This should cause the runner to exit 491 if err := r.Close(); err != nil { 492 t.Fatalf("failed to close reader") 493 } 494 495 sf.Destroy() 496 if !wrappedW.Closed { 497 t.Fatalf("writer not closed") 498 } 499 } 500 501 func TestHTTP_Stream_MissingParams(t *testing.T) { 502 httpTest(t, nil, func(s *TestServer) { 503 req, err := http.NewRequest("GET", "/v1/client/fs/stream/", nil) 504 if err != nil { 505 t.Fatalf("err: %v", err) 506 } 507 respW := httptest.NewRecorder() 508 509 _, err = s.Server.Stream(respW, req) 510 if err == nil { 511 t.Fatal("expected error") 512 } 513 514 req, err = http.NewRequest("GET", "/v1/client/fs/stream/foo", nil) 515 if err != nil { 516 t.Fatalf("err: %v", err) 517 } 518 respW = httptest.NewRecorder() 519 520 _, err = s.Server.Stream(respW, req) 521 if err == nil { 522 t.Fatal("expected error") 523 } 524 525 req, err = http.NewRequest("GET", "/v1/client/fs/stream/foo?path=/path/to/file", nil) 526 if err != nil { 527 t.Fatalf("err: %v", err) 528 } 529 respW = httptest.NewRecorder() 530 531 _, err = s.Server.Stream(respW, req) 532 if err == nil { 533 t.Fatal("expected error") 534 } 535 }) 536 } 537 538 // tempAllocDir returns a new alloc dir that is rooted in a temp dir. The caller 539 // should destroy the temp dir. 540 func tempAllocDir(t testing.TB) *allocdir.AllocDir { 541 dir, err := ioutil.TempDir("", "") 542 if err != nil { 543 t.Fatalf("TempDir() failed: %v", err) 544 } 545 546 if err := os.Chmod(dir, 0777); err != nil { 547 t.Fatalf("failed to chmod dir: %v", err) 548 } 549 550 return allocdir.NewAllocDir(log.New(os.Stderr, "", log.LstdFlags), dir) 551 } 552 553 type nopWriteCloser struct { 554 io.Writer 555 } 556 557 func (n nopWriteCloser) Close() error { 558 return nil 559 } 560 561 func TestHTTP_Stream_NoFile(t *testing.T) { 562 httpTest(t, nil, func(s *TestServer) { 563 // Get a temp alloc dir 564 ad := tempAllocDir(t) 565 defer os.RemoveAll(ad.AllocDir) 566 567 framer := NewStreamFramer(nopWriteCloser{ioutil.Discard}, false, streamHeartbeatRate, streamBatchWindow, streamFrameSize) 568 framer.Run() 569 defer framer.Destroy() 570 571 if err := s.Server.stream(0, "foo", ad, framer, nil); err == nil { 572 t.Fatalf("expected an error when streaming unknown file") 573 } 574 }) 575 } 576 577 func TestHTTP_Stream_Modify(t *testing.T) { 578 httpTest(t, nil, func(s *TestServer) { 579 // Get a temp alloc dir 580 ad := tempAllocDir(t) 581 defer os.RemoveAll(ad.AllocDir) 582 583 // Create a file in the temp dir 584 streamFile := "stream_file" 585 f, err := os.Create(filepath.Join(ad.AllocDir, streamFile)) 586 if err != nil { 587 t.Fatalf("Failed to create file: %v", err) 588 } 589 defer f.Close() 590 591 // Create a decoder 592 r, w := io.Pipe() 593 defer r.Close() 594 defer w.Close() 595 dec := codec.NewDecoder(r, jsonHandle) 596 597 data := []byte("helloworld") 598 599 // Start the reader 600 resultCh := make(chan struct{}) 601 go func() { 602 var collected []byte 603 for { 604 var frame StreamFrame 605 if err := dec.Decode(&frame); err != nil { 606 t.Fatalf("failed to decode: %v", err) 607 } 608 609 if frame.IsHeartbeat() { 610 continue 611 } 612 613 collected = append(collected, frame.Data...) 614 if reflect.DeepEqual(data, collected) { 615 resultCh <- struct{}{} 616 return 617 } 618 } 619 }() 620 621 // Write a few bytes 622 if _, err := f.Write(data[:3]); err != nil { 623 t.Fatalf("write failed: %v", err) 624 } 625 626 framer := NewStreamFramer(w, false, streamHeartbeatRate, streamBatchWindow, streamFrameSize) 627 framer.Run() 628 defer framer.Destroy() 629 630 // Start streaming 631 go func() { 632 if err := s.Server.stream(0, streamFile, ad, framer, nil); err != nil { 633 t.Fatalf("stream() failed: %v", err) 634 } 635 }() 636 637 // Sleep a little before writing more. This lets us check if the watch 638 // is working. 639 time.Sleep(1 * time.Duration(testutil.TestMultiplier()) * time.Second) 640 if _, err := f.Write(data[3:]); err != nil { 641 t.Fatalf("write failed: %v", err) 642 } 643 644 select { 645 case <-resultCh: 646 case <-time.After(10 * time.Duration(testutil.TestMultiplier()) * streamBatchWindow): 647 t.Fatalf("failed to send new data") 648 } 649 }) 650 } 651 652 func TestHTTP_Stream_Truncate(t *testing.T) { 653 httpTest(t, nil, func(s *TestServer) { 654 // Get a temp alloc dir 655 ad := tempAllocDir(t) 656 defer os.RemoveAll(ad.AllocDir) 657 658 // Create a file in the temp dir 659 streamFile := "stream_file" 660 streamFilePath := filepath.Join(ad.AllocDir, streamFile) 661 f, err := os.Create(streamFilePath) 662 if err != nil { 663 t.Fatalf("Failed to create file: %v", err) 664 } 665 defer f.Close() 666 667 // Create a decoder 668 r, w := io.Pipe() 669 defer r.Close() 670 defer w.Close() 671 dec := codec.NewDecoder(r, jsonHandle) 672 673 data := []byte("helloworld") 674 675 // Start the reader 676 truncateCh := make(chan struct{}) 677 dataPostTruncCh := make(chan struct{}) 678 go func() { 679 var collected []byte 680 for { 681 var frame StreamFrame 682 if err := dec.Decode(&frame); err != nil { 683 t.Fatalf("failed to decode: %v", err) 684 } 685 686 if frame.IsHeartbeat() { 687 continue 688 } 689 690 if frame.FileEvent == truncateEvent { 691 close(truncateCh) 692 } 693 694 collected = append(collected, frame.Data...) 695 if reflect.DeepEqual(data, collected) { 696 close(dataPostTruncCh) 697 return 698 } 699 } 700 }() 701 702 // Write a few bytes 703 if _, err := f.Write(data[:3]); err != nil { 704 t.Fatalf("write failed: %v", err) 705 } 706 707 framer := NewStreamFramer(w, false, streamHeartbeatRate, streamBatchWindow, streamFrameSize) 708 framer.Run() 709 defer framer.Destroy() 710 711 // Start streaming 712 go func() { 713 if err := s.Server.stream(0, streamFile, ad, framer, nil); err != nil { 714 t.Fatalf("stream() failed: %v", err) 715 } 716 }() 717 718 // Sleep a little before truncating. This lets us check if the watch 719 // is working. 720 time.Sleep(1 * time.Duration(testutil.TestMultiplier()) * time.Second) 721 if err := f.Truncate(0); err != nil { 722 t.Fatalf("truncate failed: %v", err) 723 } 724 if err := f.Sync(); err != nil { 725 t.Fatalf("sync failed: %v", err) 726 } 727 if err := f.Close(); err != nil { 728 t.Fatalf("failed to close file: %v", err) 729 } 730 731 f2, err := os.OpenFile(streamFilePath, os.O_RDWR, 0) 732 if err != nil { 733 t.Fatalf("failed to reopen file: %v", err) 734 } 735 defer f2.Close() 736 if _, err := f2.Write(data[3:5]); err != nil { 737 t.Fatalf("write failed: %v", err) 738 } 739 740 select { 741 case <-truncateCh: 742 case <-time.After(10 * time.Duration(testutil.TestMultiplier()) * streamBatchWindow): 743 t.Fatalf("did not receive truncate") 744 } 745 746 // Sleep a little before writing more. This lets us check if the watch 747 // is working. 748 time.Sleep(1 * time.Duration(testutil.TestMultiplier()) * time.Second) 749 if _, err := f2.Write(data[5:]); err != nil { 750 t.Fatalf("write failed: %v", err) 751 } 752 753 select { 754 case <-dataPostTruncCh: 755 case <-time.After(10 * time.Duration(testutil.TestMultiplier()) * streamBatchWindow): 756 t.Fatalf("did not receive post truncate data") 757 } 758 }) 759 } 760 761 func TestHTTP_Stream_Delete(t *testing.T) { 762 httpTest(t, nil, func(s *TestServer) { 763 // Get a temp alloc dir 764 ad := tempAllocDir(t) 765 defer os.RemoveAll(ad.AllocDir) 766 767 // Create a file in the temp dir 768 streamFile := "stream_file" 769 streamFilePath := filepath.Join(ad.AllocDir, streamFile) 770 f, err := os.Create(streamFilePath) 771 if err != nil { 772 t.Fatalf("Failed to create file: %v", err) 773 } 774 defer f.Close() 775 776 // Create a decoder 777 r, w := io.Pipe() 778 wrappedW := &WriteCloseChecker{WriteCloser: w} 779 defer r.Close() 780 defer w.Close() 781 dec := codec.NewDecoder(r, jsonHandle) 782 783 data := []byte("helloworld") 784 785 // Start the reader 786 deleteCh := make(chan struct{}) 787 go func() { 788 for { 789 var frame StreamFrame 790 if err := dec.Decode(&frame); err != nil { 791 t.Fatalf("failed to decode: %v", err) 792 } 793 794 if frame.IsHeartbeat() { 795 continue 796 } 797 798 if frame.FileEvent == deleteEvent { 799 close(deleteCh) 800 return 801 } 802 } 803 }() 804 805 // Write a few bytes 806 if _, err := f.Write(data[:3]); err != nil { 807 t.Fatalf("write failed: %v", err) 808 } 809 810 framer := NewStreamFramer(wrappedW, false, streamHeartbeatRate, streamBatchWindow, streamFrameSize) 811 framer.Run() 812 813 // Start streaming 814 go func() { 815 if err := s.Server.stream(0, streamFile, ad, framer, nil); err != nil { 816 t.Fatalf("stream() failed: %v", err) 817 } 818 }() 819 820 // Sleep a little before deleting. This lets us check if the watch 821 // is working. 822 time.Sleep(1 * time.Duration(testutil.TestMultiplier()) * time.Second) 823 if err := os.Remove(streamFilePath); err != nil { 824 t.Fatalf("delete failed: %v", err) 825 } 826 827 select { 828 case <-deleteCh: 829 case <-time.After(10 * time.Duration(testutil.TestMultiplier()) * streamBatchWindow): 830 t.Fatalf("did not receive delete") 831 } 832 833 framer.Destroy() 834 testutil.WaitForResult(func() (bool, error) { 835 return wrappedW.Closed, nil 836 }, func(err error) { 837 t.Fatalf("connection not closed") 838 }) 839 840 }) 841 } 842 843 func TestHTTP_Logs_NoFollow(t *testing.T) { 844 httpTest(t, nil, func(s *TestServer) { 845 // Get a temp alloc dir and create the log dir 846 ad := tempAllocDir(t) 847 defer os.RemoveAll(ad.AllocDir) 848 849 logDir := filepath.Join(ad.SharedDir, allocdir.LogDirName) 850 if err := os.MkdirAll(logDir, 0777); err != nil { 851 t.Fatalf("Failed to make log dir: %v", err) 852 } 853 854 // Create a series of log files in the temp dir 855 task := "foo" 856 logType := "stdout" 857 expected := []byte("012") 858 for i := 0; i < 3; i++ { 859 logFile := fmt.Sprintf("%s.%s.%d", task, logType, i) 860 logFilePath := filepath.Join(logDir, logFile) 861 err := ioutil.WriteFile(logFilePath, expected[i:i+1], 777) 862 if err != nil { 863 t.Fatalf("Failed to create file: %v", err) 864 } 865 } 866 867 // Create a decoder 868 r, w := io.Pipe() 869 wrappedW := &WriteCloseChecker{WriteCloser: w} 870 defer r.Close() 871 defer w.Close() 872 dec := codec.NewDecoder(r, jsonHandle) 873 874 var received []byte 875 876 // Start the reader 877 resultCh := make(chan struct{}) 878 go func() { 879 for { 880 var frame StreamFrame 881 if err := dec.Decode(&frame); err != nil { 882 if err == io.EOF { 883 t.Logf("EOF") 884 return 885 } 886 887 t.Fatalf("failed to decode: %v", err) 888 } 889 890 if frame.IsHeartbeat() { 891 continue 892 } 893 894 received = append(received, frame.Data...) 895 if reflect.DeepEqual(received, expected) { 896 close(resultCh) 897 return 898 } 899 } 900 }() 901 902 // Start streaming logs 903 go func() { 904 if err := s.Server.logs(false, false, 0, OriginStart, task, logType, ad, wrappedW); err != nil { 905 t.Fatalf("logs() failed: %v", err) 906 } 907 }() 908 909 select { 910 case <-resultCh: 911 case <-time.After(10 * time.Duration(testutil.TestMultiplier()) * streamBatchWindow): 912 t.Fatalf("did not receive data: got %q", string(received)) 913 } 914 915 testutil.WaitForResult(func() (bool, error) { 916 return wrappedW.Closed, nil 917 }, func(err error) { 918 t.Fatalf("connection not closed") 919 }) 920 921 }) 922 } 923 924 func TestHTTP_Logs_Follow(t *testing.T) { 925 httpTest(t, nil, func(s *TestServer) { 926 // Get a temp alloc dir and create the log dir 927 ad := tempAllocDir(t) 928 defer os.RemoveAll(ad.AllocDir) 929 930 logDir := filepath.Join(ad.SharedDir, allocdir.LogDirName) 931 if err := os.MkdirAll(logDir, 0777); err != nil { 932 t.Fatalf("Failed to make log dir: %v", err) 933 } 934 935 // Create a series of log files in the temp dir 936 task := "foo" 937 logType := "stdout" 938 expected := []byte("012345") 939 initialWrites := 3 940 941 writeToFile := func(index int, data []byte) { 942 logFile := fmt.Sprintf("%s.%s.%d", task, logType, index) 943 logFilePath := filepath.Join(logDir, logFile) 944 err := ioutil.WriteFile(logFilePath, data, 777) 945 if err != nil { 946 t.Fatalf("Failed to create file: %v", err) 947 } 948 } 949 for i := 0; i < initialWrites; i++ { 950 writeToFile(i, expected[i:i+1]) 951 } 952 953 // Create a decoder 954 r, w := io.Pipe() 955 wrappedW := &WriteCloseChecker{WriteCloser: w} 956 defer r.Close() 957 defer w.Close() 958 dec := codec.NewDecoder(r, jsonHandle) 959 960 var received []byte 961 962 // Start the reader 963 firstResultCh := make(chan struct{}) 964 fullResultCh := make(chan struct{}) 965 go func() { 966 for { 967 var frame StreamFrame 968 if err := dec.Decode(&frame); err != nil { 969 if err == io.EOF { 970 t.Logf("EOF") 971 return 972 } 973 974 t.Fatalf("failed to decode: %v", err) 975 } 976 977 if frame.IsHeartbeat() { 978 continue 979 } 980 981 received = append(received, frame.Data...) 982 if reflect.DeepEqual(received, expected[:initialWrites]) { 983 close(firstResultCh) 984 } else if reflect.DeepEqual(received, expected) { 985 close(fullResultCh) 986 return 987 } 988 } 989 }() 990 991 // Start streaming logs 992 go func() { 993 if err := s.Server.logs(true, false, 0, OriginStart, task, logType, ad, wrappedW); err != nil { 994 t.Fatalf("logs() failed: %v", err) 995 } 996 }() 997 998 select { 999 case <-firstResultCh: 1000 case <-time.After(10 * time.Duration(testutil.TestMultiplier()) * streamBatchWindow): 1001 t.Fatalf("did not receive data: got %q", string(received)) 1002 } 1003 1004 // We got the first chunk of data, write out the rest to the next file 1005 // at an index much ahead to check that it is following and detecting 1006 // skips 1007 skipTo := initialWrites + 10 1008 writeToFile(skipTo, expected[initialWrites:]) 1009 1010 select { 1011 case <-fullResultCh: 1012 case <-time.After(10 * time.Duration(testutil.TestMultiplier()) * streamBatchWindow): 1013 t.Fatalf("did not receive data: got %q", string(received)) 1014 } 1015 1016 // Close the reader 1017 r.Close() 1018 1019 testutil.WaitForResult(func() (bool, error) { 1020 return wrappedW.Closed, nil 1021 }, func(err error) { 1022 t.Fatalf("connection not closed") 1023 }) 1024 }) 1025 } 1026 1027 func BenchmarkHTTP_Logs_Follow(t *testing.B) { 1028 runtime.MemProfileRate = 1 1029 1030 s := makeHTTPServer(t, nil) 1031 defer s.Cleanup() 1032 testutil.WaitForLeader(t, s.Agent.RPC) 1033 1034 // Get a temp alloc dir and create the log dir 1035 ad := tempAllocDir(t) 1036 s.Agent.logger.Printf("ALEX: LOG DIR: %q", ad.SharedDir) 1037 //defer os.RemoveAll(ad.AllocDir) 1038 1039 logDir := filepath.Join(ad.SharedDir, allocdir.LogDirName) 1040 if err := os.MkdirAll(logDir, 0777); err != nil { 1041 t.Fatalf("Failed to make log dir: %v", err) 1042 } 1043 1044 // Create a series of log files in the temp dir 1045 task := "foo" 1046 logType := "stdout" 1047 expected := make([]byte, 1024*1024*100) 1048 initialWrites := 3 1049 1050 writeToFile := func(index int, data []byte) { 1051 logFile := fmt.Sprintf("%s.%s.%d", task, logType, index) 1052 logFilePath := filepath.Join(logDir, logFile) 1053 err := ioutil.WriteFile(logFilePath, data, 777) 1054 if err != nil { 1055 t.Fatalf("Failed to create file: %v", err) 1056 } 1057 } 1058 1059 part := (len(expected) / 3) - 50 1060 goodEnough := (8 * len(expected)) / 10 1061 for i := 0; i < initialWrites; i++ { 1062 writeToFile(i, expected[i*part:(i+1)*part]) 1063 } 1064 1065 t.ResetTimer() 1066 for i := 0; i < t.N; i++ { 1067 s.Agent.logger.Printf("BENCHMARK %d", i) 1068 1069 // Create a decoder 1070 r, w := io.Pipe() 1071 wrappedW := &WriteCloseChecker{WriteCloser: w} 1072 defer r.Close() 1073 defer w.Close() 1074 dec := codec.NewDecoder(r, jsonHandle) 1075 1076 var received []byte 1077 1078 // Start the reader 1079 fullResultCh := make(chan struct{}) 1080 go func() { 1081 for { 1082 var frame StreamFrame 1083 if err := dec.Decode(&frame); err != nil { 1084 if err == io.EOF { 1085 t.Logf("EOF") 1086 return 1087 } 1088 1089 t.Fatalf("failed to decode: %v", err) 1090 } 1091 1092 if frame.IsHeartbeat() { 1093 continue 1094 } 1095 1096 received = append(received, frame.Data...) 1097 if len(received) > goodEnough { 1098 close(fullResultCh) 1099 return 1100 } 1101 } 1102 }() 1103 1104 // Start streaming logs 1105 go func() { 1106 if err := s.Server.logs(true, false, 0, OriginStart, task, logType, ad, wrappedW); err != nil { 1107 t.Fatalf("logs() failed: %v", err) 1108 } 1109 }() 1110 1111 select { 1112 case <-fullResultCh: 1113 case <-time.After(time.Duration(60 * time.Second)): 1114 t.Fatalf("did not receive data: %d < %d", len(received), goodEnough) 1115 } 1116 1117 s.Agent.logger.Printf("ALEX: CLOSING") 1118 1119 // Close the reader 1120 r.Close() 1121 s.Agent.logger.Printf("ALEX: CLOSED") 1122 1123 s.Agent.logger.Printf("ALEX: WAITING FOR WRITER TO CLOSE") 1124 testutil.WaitForResult(func() (bool, error) { 1125 return wrappedW.Closed, nil 1126 }, func(err error) { 1127 t.Fatalf("connection not closed") 1128 }) 1129 s.Agent.logger.Printf("ALEX: WRITER CLOSED") 1130 } 1131 } 1132 1133 func TestLogs_findClosest(t *testing.T) { 1134 task := "foo" 1135 entries := []*allocdir.AllocFileInfo{ 1136 { 1137 Name: "foo.stdout.0", 1138 Size: 100, 1139 }, 1140 { 1141 Name: "foo.stdout.1", 1142 Size: 100, 1143 }, 1144 { 1145 Name: "foo.stdout.2", 1146 Size: 100, 1147 }, 1148 { 1149 Name: "foo.stdout.3", 1150 Size: 100, 1151 }, 1152 { 1153 Name: "foo.stderr.0", 1154 Size: 100, 1155 }, 1156 { 1157 Name: "foo.stderr.1", 1158 Size: 100, 1159 }, 1160 { 1161 Name: "foo.stderr.2", 1162 Size: 100, 1163 }, 1164 } 1165 1166 cases := []struct { 1167 Entries []*allocdir.AllocFileInfo 1168 DesiredIdx int64 1169 DesiredOffset int64 1170 Task string 1171 LogType string 1172 ExpectedFile string 1173 ExpectedIdx int64 1174 ExpectedOffset int64 1175 Error bool 1176 }{ 1177 // Test error cases 1178 { 1179 Entries: nil, 1180 DesiredIdx: 0, 1181 Task: task, 1182 LogType: "stdout", 1183 Error: true, 1184 }, 1185 { 1186 Entries: entries[0:3], 1187 DesiredIdx: 0, 1188 Task: task, 1189 LogType: "stderr", 1190 Error: true, 1191 }, 1192 1193 // Test begining cases 1194 { 1195 Entries: entries, 1196 DesiredIdx: 0, 1197 Task: task, 1198 LogType: "stdout", 1199 ExpectedFile: entries[0].Name, 1200 ExpectedIdx: 0, 1201 }, 1202 { 1203 // Desired offset should be ignored at edges 1204 Entries: entries, 1205 DesiredIdx: 0, 1206 DesiredOffset: -100, 1207 Task: task, 1208 LogType: "stdout", 1209 ExpectedFile: entries[0].Name, 1210 ExpectedIdx: 0, 1211 ExpectedOffset: 0, 1212 }, 1213 { 1214 // Desired offset should be ignored at edges 1215 Entries: entries, 1216 DesiredIdx: 1, 1217 DesiredOffset: -1000, 1218 Task: task, 1219 LogType: "stdout", 1220 ExpectedFile: entries[0].Name, 1221 ExpectedIdx: 0, 1222 ExpectedOffset: 0, 1223 }, 1224 { 1225 Entries: entries, 1226 DesiredIdx: 0, 1227 Task: task, 1228 LogType: "stderr", 1229 ExpectedFile: entries[4].Name, 1230 ExpectedIdx: 0, 1231 }, 1232 { 1233 Entries: entries, 1234 DesiredIdx: 0, 1235 Task: task, 1236 LogType: "stdout", 1237 ExpectedFile: entries[0].Name, 1238 ExpectedIdx: 0, 1239 }, 1240 1241 // Test middle cases 1242 { 1243 Entries: entries, 1244 DesiredIdx: 1, 1245 Task: task, 1246 LogType: "stdout", 1247 ExpectedFile: entries[1].Name, 1248 ExpectedIdx: 1, 1249 }, 1250 { 1251 Entries: entries, 1252 DesiredIdx: 1, 1253 DesiredOffset: 10, 1254 Task: task, 1255 LogType: "stdout", 1256 ExpectedFile: entries[1].Name, 1257 ExpectedIdx: 1, 1258 ExpectedOffset: 10, 1259 }, 1260 { 1261 Entries: entries, 1262 DesiredIdx: 1, 1263 DesiredOffset: 110, 1264 Task: task, 1265 LogType: "stdout", 1266 ExpectedFile: entries[2].Name, 1267 ExpectedIdx: 2, 1268 ExpectedOffset: 10, 1269 }, 1270 { 1271 Entries: entries, 1272 DesiredIdx: 1, 1273 Task: task, 1274 LogType: "stderr", 1275 ExpectedFile: entries[5].Name, 1276 ExpectedIdx: 1, 1277 }, 1278 // Test end cases 1279 { 1280 Entries: entries, 1281 DesiredIdx: math.MaxInt64, 1282 Task: task, 1283 LogType: "stdout", 1284 ExpectedFile: entries[3].Name, 1285 ExpectedIdx: 3, 1286 }, 1287 { 1288 Entries: entries, 1289 DesiredIdx: math.MaxInt64, 1290 DesiredOffset: math.MaxInt64, 1291 Task: task, 1292 LogType: "stdout", 1293 ExpectedFile: entries[3].Name, 1294 ExpectedIdx: 3, 1295 ExpectedOffset: 100, 1296 }, 1297 { 1298 Entries: entries, 1299 DesiredIdx: math.MaxInt64, 1300 DesiredOffset: -10, 1301 Task: task, 1302 LogType: "stdout", 1303 ExpectedFile: entries[3].Name, 1304 ExpectedIdx: 3, 1305 ExpectedOffset: 90, 1306 }, 1307 { 1308 Entries: entries, 1309 DesiredIdx: math.MaxInt64, 1310 Task: task, 1311 LogType: "stderr", 1312 ExpectedFile: entries[6].Name, 1313 ExpectedIdx: 2, 1314 }, 1315 } 1316 1317 for i, c := range cases { 1318 entry, idx, offset, err := findClosest(c.Entries, c.DesiredIdx, c.DesiredOffset, c.Task, c.LogType) 1319 if err != nil { 1320 if !c.Error { 1321 t.Fatalf("case %d: Unexpected error: %v", i, err) 1322 } 1323 continue 1324 } 1325 1326 if entry.Name != c.ExpectedFile { 1327 t.Fatalf("case %d: Got file %q; want %q", i, entry.Name, c.ExpectedFile) 1328 } 1329 if idx != c.ExpectedIdx { 1330 t.Fatalf("case %d: Got index %d; want %d", i, idx, c.ExpectedIdx) 1331 } 1332 if offset != c.ExpectedOffset { 1333 t.Fatalf("case %d: Got offset %d; want %d", i, offset, c.ExpectedOffset) 1334 } 1335 } 1336 }