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