github.com/taylorchu/nomad@v0.5.3-rc1.0.20170407200202-db11e7dd7b55/command/agent/fs_endpoint_test.go (about)

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