<p>Falkenber9 has uploaded this change for <strong>review</strong>.</p><p><a href="https://gerrit.osmocom.org/c/pysim/+/24034">View Change</a></p><pre style="font-family: monospace,monospace; white-space: pre-wrap;">Improve performance of AT command interface<br><br>Previous implementation waits 300ms for response after<br>each command issued. But many commands finish earlier.<br><br>This patch improves the command execution time by frequently<br>checking for the response to complete (i.e. ends with<br>OK or ERROR), or the occurence of a timeout (default 200ms).<br><br>Timeout can be adapted per command to support long response<br>times of certain commands like AT+COPS=? (network search)<br><br>Change-Id: I69b1cbc0a20d54791e5800bf27ebafc2c8606d93<br>---<br>A benchmark_at.py<br>M pySim/transport/modem_atcmd.py<br>2 files changed, 105 insertions(+), 6 deletions(-)<br><br></pre><pre style="font-family: monospace,monospace; white-space: pre-wrap;">git pull ssh://gerrit.osmocom.org:29418/pysim refs/changes/34/24034/1</pre><pre style="font-family: monospace,monospace; white-space: pre-wrap;"><span>diff --git a/benchmark_at.py b/benchmark_at.py</span><br><span>new file mode 100755</span><br><span>index 0000000..ca6095b</span><br><span>--- /dev/null</span><br><span>+++ b/benchmark_at.py</span><br><span>@@ -0,0 +1,33 @@</span><br><span style="color: hsl(120, 100%, 40%);">+#!/usr/bin/env python3</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+import logging as log</span><br><span style="color: hsl(120, 100%, 40%);">+import time</span><br><span style="color: hsl(120, 100%, 40%);">+from pySim.transport.modem_atcmd import ModemATCommandLink</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+#log.root.setLevel(log.DEBUG)</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+tty = "/dev/ttyUSB2"</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+# Use old code</span><br><span style="color: hsl(120, 100%, 40%);">+tt = time.time()</span><br><span style="color: hsl(120, 100%, 40%);">+tp = time.process_time()</span><br><span style="color: hsl(120, 100%, 40%);">+modem = ModemATCommandLink(tty)</span><br><span style="color: hsl(120, 100%, 40%);">+for i in range(10):</span><br><span style="color: hsl(120, 100%, 40%);">+ modem.send_at_cmd_old("ATI")</span><br><span style="color: hsl(120, 100%, 40%);">+ modem.send_at_cmd_old("AT+CIMI")</span><br><span style="color: hsl(120, 100%, 40%);">+print("Old execution time: {:.6f}s (CPU: {:.6f}s)".format(time.time() - tt, time.process_time() - tp))</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+# Use new code</span><br><span style="color: hsl(120, 100%, 40%);">+tt = time.time()</span><br><span style="color: hsl(120, 100%, 40%);">+tp = time.process_time()</span><br><span style="color: hsl(120, 100%, 40%);">+modem = ModemATCommandLink(tty)</span><br><span style="color: hsl(120, 100%, 40%);">+for i in range(10):</span><br><span style="color: hsl(120, 100%, 40%);">+ modem.send_at_cmd("ATI")</span><br><span style="color: hsl(120, 100%, 40%);">+ modem.send_at_cmd("AT+CIMI")</span><br><span style="color: hsl(120, 100%, 40%);">+print("New execution time: {:.6f}s (CPU: {:.6f}s)".format(time.time() - tt, time.process_time() - tp))</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+# Use new code for long-term command (i.e. network search)</span><br><span style="color: hsl(120, 100%, 40%);">+# tt = time.time()</span><br><span style="color: hsl(120, 100%, 40%);">+# tp = time.process_time()</span><br><span style="color: hsl(120, 100%, 40%);">+# modem.send_at_cmd("AT+COPS=?", timeout=60)</span><br><span style="color: hsl(120, 100%, 40%);">+# print("Network search: {:.6f}s (CPU: {:.6f}s)".format(time.time() - tt, time.process_time() - tp))</span><br><span>diff --git a/pySim/transport/modem_atcmd.py b/pySim/transport/modem_atcmd.py</span><br><span>index eef38cb..55f3a00 100644</span><br><span>--- a/pySim/transport/modem_atcmd.py</span><br><span>+++ b/pySim/transport/modem_atcmd.py</span><br><span>@@ -32,16 +32,64 @@</span><br><span> def __init__(self, device:str='/dev/ttyUSB0', baudrate:int=115200, **kwargs):</span><br><span> super().__init__(**kwargs)</span><br><span> self._sl = serial.Serial(device, baudrate, timeout=5)</span><br><span style="color: hsl(120, 100%, 40%);">+ self._echo = False # this will be auto-detected by _check_echo()</span><br><span> self._device = device</span><br><span> self._atr = None</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+ # Check the AT interface</span><br><span style="color: hsl(120, 100%, 40%);">+ self._check_echo()</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> # Trigger initial reset</span><br><span> self.reset_card()</span><br><span> </span><br><span> def __del__(self):</span><br><span> self._sl.close()</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- def send_at_cmd(self, cmd):</span><br><span style="color: hsl(120, 100%, 40%);">+ def send_at_cmd(self, cmd, timeout=0.2, patience=0.002):</span><br><span style="color: hsl(120, 100%, 40%);">+ # Convert from string to bytes, if needed</span><br><span style="color: hsl(120, 100%, 40%);">+ bcmd = cmd if type(cmd) is bytes else cmd.encode()</span><br><span style="color: hsl(120, 100%, 40%);">+ bcmd += b'\r'</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ # Clean input buffer from previous/unexpected data</span><br><span style="color: hsl(120, 100%, 40%);">+ self._sl.reset_input_buffer()</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ # Send command to the modem</span><br><span style="color: hsl(120, 100%, 40%);">+ log.debug('Sending AT command: {}'.format(cmd))</span><br><span style="color: hsl(120, 100%, 40%);">+ try:</span><br><span style="color: hsl(120, 100%, 40%);">+ wlen = self._sl.write(bcmd)</span><br><span style="color: hsl(120, 100%, 40%);">+ assert(wlen == len(bcmd))</span><br><span style="color: hsl(120, 100%, 40%);">+ except:</span><br><span style="color: hsl(120, 100%, 40%);">+ raise ReaderError('Failed to send AT command: {}'.format(cmd))</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ rsp = b''</span><br><span style="color: hsl(120, 100%, 40%);">+ its = 1</span><br><span style="color: hsl(120, 100%, 40%);">+ t_start = time.time()</span><br><span style="color: hsl(120, 100%, 40%);">+ while True:</span><br><span style="color: hsl(120, 100%, 40%);">+ rsp = rsp + self._sl.read(self._sl.in_waiting)</span><br><span style="color: hsl(120, 100%, 40%);">+ if rsp.endswith(b'OK\r\n'):</span><br><span style="color: hsl(120, 100%, 40%);">+ log.debug('Command finished with result: OK')</span><br><span style="color: hsl(120, 100%, 40%);">+ break</span><br><span style="color: hsl(120, 100%, 40%);">+ if rsp.endswith(b'ERROR\r\n'):</span><br><span style="color: hsl(120, 100%, 40%);">+ log.debug('Command finished with result: ERROR')</span><br><span style="color: hsl(120, 100%, 40%);">+ break</span><br><span style="color: hsl(120, 100%, 40%);">+ if time.time() - t_start >= timeout:</span><br><span style="color: hsl(120, 100%, 40%);">+ log.debug('Command finished with timeout >= {}s'.format(timeout))</span><br><span style="color: hsl(120, 100%, 40%);">+ break</span><br><span style="color: hsl(120, 100%, 40%);">+ else:</span><br><span style="color: hsl(120, 100%, 40%);">+ time.sleep(patience)</span><br><span style="color: hsl(120, 100%, 40%);">+ its += 1</span><br><span style="color: hsl(120, 100%, 40%);">+ log.debug('Command took {:.6f}s ({} cycles a {}s)'.format(time.time() - t_start, its, patience))</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ if self._echo:</span><br><span style="color: hsl(120, 100%, 40%);">+ # Skip echo chars</span><br><span style="color: hsl(120, 100%, 40%);">+ rsp = rsp[wlen:]</span><br><span style="color: hsl(120, 100%, 40%);">+ rsp = rsp.strip()</span><br><span style="color: hsl(120, 100%, 40%);">+ rsp = rsp.split(b'\r\n\r\n')</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ log.debug('Got response from modem: {}'.format(rsp))</span><br><span style="color: hsl(120, 100%, 40%);">+ return rsp</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ def send_at_cmd_old(self, cmd):</span><br><span> # Convert from string to bytes, if needed</span><br><span> bcmd = cmd if type(cmd) is bytes else cmd.encode()</span><br><span> bcmd += b'\r'</span><br><span>@@ -74,11 +122,29 @@</span><br><span> log.debug('Got response from modem: %s' % rsp)</span><br><span> return rsp</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- def reset_card(self):</span><br><span style="color: hsl(0, 100%, 40%);">- # Make sure that we can talk to the modem</span><br><span style="color: hsl(0, 100%, 40%);">- if self.send_at_cmd('AT') != [b'OK']:</span><br><span style="color: hsl(0, 100%, 40%);">- raise ReaderError('Failed to connect to modem')</span><br><span style="color: hsl(120, 100%, 40%);">+ def _check_echo(self):</span><br><span style="color: hsl(120, 100%, 40%);">+ """Verify the correct response to 'AT' command</span><br><span style="color: hsl(120, 100%, 40%);">+ and detect if inputs are echoed by the device</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+ Although echo of inputs can be enabled/disabled via</span><br><span style="color: hsl(120, 100%, 40%);">+ ATE1/ATE0, respectively, we rather detect the current</span><br><span style="color: hsl(120, 100%, 40%);">+ configuration of the modem without any change.</span><br><span style="color: hsl(120, 100%, 40%);">+ """</span><br><span style="color: hsl(120, 100%, 40%);">+ # Next command shall not strip the echo from the response</span><br><span style="color: hsl(120, 100%, 40%);">+ self._echo = False</span><br><span style="color: hsl(120, 100%, 40%);">+ result = self.send_at_cmd('AT')</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ # Verify the response</span><br><span style="color: hsl(120, 100%, 40%);">+ if len(result) > 0:</span><br><span style="color: hsl(120, 100%, 40%);">+ if result[-1] == b'OK':</span><br><span style="color: hsl(120, 100%, 40%);">+ self._echo = False</span><br><span style="color: hsl(120, 100%, 40%);">+ return</span><br><span style="color: hsl(120, 100%, 40%);">+ elif result[-1] == b'AT\r\r\nOK':</span><br><span style="color: hsl(120, 100%, 40%);">+ self._echo = True</span><br><span style="color: hsl(120, 100%, 40%);">+ return</span><br><span style="color: hsl(120, 100%, 40%);">+ raise ReaderError('Interface "{}" does not respond to "AT" command'.format(self._device))</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ def reset_card(self):</span><br><span> # Reset the modem, just to be sure</span><br><span> if self.send_at_cmd('ATZ') != [b'OK']:</span><br><span> raise ReaderError('Failed to reset the modem')</span><br><span>@@ -87,7 +153,7 @@</span><br><span> if self.send_at_cmd('AT+CSIM=?') != [b'OK']:</span><br><span> raise ReaderError('The modem does not seem to support SIM access')</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- log.info('Modem at \'%s\' is ready!' % self._device)</span><br><span style="color: hsl(120, 100%, 40%);">+ log.info('Modem at "{}" is ready!'.format(self._device))</span><br><span> </span><br><span> def connect(self):</span><br><span> pass # Nothing to do really ...</span><br><span></span><br></pre><p>To view, visit <a href="https://gerrit.osmocom.org/c/pysim/+/24034">change 24034</a>. To unsubscribe, or for help writing mail filters, visit <a href="https://gerrit.osmocom.org/settings">settings</a>.</p><div itemscope itemtype="http://schema.org/EmailMessage"><div itemscope itemprop="action" itemtype="http://schema.org/ViewAction"><link itemprop="url" href="https://gerrit.osmocom.org/c/pysim/+/24034"/><meta itemprop="name" content="View Change"/></div></div>
<div style="display:none"> Gerrit-Project: pysim </div>
<div style="display:none"> Gerrit-Branch: master </div>
<div style="display:none"> Gerrit-Change-Id: I69b1cbc0a20d54791e5800bf27ebafc2c8606d93 </div>
<div style="display:none"> Gerrit-Change-Number: 24034 </div>
<div style="display:none"> Gerrit-PatchSet: 1 </div>
<div style="display:none"> Gerrit-Owner: Falkenber9 <robert.falkenberg@tu-dortmund.de> </div>
<div style="display:none"> Gerrit-MessageType: newchange </div>