Adding Estimated-Time-of-Arrival (ETA) to training...

[cfrigaard]

You can add an ETA estimate to you training as simple as adding the following eta.py file and then add the function LoggerPrintEta and etafilter to train.py at lines 285 (just after LOGGER.info(..) and before for epoch in range(start_epoch, epochs): # epoch ---):

  compute_loss = ComputeLoss(model)  # init loss class
  LOGGER.info(f'Image sizes {imgsz} train, {imgsz} val\n'
              f'Using {train_loader.num_workers * WORLD_SIZE} dataloader workers\n'
              f"Logging results to {colorstr('bold', save_dir)}\n"
              f'Starting training for {epochs} epochs...')
  # ADD from here..
  def LoggerPrintEta(etafilter, start_epoch, epoch, epochs):
      try:
          assert epoch >= 0
          assert start_epoch <= epoch
          assert epoch <= epochs
          calced_epoch = epoch-start_epoch
          eta_msg = etafilter.print(calced_epoch, do_print=False)
          LOGGER.info(eta_msg)
      except:
          pass
          
  etafilter = eta.Eta(epochs-start_epoch, 0)
 # ADD to here..
  for epoch in range(start_epoch, epochs):  # epoch ------------------------------------------------------------------

and the call to the filter

  LoggerPrintEta(etafilter, start_epoch, epoch, epochs)

again in train.py line 303 (approx), just after pbar and before LOGGER.info:

   pbar = enumerate(train_loader)
   # ADD from here..
   LoggerPrintEta(etafilter, start_epoch, epoch, epochs)
   # ADD tohere..
   LOGGER.info(('\n' + '%10s' * 7) % ('Epoch', 'gpu_mem', 'box', 'obj', 'cls', 'labels', 'img_size'))`	

And also remember to put the eta.py in, say the utils dir and add

from utils import eta

to the import clauses in the beginning of the train.py file.

Then, when you run training, it also put out estimated-time-of-arrival like

Starting training for 300 epochs...
     0/299      =  0.3%,  elapsed=  0.0 s = 00:00,   total = 00:00 / 00:00,  remain = 00:00 / 00:00 (direct / filtered)

     Epoch   gpu_mem       box       obj       cls    labels  img_size
     0/299     7.88G    0.1229     0.201   0.03912       532      1024: 100%|██████████| 23/23 [00:09<00:00,  2.36it/s]
               Class     Images     Labels          P          R     mAP@.5 mAP@.5:.95: 100%|██████████| 4/4 [00:03<00:00,  1.11it/s]
                 all         97       3618    0.00513     0.0528    0.00238   0.000545
     1/299      =  0.7%,  elapsed= 13.9 s = 00:14,   total = 34:47 / 03:29,  remain = 34:33 / 03:27 (direct / filtered)

     Epoch   gpu_mem       box       obj       cls    labels  img_size
     1/299        9G    0.1184    0.1811   0.03489       462      1024: 100%|██████████| 23/23 [00:08<00:00,  2.60it/s]
               Class     Images     Labels          P          R     mAP@.5 mAP@.5:.95: 100%|██████████| 4/4 [00:03<00:00,  1.13it/s]
                 all         97       3618     0.0136     0.0856    0.00705    0.00167
     2/299      =  1.0%,  elapsed= 26.9 s = 00:27,   total = 44:52 / 07:37,  remain = 44:25 / 07:33 (direct / filtered)

     Epoch   gpu_mem       box       obj       cls    labels  img_size
     2/299        9G    0.1111     0.168   0.03107       292      1024: 100%|██████████| 23/23 [00:08<00:00,  2.59it/s]

Notice, if there is an early-stopping at play, the filter will miscalculate the eta, since it is based on the number of epochs.

The eta.py file:

#!/bin/env python3

import sys, time

class Eta:
	# NOTE; N=0 for non MPI build, and precond will fail
	#@pre_condition(lambda self, N, mod_factor=1024, interval=30: isPositive(N) and isInt(mod_factor) and isNatural(interval))
	def __init__(self, N, mod_factor=1024, interval=30, warmupiterations=32):

		assert isinstance(N, int),          f"expected N to be an int, but found it to be an {type(N)}"
		assert isinstance(mod_factor, int), f"expected mod_factor to be an int, but found it to be an {type(mod_factor)}"
		assert isinstance(interval, int),   f"expected interval to be an int, but found it to be an {type(interval)}"
	
		assert N > 0               , f"expected N > 0, but found N={N}"
		assert mod_factor >= 0     , f"expected mod_factor >= 0, but found mod_factor={mod_factor}"
		assert interval >= 0       , f"expected intervalk >= 0, but found interval={interval}"
		assert warmupiterations > 0, f"expected warmupiterations > 0, but found warmupiterations={warmupiterations}"  

		self.__N = N
		self.__mod_factor = mod_factor
		self.__interval = interval
		self.__warmupiterations = warmupiterations
		self.__tic = time.time()
		self.__last = self.__tic
		self.__filter_total  = -1
		self.__filter_remain = -1

	#@pre_condition(lambda self, i, do_print=True: isInt(i) and i>=0 and isBool(do_print))
	#@post_condition(lambda ret: isStr(ret, False))
	def print(self, i, do_print=True, use_stderr=True, add_colors=True, print_all_iterations=True, simple_print=False):
		try:
			assert isinstance(i, int),                    f"expected i to be an int, but found it to be an {type(i)}"
			assert i>=0 and i<self.__N,                   f"expected i>=0 and i<{self.__N}, but found it to be {i}"
			assert isinstance(do_print, bool),            f"expected do_print to be an bool, but found it to be an {type(do_print)}"
			assert isinstance(add_colors, bool),          f"expected add_colors to be an bool, but found it to be an {type(add_colors)}"
			assert isinstance(print_all_iterations, bool),f"expected print_all_iterations to be an bool, but found it to be an {type(print_all_iterations)}"
			assert isinstance(simple_print, bool),        f"expected simple_print to be an bool, but found it to be an {type(simple_print)}"

			r = ""
			if i+1==self.__N or self.__mod_factor<=0 or i % self.__mod_factor==0 or i==self.__warmupiterations:

				if i >= self.__N:
					Eta._WARN(f"ETA i={i} is >= N={self.__N}; expectation was i<N, returning empty string")
					return ""

				t = time.time()
				if not print_all_iterations and i!=self.__warmupiterations:
					if t-self.__last < self.__interval:
						return ""

				self.__last=t

				diff = t-self.__tic
				assert diff>=0, f"expected diff >= 0, but found it to be {diff}"

				p = 100.0*(i+1)/self.__N
				assert isinstance(p, float), f"expected p to be an float, but found it to be an {type(p)}"

				if p==0:
					return r
				if p<0 or p>100:
					Eta._WARN(f"ETA p={p} > 100%; expected it to be in the range [0;100]%, returning empty string")
					return ""

				total  = diff/p
				remain = total * (100-p)
				total *= 100

				if self.__filter_total < 0 or self.__filter_remain < 0:
					self.__filter_total  = total
					self.__filter_remain = remain
				else:
					self.__filter_total  = self.__filter_total  * 0.9 + 0.1 * total
					self.__filter_remain = self.__filter_remain * 0.9 + 0.1 * remain

				if add_colors:
					cn = "\033[0m"
					c0 = "\033[1;35m"
				else:
					cn = ""
					c0 = ""
				
				r = f"{c0}{i:>6d}/{self.__N-1:<8d} ={p:>5.1f}%,  elapsed={diff:>5.1f} s = {Eta._HMS(diff)}"
				if not simple_print:
					r += f",   total = {Eta._HMS(total)} / {Eta._HMS(self.__filter_total)},  remain = {Eta._HMS(remain)} / {Eta._HMS(self.__filter_remain)} (direct / filtered)"
				r += cn

				if do_print:
					if use_stderr:
						sys.stdout.flush()
						print(r, file=sys.stderr)
						sys.stderr.flush()
					else:
						print(r)
						sys.stdout.flush()

			return r
		except Exception as ex:
			Eta._WARN(f"exception {ex} occured in ETA print, returning empty string")
			return ""

	def __getitem__(self, i):
		return self.print(i)

	@staticmethod
	def _WARN(msg):
		print(f"WARNING(Eta): {msg}", file=sys.stderr)

	@staticmethod
	#@pre_condition(lambda t, add_hhmmss_suffix=False: isFloat(t) and t>=0 and isBool(add_hhmmss_suffix))
	#@post_condition(lambda ret: isStr(ret))
	def _HMS(t, add_hhmmss_suffix=False):
		try:
			t = int(t+0.5)

			yy = t//(60*60*24*356)
			ys = yy*(60*60*24*356)
			
			dd = (t-ys)//(60*60*24)
			ds = dd*60*60*24
			assert t>=ds and ds>=0 and dd<356, f"expected t>=ds and ds>=0 and dd<365, with t={t}, ds={ds}, dd={dd}"

			hh = (t-ds-ys)//(60*60)
			hs = hh*60*60
			assert t>=hs and hs>=0 and hh<24, f"expected t>=hs and hs>=0 and hh<24, with t={t}, hs={hs}, hh={hh}"

			mm = (t-hs-ds-ys)//60
			ms = mm*60
			assert t>=ms and ms>=0 and mm<60, f"expected t>=ms and ms>=0 and mm<60, with t={t}, ms={ms}, mm={mm}"
			
			ss = t - ms - hs - ds - ys

			assert isinstance(ss, int), f"ss is not a int but instead a {type(ss)}"
			assert ss >= 0  , f"ss={ss} is < 0"
			assert ss < 60  , f"ss={ss} is > 60"   
			assert ss + ms + hs + ds + ys == t, f"ys + ds + hs + ms + ss (={ss + ms + hs + ds + ys}) is not equal t={t}"

			r = ""
			sfx = " "
			if yy>0:
				r += f"{yy} " + ("years " if yy>1 else "year ")
				sfx += ""
			if dd>0:
				r += f"{dd} " + ("days " if dd>1 else "day ")
				sfx += ""
			if hh>0:
				r += f"{hh:>02d}:"
				sfx += "hh:"
			#else:
			#	r += "   "
			if True or mm>0 or hh>0:
				r += f"{mm:>02d}:"
				sfx += "mm:"
			r += f"{ss:>02d}"

			sfx += "ss"
			
			return r + (sfx if add_hhmmss_suffix else "")
		except Exception as ex:
			Eta._WARN(f"exception {ex} occured in ETA HMS, returning empty string")
			return ""

if __name__=='__main__':
	try:
		print("TEST Eta..")
		n = 16
		mod = 8
		print(f"  testing mod_factor={mod}, n={n} and simple_print=True..")
		eta = Eta(n, mod_factor=mod)
		for i in range(n):
			time.sleep(0.1)
			eta.print(i, simple_print=True)
	
		interval = 2
		warmupiterations = 1
		print(f"  testing mod_factor=0, interval={interval},  warmupiterations={warmupiterations} and print_all_iterations=True..")	
		eta = Eta(n, mod_factor=0,  interval=interval, warmupiterations=warmupiterations)
		for i in range(n):
			time.sleep(1)
			eta.print(i, print_all_iterations=False)
		print("TEST Eta DONE")	
	except Exception as ex:
		print(f"EXCEPTION occured: {ex}")
		exit(-1)