Fix log_info/log_err printing with progress bars

**Issue**
While a TQDM progress bar is active using a standard 'print' will cause unpredicable output. In most cases this causes the progress bar to be duplicated/frozen next to the log message:
```
Running on CPU0.
Running on CPU1.
Converting:   0% 0/356 [00:00<?, ?it/s]no faces found for 00001.png, copying without faces
Converting:   0% 1/356 [00:00<00:02, 165.12it/s]no faces found for 00002.png, copying without faces
Converting:   1% 2/356 [00:00<00:01, 318.97it/s]no faces found for 00003.png, copying without faces
Converting:   1% 3/356 [00:00<00:01, 255.22it/s]no faces found for 00004.png, copying without faces
Converting:   1% 4/356 [00:00<00:01, 333.46it/s]no faces found for 00005.png, copying without faces
Converting:   1% 5/356 [00:00<00:01, 287.34it/s]no faces found for 00006.png, copying without faces
Converting:   2% 6/356 [00:00<00:01, 340.82it/s]no faces found for 00007.png, copying without faces
Converting:   2% 7/356 [00:00<00:01, 301.00it/s]no faces found for 00008.png, copying without faces
Converting:   2% 8/356 [00:00<00:01, 341.15it/s]no faces found for 00009.png, copying without faces
Converting:   3% 9/356 [00:00<00:01, 310.79it/s]no faces found for 00010.png, copying without faces
Converting:   3% 10/356 [00:00<00:01, 342.98it/s]no faces found for 00011.png, copying without faces
Converting:   3% 11/356 [00:00<00:01, 317.86it/s]no faces found for 00012.png, copying without faces
Converting:   3% 12/356 [00:00<00:00, 344.40it/s]no faces found for 00013.png, copying without faces
Converting:   4% 13/356 [00:00<00:01, 322.13it/s]no faces found for 00014.png, copying without faces
```
**Resolution**
This can be mitigated by changing `log_info` and `log_err` to be aware of the presence of a progress bar and use `tqdm.write()` instead of `print()` if one exists:
```
Running on CPU0.
Running on CPU1.
no faces found for 00001.png, copying without faces
no faces found for 00002.png, copying without faces
no faces found for 00003.png, copying without faces
no faces found for 00004.png, copying without faces
no faces found for 00005.png, copying without faces
...
no faces found for 00197.png, copying without faces
no faces found for 00198.png, copying without faces
no faces found for 00199.png, copying without faces
Converting:  57% 203/356 [00:01<00:01, 120.22it/s]
```
**Method**
For `log_info` if a pb is running `tqdm.write` is attempted, if it fails a normal print is used. Likewise with `log_err` except that the msg is prefixed by `self.error_log_line_prefix`, `/!\`, to denote increased severity.

`progress_bar_generator()` has been updated to set `self.pb_bar` like the `progress_bar()` function and then clean up when the generator expires. Without this the class is unaware of the running pb since `self.pb_bar` remains defaulted to `None`.

**Result**
This doesn't completely fix the problem, there is still a lot of normal `print()` calls that will need to be updated eventually to use these for printing.
```
Loading:   3% 30/1000 [00:00<00:03, 297.17it/s]No Valid PNG header
00100.png is not a dfl image file required for training
Loading:  13% 126/1000 [00:00<00:02, 374.53it/s]No Valid PNG header
00200.png is not a dfl image file required for training
Loading:  30% 296/1000 [00:00<00:01, 519.82it/s]No Valid PNG header
00300.png is not a dfl image file required for training
Loading:  38% 380/1000 [00:00<00:01, 586.20it/s]No Valid PNG header
00400.png is not a dfl image file required for training
```
`No Valid PNG header` has not been updated to use `log_info`, causes duplicate progress bars. `<X> is not a dfl image file required for training` does use `log_info` and prints correctly. A majority of the commonly seen messages are covered, so this is still very worthwhile from a UX perspective.
This commit is contained in:
Auroir 2019-08-16 16:06:47 -07:00 committed by GitHub
commit c795e5258a
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23

View file

@ -33,6 +33,7 @@ class InteractBase(object):
self.key_events = {} self.key_events = {}
self.pg_bar = None self.pg_bar = None
self.focus_wnd_name = None self.focus_wnd_name = None
self.error_log_line_prefix = '/!\\ '
def is_support_windows(self): def is_support_windows(self):
return False return False
@ -65,10 +66,22 @@ class InteractBase(object):
raise NotImplemented raise NotImplemented
def log_info(self, msg, end='\n'): def log_info(self, msg, end='\n'):
if self.pg_bar is not None:
try: # Attempt print before the pb
tqdm.write(msg)
return
except:
pass #Fallback to normal print upon failure
print (msg, end=end) print (msg, end=end)
def log_err(self, msg, end='\n'): def log_err(self, msg, end='\n'):
print (msg, end=end) if self.pg_bar is not None:
try: # Attempt print before the pb
tqdm.write(f'{self.error_log_line_prefix}{msg}')
return
except:
pass #Fallback to normal print upon failure
print (f'{self.error_log_line_prefix}{msg}', end=end)
def named_window(self, wnd_name): def named_window(self, wnd_name):
if wnd_name not in self.named_windows: if wnd_name not in self.named_windows:
@ -150,9 +163,12 @@ class InteractBase(object):
else: print("progress_bar not set.") else: print("progress_bar not set.")
def progress_bar_generator(self, data, desc, leave=True): def progress_bar_generator(self, data, desc, leave=True):
for x in tqdm( data, desc=desc, leave=leave, ascii=True ): self.pg_bar = tqdm( data, desc=desc, leave=leave, ascii=True )
for x in self.pg_bar:
yield x yield x
self.pg_bar.close()
self.pg_bar = None
def process_messages(self, sleep_time=0): def process_messages(self, sleep_time=0):
self.on_process_messages(sleep_time) self.on_process_messages(sleep_time)