<p>fixeria <strong>submitted</strong> this change.</p><p><a href="https://gerrit.osmocom.org/c/pysim/+/24034">View Change</a></p><div style="white-space:pre-wrap">Approvals:
Jenkins Builder: Verified
dexter: Looks good to me, but someone else must approve
fixeria: Looks good to me, approved
</div><pre style="font-family: monospace,monospace; white-space: pre-wrap;">Speed up AT command interface (~130 times faster)<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>Execution time benchmark (20 AT commands/responses):<br>Previous: 6.010s (100.0%)<br>New code: 0.045s ( 0.7%)<br><br>Change-Id: I69b1cbc0a20d54791e5800bf27ebafc2c8606d93<br>---<br>M pySim/transport/modem_atcmd.py<br>1 file changed, 54 insertions(+), 22 deletions(-)<br><br></pre><pre style="font-family: monospace,monospace; white-space: pre-wrap;"><span>diff --git a/pySim/transport/modem_atcmd.py b/pySim/transport/modem_atcmd.py</span><br><span>index eef38cb..43614f1 100644</span><br><span>--- a/pySim/transport/modem_atcmd.py</span><br><span>+++ b/pySim/transport/modem_atcmd.py</span><br><span>@@ -32,53 +32,85 @@</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> # 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> </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> # Send command to the modem</span><br><span style="color: hsl(0, 100%, 40%);">- log.debug('Sending AT command: %s' % cmd)</span><br><span style="color: hsl(120, 100%, 40%);">+ log.debug('Sending AT command: %s', cmd)</span><br><span> try:</span><br><span> wlen = self._sl.write(bcmd)</span><br><span> assert(wlen == len(bcmd))</span><br><span> except:</span><br><span> raise ReaderError('Failed to send AT command: %s' % cmd)</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- # Give the modem some time...</span><br><span style="color: hsl(0, 100%, 40%);">- time.sleep(0.3)</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 >= %ss', timeout)</span><br><span style="color: hsl(120, 100%, 40%);">+ break</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 %0.6fs (%d cycles a %fs)', time.time() - t_start, its, patience)</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- # Read the response</span><br><span style="color: hsl(0, 100%, 40%);">- try:</span><br><span style="color: hsl(0, 100%, 40%);">- # Skip characters sent back</span><br><span style="color: hsl(0, 100%, 40%);">- self._sl.read(wlen)</span><br><span style="color: hsl(0, 100%, 40%);">- # Read the rest</span><br><span style="color: hsl(0, 100%, 40%);">- rsp = self._sl.read_all()</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> </span><br><span style="color: hsl(0, 100%, 40%);">- # Strip '\r\n'</span><br><span style="color: hsl(0, 100%, 40%);">- rsp = rsp.strip()</span><br><span style="color: hsl(0, 100%, 40%);">- # Split into a list</span><br><span style="color: hsl(0, 100%, 40%);">- rsp = rsp.split(b'\r\n\r\n')</span><br><span style="color: hsl(0, 100%, 40%);">- except:</span><br><span style="color: hsl(0, 100%, 40%);">- raise ReaderError('Failed parse response to AT command: %s' % cmd)</span><br><span style="color: hsl(0, 100%, 40%);">-</span><br><span style="color: hsl(0, 100%, 40%);">- log.debug('Got response from modem: %s' % rsp)</span><br><span style="color: hsl(120, 100%, 40%);">+ 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 \'%s\' does not respond to \'AT\' command' % 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></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: 3 </div>
<div style="display:none"> Gerrit-Owner: Falkenber9 <robert.falkenberg@tu-dortmund.de> </div>
<div style="display:none"> Gerrit-Reviewer: Jenkins Builder </div>
<div style="display:none"> Gerrit-Reviewer: dexter <pmaier@sysmocom.de> </div>
<div style="display:none"> Gerrit-Reviewer: fixeria <vyanitskiy@sysmocom.de> </div>
<div style="display:none"> Gerrit-Reviewer: laforge <laforge@osmocom.org> </div>
<div style="display:none"> Gerrit-MessageType: merged </div>