github.com/mongey/nomad@v0.5.2/command/agent/fs_endpoint_test.go (about)

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