PySerial problem: embedded controller stops echoing commands

I'm trying to use PySerial running on an Ubuntu host to automate testing of an embedded controller (EC). I can enter commands in a terminal window (e.g., PuTTY) and get responses from the EC all day long. However, when I try using a PySerial program to do the same thing, the EC stops echoing the commands after some time, right in the middle of echoing a command. From that point forward, the EC stops responding to the program, including not sending results from the command that was interrupted.

If I terminate the program and try to connect to the EC with a terminal again, the EC is unresponsive. If an external event happens that causes the EC to write output to the terminal, that information is displayed correctly. The problem persists until I reboot the EC - which also erases any logs of what was happening on the EC when the problem occurred. (The logs are only accessible through the serial port...)

It appears that something PySerial is doing causes the EC's input processing to stop. I tried typing Ctrl + Q (XON) hoping there was some software flow control going on that wasn't obvious, but that didn't make a difference. I've tried sending alternating commands in the program, sending blank lines between sending commands, inserting delays between when the commands are sent - but it dies, every time, after processing a few commands.

This is the script I'm currently using:

import serial
from datetime import datetime

ser = serial.Serial('/dev/ttyUSB0', 115200, timeout=1)

print('Starting up')
# send an empty command to ensure a prompt is displayed
ser.write(b'\r\n')

commandToSend = 'battery current'
failed = 0
running = True
while running:
    while running:
        # read from the EC until a timeout occurs with no data available
        try:
            # wait for the EC prompt
            rcvData = ser.read_until(b' ec> ')
            now = datetime.now().time()
            print('{}\tRead from device: "{}"'.format(now, rcvData))
            decoded = rcvData.decode('ascii')
            if len(decoded) == 0:
                # timeout, nothing read from EC, send next command
                failed += 1
                break
            # normalize line terminations then split the data into lines
            lines = decoded.replace('\r\r\n','\r\n').split('\r\n')
            for line in lines:
                print('{}{}'.format(' '*34, line))
            break
        except KeyboardInterrupt:
            print('\nKeyboard interrupt, aborting')
            running = False
            break
        except Exception as e:
            print(e)  # this branch never executes, from my observation
            pass
    now = datetime.now().time()
    if failed > 1:
        print('{}\tCommunication with the EC has failed'.format(now))
        break
    if running:
        # send the command when there's no data to read
        print('{}\tWriting: "{}\\r\\n"'.format(now, commandToSend))
        ser.write('{}\r\n'.format(commandToSend).encode())
        ser.flush()

A typical result from running the above script is this:

./ec-uart-test.py

Output:

Starting up
20:19:10.620998     Read from device: "b'\r\n ec> '"

                                   ec>
20:19:11.622234     Read from device: "b''"
20:19:11.622345     Writing: "battery current\r\n"
20:19:11.627921     Read from device: "b'\r\n ec> '"

                                   ec>
20:19:11.628690     Read from device: "b'battery current\r\n0ma\r\r\n ec> '"
                                  battery current
                                  0ma
                                   ec>
20:19:11.628777     Writing: "battery current\r\n"
20:19:11.635899     Read from device: "b'\r\n ec> '"

                                   ec>
20:19:12.637335     Read from device: "b'battery cu'"
                                  battery cu
20:19:12.637439     Writing: "battery current\r\n"
20:19:13.644800     Read from device: "b''"

20:19:14.646080     Read from device: "b''"
20:19:14.646172     Communication with the EC has failed

Short of cracking open the EC and putting a hardware analyzer on it, is there something else I should try to get this code to work?

Solution

It appears the testing procedure was actually in error: Following one of my colleague's example, I typed the "battery current" command into the terminal, got a response, then used the up-arrow key to re-run the command - which seems to work all day long.

However, that's not the same test: Up-arrow (which retrieves the last command from the EC's history) followed by is not the same as repeatedly typing the command and sending it.

When I repeatedly pasted the command into the terminal window as quickly as I could, the EC failed exactly the same way as did sending the commands using PySerial: The failure is internal to the EC, not something different PySerial was doing on the communication line.