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