Browse code

Optimize test daemon startup

This adds some logs, handles timers better, and sets a request timeout
for the ping request.

I'm not sure the ticker in that loop is what we really want since the
ticker keeps ticking while we are (attempting) to make a request... but
I opted to not change that for now.

Signed-off-by: Brian Goff <cpuguy83@gmail.com>

Brian Goff authored on 2019/04/18 08:04:25
Showing 1 changed files
... ...
@@ -278,41 +278,46 @@ func (d *Daemon) StartWithLogFile(out *os.File, providedArgs ...string) error {
278 278
 
279 279
 	d.Wait = wait
280 280
 
281
+	clientConfig, err := d.getClientConfig()
282
+	if err != nil {
283
+		return err
284
+	}
285
+	client := &http.Client{
286
+		Transport: clientConfig.transport,
287
+	}
288
+
289
+	req, err := http.NewRequest("GET", "/_ping", nil)
290
+	if err != nil {
291
+		return errors.Wrapf(err, "[%s] could not create new request", d.id)
292
+	}
293
+	req.URL.Host = clientConfig.addr
294
+	req.URL.Scheme = clientConfig.scheme
295
+
281 296
 	ticker := time.NewTicker(500 * time.Millisecond)
282 297
 	defer ticker.Stop()
283 298
 	tick := ticker.C
284 299
 
300
+	timeout := time.NewTimer(60 * time.Second) // timeout for the whole loop
301
+	defer timeout.Stop()
302
+
285 303
 	// make sure daemon is ready to receive requests
286
-	startTime := time.Now().Unix()
287 304
 	for {
288 305
 		d.log.Logf("[%s] waiting for daemon to start", d.id)
289
-		if time.Now().Unix()-startTime > 5 {
290
-			// After 5 seconds, give up
291
-			return errors.Errorf("[%s] Daemon exited and never started", d.id)
292
-		}
306
+
293 307
 		select {
294
-		case <-time.After(2 * time.Second):
295
-			return errors.Errorf("[%s] timeout: daemon does not respond", d.id)
308
+		case <-timeout.C:
309
+			return errors.Errorf("[%s] Daemon exited and never started", d.id)
296 310
 		case <-tick:
297
-			clientConfig, err := d.getClientConfig()
298
-			if err != nil {
299
-				return err
300
-			}
301
-
302
-			client := &http.Client{
303
-				Transport: clientConfig.transport,
304
-			}
311
+			ctx, cancel := context.WithTimeout(context.TODO(), 2*time.Second)
312
+			req := req.WithContext(ctx)
305 313
 
306
-			req, err := http.NewRequest("GET", "/_ping", nil)
307
-			if err != nil {
308
-				return errors.Wrapf(err, "[%s] could not create new request", d.id)
309
-			}
310
-			req.URL.Host = clientConfig.addr
311
-			req.URL.Scheme = clientConfig.scheme
312 314
 			resp, err := client.Do(req)
315
+			cancel()
313 316
 			if err != nil {
317
+				d.log.Logf("[%s] error pinging daemon on start: %v", d.id, err)
314 318
 				continue
315 319
 			}
320
+
316 321
 			resp.Body.Close()
317 322
 			if resp.StatusCode != http.StatusOK {
318 323
 				d.log.Logf("[%s] received status != 200 OK: %s\n", d.id, resp.Status)
... ...
@@ -412,8 +417,8 @@ func (d *Daemon) StopWithError() error {
412 412
 	if d.cmd == nil || d.Wait == nil {
413 413
 		return errDaemonNotStarted
414 414
 	}
415
-
416 415
 	defer func() {
416
+		d.log.Logf("[%s] Daemon stopped", d.id)
417 417
 		d.logFile.Close()
418 418
 		d.cmd = nil
419 419
 	}()
... ...
@@ -423,12 +428,15 @@ func (d *Daemon) StopWithError() error {
423 423
 	defer ticker.Stop()
424 424
 	tick := ticker.C
425 425
 
426
+	d.log.Logf("[%s] Stopping daemon", d.id)
427
+
426 428
 	if err := d.cmd.Process.Signal(os.Interrupt); err != nil {
427 429
 		if strings.Contains(err.Error(), "os: process already finished") {
428 430
 			return errDaemonNotStarted
429 431
 		}
430 432
 		return errors.Errorf("could not send signal: %v", err)
431 433
 	}
434
+
432 435
 out1:
433 436
 	for {
434 437
 		select {
... ...
@@ -482,6 +490,7 @@ func (d *Daemon) Restart(t testingT, args ...string) {
482 482
 // RestartWithError will restart the daemon by first stopping it and then starting it.
483 483
 func (d *Daemon) RestartWithError(arg ...string) error {
484 484
 	if err := d.StopWithError(); err != nil {
485
+		d.log.Logf("[%s] Error when stopping daemon: %v", d.id, err)
485 486
 		return err
486 487
 	}
487 488
 	return d.StartWithError(arg...)