wexpect icon indicating copy to clipboard operation
wexpect copied to clipboard

Critical Performance Issue

Open corradods opened this issue 4 years ago • 2 comments

Describe the bug if I don't interact with the process, expect() takes increasing time to return. what is most strange is that elapsed time will slowly approach the time between two sendline (inactivity time). More time passes between two sendline, more times it takes for returning after I execute a new sendline().

To Reproduce

import wexpect
import time

child = wexpect.spawn('cmd.exe')
child.expect('>')
for _ in range(10):
    child.sendline('echo "hello"')
    starting_time = time.time()
    child.expect('>')
    print("Expect Elapsed time:",time.time() -starting_time)
    time.sleep(5) #if you execute sleep(10) expect will soon take 10 seconds instead of 5
child.sendline('exit')
child.wait()

Expected behavior "Expect elapsed time" shouldn't depend on how much time I didn't iteracted with the process.

Output Expect Elapsed time: 0.07507729530334473 Expect Elapsed time: 2.6089940071105957 Expect Elapsed time: 3.860004425048828 Expect Elapsed time: 4.498199224472046 Expect Elapsed time: 4.816983938217163 Expect Elapsed time: 4.947844982147217 Expect Elapsed time: 5.021565198898315 Expect Elapsed time: 5.082917213439941 Expect Elapsed time: 5.092726707458496 Expect Elapsed time: 5.106329441070557

Environment:

  • [windows version] 21H1 - Build 19043.1348
  • [Python version] 3.85
  • [wexpect version] 4.0.0

corradods avatar Dec 13 '21 14:12 corradods

I (the author) finished my profession as an engineer, now I'm in novitiate of Jesuits. I'm sorry. I cant help now.

raczben avatar Dec 15 '21 14:12 raczben

I don't know why time.sleep(0.01) statement is needed, but it is the source of the bad behaviour. If the sleep statement is removed, the behaviour fades away.

#file: /master/wexpect/host.py    
#line: 828
   # Still have time left, so read more data
                self.isalive()
                c = self.read_nonblocking(self.maxread)
                freshlen = len(c)
                time.sleep(0.01) #<-- 
                incoming += c

Output: Expect Elapsed time: 0.04537820816040039 Expect Elapsed time: 0.031409502029418945 Expect Elapsed time: 0.030704021453857422 Expect Elapsed time: 0.030231475830078125 Expect Elapsed time: 0.04694247245788574 Expect Elapsed time: 0.03125119209289551 Expect Elapsed time: 0.031536102294921875 Expect Elapsed time: 0.046549081802368164 Expect Elapsed time: 0.04633355140686035 Expect Elapsed time: 0.046590328216552734

corradods avatar Apr 29 '22 10:04 corradods