Also log, for heuristics tuning only, the elapsed time

Signed-off-by: Miloslav Trmač <mitr@redhat.com>

docker/body_reader.go

@@ -30,6 +30,7 @@ type bodyReader struct {
 	body            io.ReadCloser // The currently open connection we use to read data, or nil if there is nothing to read from / close.
 	lastRetryOffset int64
 	offset          int64 // Current offset within the blob
+	lastSuccessTime time.Time
 
 	sysLog *syslog.Writer
 }
@@ -151,12 +152,17 @@ func (br *bodyReader) Read(p []byte) (int, error) {
 	br.offset += int64(n)
 	switch {
 	case err == nil || err == io.EOF:
+		br.lastSuccessTime = time.Now()
 		return n, err // Unlike the default: case, don’t log anything.
 
 	case errors.Is(err, io.ErrUnexpectedEOF) || errors.Is(err, syscall.ECONNRESET):
 		originalErr := err
 		// FIXME: Turn this into a Debugf
-		br.Logf("BODYREADER DEBUG: Reading blob body, decision inputs: lastRetryOffset %d, offset %d, error %#v", br.lastRetryOffset, br.offset, originalErr)
+		failureTime := int64(-1)
+		if (br.lastSuccessTime != time.Time{}) {
+			failureTime = time.Since(br.lastSuccessTime).Milliseconds()
+		}
+		br.Logf("BODYREADER DEBUG: Reading blob body, decision inputs: lastRetryOffset %d, offset %d, time diff %d ms, error %#v", br.lastRetryOffset, br.offset, failureTime, originalErr)
 		progress := br.offset - br.lastRetryOffset
 		if progress < bodyReaderMinimumProgress {
 			// FIXME: Warnf