<div dir="ltr"><div dir="ltr">Hi Kieran,<div><br></div></div><div class="gmail_quote"><div dir="ltr" class="gmail_attr">On Fri, 12 Mar 2021 at 13:12, Kieran Bingham <<a href="mailto:kieran.bingham@ideasonboard.com">kieran.bingham@ideasonboard.com</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">Hi Naush,<br>
<br>
On 04/03/2021 08:17, Naushir Patuck wrote:<br>
> This script will parse log output from the DelayedControls helper, when<br>
> enabled with:<br>
> <br>
> LIBCAMERA_LOG_LEVELS=DelayedControls:0<br>
> <br>
> It tabulates all control queuing/writing/getting per frame and warns<br>
> about potential issues related to frame delays not being account for, or<br>
> writes that are lagging behind or missed.<br>
> <br>
> Run with the following command:<br>
> <br>
> python3 ./delayedctrls_parse.py <logfile><br>
> <br>
> Signed-off-by: Naushir Patuck <<a href="mailto:naush@raspberrypi.com" target="_blank">naush@raspberrypi.com</a>><br>
> Tested-by: David Plowman <<a href="mailto:david.plowman@raspberrypi.com" target="_blank">david.plowman@raspberrypi.com</a>><br>
> Acked-by: Paul Elder <<a href="mailto:paul.elder@ideasonboard.com" target="_blank">paul.elder@ideasonboard.com</a>><br>
<br>
This patch has the following checkstyle warnings:<br>
<br>
3ea0b3f4bee5670b4e46045836dee48928c3e1f2 utils: raspberrypi: Add a<br>
DelayedControls log parser<br>
---------------------------------------------------------------------------------------------<br>
--- utils/raspberrypi/delayedctrls_parse.py<br>
+++ utils/raspberrypi/delayedctrls_parse.py<br>
#13: : W605 invalid escape sequence '\d'<br>
+frame_re = re.compile('frame (\d+) started')<br>
#29: : W605 invalid escape sequence '\d'<br>
+ 'Write': re.compile('Setting (.*?) to (\d+) at index (\d+)'),<br>
#29: : W605 invalid escape sequence '\d'<br>
+ 'Write': re.compile('Setting (.*?) to (\d+) at index (\d+)'),<br>
#31: : W605 invalid escape sequence '\d'<br>
+ 'Get': re.compile('Reading (.*?) to (\d+) at index (\d+)'),<br>
#31: : W605 invalid escape sequence '\d'<br>
+ 'Get': re.compile('Reading (.*?) to (\d+) at index (\d+)'),<br>
#32: : W605 invalid escape sequence '\d'<br>
+ 'Queue': re.compile('Queuing (.*?) to (\d+) at index (\d+)')<br>
#32: : W605 invalid escape sequence '\d'<br>
+ 'Queue': re.compile('Queuing (.*?) to (\d+) at index (\d+)')<br>
---<br>
7 potential issues detected, please review<br>
<br>
<br>
If you have pycodestyle installed (the pep8 update) you should get these<br>
checks.<br></blockquote><div><br></div><div>Will do!</div><div> </div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
<br>
<br>
Prefixing the regex string with an 'r' fixes these.<br>
<br>
<br>
If you're happy, and there' turns out to be no need to repost<br>
(I'm hoping not) I'll apply the following fix:<br></blockquote><div><br></div><div>Happy for you to fixup when merging if it is convenient.</div><div><br></div><div>Regards,</div><div>Naush</div><div><br></div><div> </div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
<br>
<br>
> diff --git a/utils/raspberrypi/delayedctrls_parse.py b/utils/raspberrypi/delayedctrls_parse.py<br>
> index 3965b86daaaf..e38145d8e98e 100644<br>
> --- a/utils/raspberrypi/delayedctrls_parse.py<br>
> +++ b/utils/raspberrypi/delayedctrls_parse.py<br>
> @@ -10,7 +10,7 @@ infile = sys.argv[1]<br>
> insplit = os.path.splitext(infile)<br>
> outfile = insplit[0] + '_parsed' + insplit[1]<br>
> <br>
> -frame_re = re.compile('frame (\d+) started')<br>
> +frame_re = re.compile(r'frame (\d+) started')<br>
> <br>
> delays = {<br>
> 'Analogue Gain': 1,<br>
> (1/2) Stage this hunk [y,n,q,a,d,j,J,g,/,e,?]? y<br>
> @@ -26,10 +26,10 @@ ctrl_action = {<br>
> }<br>
> <br>
> ctrl_re = {<br>
> - 'Write': re.compile('Setting (.*?) to (\d+) at index (\d+)'),<br>
> - 'No-op': re.compile('Queue is empty, (.*?) (.*?) (.*?)'),<br>
> - 'Get': re.compile('Reading (.*?) to (\d+) at index (\d+)'),<br>
> - 'Queue': re.compile('Queuing (.*?) to (\d+) at index (\d+)')<br>
> + 'Write': re.compile(r'Setting (.*?) to (\d+) at index (\d+)'),<br>
> + 'No-op': re.compile(r'Queue is empty, (.*?) (.*?) (.*?)'),<br>
> + 'Get': re.compile(r'Reading (.*?) to (\d+) at index (\d+)'),<br>
> + 'Queue': re.compile(r'Queuing (.*?) to (\d+) at index (\d+)')<br>
> }<br>
> <br>
> frame_num = -1<br>
<br>
<br>
<br>
<br>
<br>
<br>
> ---<br>
> utils/raspberrypi/delayedctrls_parse.py | 111 ++++++++++++++++++++++++<br>
> 1 file changed, 111 insertions(+)<br>
> create mode 100644 utils/raspberrypi/delayedctrls_parse.py<br>
> <br>
> diff --git a/utils/raspberrypi/delayedctrls_parse.py b/utils/raspberrypi/delayedctrls_parse.py<br>
> new file mode 100644<br>
> index 000000000000..3965b86daaaf<br>
> --- /dev/null<br>
> +++ b/utils/raspberrypi/delayedctrls_parse.py<br>
> @@ -0,0 +1,111 @@<br>
> +import re<br>
> +import sys<br>
> +import os<br>
> +<br>
> +if len(sys.argv) != 2:<br>
> + print("Usage: {} <infile>".format(sys.argv[0]))<br>
> + sys.exit()<br>
> +<br>
> +infile = sys.argv[1]<br>
> +insplit = os.path.splitext(infile)<br>
> +outfile = insplit[0] + '_parsed' + insplit[1]<br>
> +<br>
> +frame_re = re.compile('frame (\d+) started')<br>
> +<br>
> +delays = {<br>
> + 'Analogue Gain': 1,<br>
> + 'Exposure': 2,<br>
> + 'Vertical Blanking': 2<br>
> +}<br>
<br>
Are these sensor dependant ?<br>
<br>
Otherwise, with the raw string prefix,<br>
<br>
Reviewed-by: Kieran Bingham <<a href="mailto:kieran.bingham@ideasonboard.com" target="_blank">kieran.bingham@ideasonboard.com</a>><br>
<br>
> +<br>
> +ctrl_action = {<br>
> + 'Write': {},<br>
> + 'Get': {},<br>
> + 'Queue': {},<br>
> + 'No-op': {}<br>
> +}<br>
> +<br>
> +ctrl_re = {<br>
> + 'Write': re.compile('Setting (.*?) to (\d+) at index (\d+)'),<br>
> + 'No-op': re.compile('Queue is empty, (.*?) (.*?) (.*?)'),<br>
> + 'Get': re.compile('Reading (.*?) to (\d+) at index (\d+)'),<br>
> + 'Queue': re.compile('Queuing (.*?) to (\d+) at index (\d+)')<br>
> +}<br>
> +<br>
> +frame_num = -1<br>
> +<br>
> +max_delay = 0<br>
> +for k, d in delays.items():<br>
> + if max_delay < d:<br>
> + max_delay = d<br>
> +<br>
> +with open(infile) as f:<br>
> + lines = f.readlines()<br>
> +<br>
> +for line in lines:<br>
> + r = frame_re.search(line)<br>
> + if r:<br>
> + frame_num = int(r.group(1))<br>
> +<br>
> + for (key, re) in ctrl_re.items():<br>
> + r = re.search(line)<br>
> + if r:<br>
> + ctrl_action[key][(frame_num, r.group(1))] = (r.group(2), r.group(3))<br>
> +<br>
> +with open(outfile, 'wt') as f:<br>
> + queueIndex = 1<br>
> + f.write('{:<10}{:<15}{:<12}{:<18}{}\n'.format('Frame', 'Action', 'Gain', 'Exposure', 'Vblank'))<br>
> + for frame in range(0, frame_num + 1):<br>
> + for (k, a) in ctrl_action.items():<br>
> + str = '{:<10}{:<10}'.format(frame, k)<br>
> +<br>
> + for c in delays.keys():<br>
> + # Tabulate all results<br>
> + str += '{:>5} {:<10}'.format(a[(frame, c)][0] if (frame, c) in a.keys() else '---',<br>
> + '[' + (a[(frame, c)][1] if (frame, c) in a.keys() else '-') + ']')<br>
> +<br>
> + f.write(str.strip() + '\n')<br>
> +<br>
> +# Test the write -> get matches the set delay.<br>
> +for (frame, c) in ctrl_action['Write'].keys():<br>
> + set_value = ctrl_action['Write'][(frame, c)][0]<br>
> + delay_frame = frame + delays[c]<br>
> + if (delay_frame <= frame_num):<br>
> + if (delay_frame, c) in ctrl_action['Get']:<br>
> + get_value = ctrl_action['Get'][(delay_frame, c)][0]<br>
> + if get_value != set_value:<br>
> + print('Error: {} written at frame {} to value {} != {} at frame {}'<br>
> + .format(c, frame, set_value, get_value, delay_frame))<br>
> + else:<br>
> + print('Warning: {} written at frame {} to value {} did not get logged on frame {} - dropped frame?'<br>
> + .format(c, frame, set_value, delay_frame))<br>
> +<br>
> +# Test the queue -> write matches the set delay.<br>
> +for (frame, c) in ctrl_action['Queue'].keys():<br>
> + set_value = ctrl_action['Queue'][(frame, c)][0]<br>
> + delay_frame = frame + max_delay - delays[c] + 1<br>
> + if (delay_frame <= frame_num):<br>
> + if (delay_frame, c) in ctrl_action['Write']:<br>
> + write_value = ctrl_action['Write'][(delay_frame, c)][0]<br>
> + if write_value != set_value:<br>
> + print('Info: {} queued at frame {} to value {} != {} written at frame {}'<br>
> + ' - lagging behind or double queue on a single frame!'<br>
> + .format(c, frame, set_value, write_value, delay_frame))<br>
> + else:<br>
> + print('Warning: {} queued at frame {} to value {} did not get logged on frame {} - dropped frame?'<br>
> + .format(c, frame, set_value, delay_frame))<br>
> +<br>
> +# Test the get -> write matches the set delay going backwards.<br>
> +for (frame, c) in ctrl_action['Get'].keys():<br>
> + get_value = ctrl_action['Get'][(frame, c)][0]<br>
> + delay_frame = frame - delays[c]<br>
> + if (delay_frame >= 6):<br>
> + if (delay_frame, c) in ctrl_action['Write']:<br>
> + write_value = ctrl_action['Write'][(delay_frame, c)][0]<br>
> + if get_value != write_value:<br>
> + print('Info: {} got at frame {} to value {} != {} written at frame {}'<br>
> + ' - lagging behind or double queue on a single frame!'<br>
> + .format(c, frame, get_value, write_value, delay_frame))<br>
> + else:<br>
> + print('Warning: {} got at frame {} to value {} did not get written on frame {}'<br>
> + .format(c, frame, get_value, delay_frame))<br>
> <br>
<br>
-- <br>
Regards<br>
--<br>
Kieran<br>
</blockquote></div></div>