search

ianmiell / shutit

Automation framework for programmers
http://ianmiell.github.io/shutit/
MIT License
2.15k stars 110 forks source link

multiline output in mac #267

Closed ianmiell closed 7 years ago

ianmiell commented 7 years ago

git-101-tutorial

keep hitting CTRL-s in testing mode in mac.

2016-10-01 08:27:06,958 DEBUG: ================================================================================
2016-10-01 08:27:06,958 DEBUG: Sending>>> export HISTCONTROL=$HISTCONTROL:ignoredups:ignorespace<<<
2016-10-01 08:27:06,958 DEBUG: Expecting>>>root#MZ4cChHf> <<<
 export HISTCONTROL=$HISTCONTROL:ignoredups:ignorespace
 export HISTCONTROL=$HISTCONTROL:ignoredups:ignorespace
root#MZ4cChHf> 2016-10-01 08:27:06,964 DEBUG: Output (squashed): root#MZ4cChHf>  [...]
2016-10-01 08:27:06,964 DEBUG: shutit_pexpect_child.before>>> export HISTCONTROL=$HISTCONTROL:ignoredups:ignorespace
<<<
2016-10-01 08:27:06,964 DEBUG: shutit_pexpect_child.after>>>root#MZ4cChHf> <<<
2016-10-01 08:27:06,965 DEBUG: Expecting: root#MZ4cChHf> 
2016-10-01 08:27:06,967 DEBUG: Retrieving output from command:  test -d /tmp/shutit_imiell/Ians-Air.home_imiell_1475306801.63.631095/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN
2016-10-01 08:27:06,967 DEBUG: Sending in session: target_child
2016-10-01 08:27:06,967 DEBUG: ================================================================================
2016-10-01 08:27:06,967 DEBUG: Sending>>> test -d /tmp/shutit_imiell/Ians-Air.home_imiell_1475306801.63.631095/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN<<<
2016-10-01 08:27:06,967 DEBUG: Expecting>>>root#MZ4cChHf> <<<
 test -d /tmp/shutit_imiell/Ians-Air.home_imiell_1475306801.63.631095/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN
1095/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN01.63.63 
FILNEXIST-FILFIN
root#MZ4cChHf> 2016-10-01 08:27:06,971 DEBUG: Output (squashed): root#MZ4cChHf>  [...]
<<<
2016-10-01 08:27:06,972 DEBUG: shutit_pexpect_child.after>>>root#MZ4cChHf> <<<
'before>>>>:\r\x1b[K<<<< after:>>>>root#MZ4cChHf> <<<<'
2016-10-01 08:27:06,972 CRITICAL: Did not see FIL(N)?EXIST in output:

2016-10-01 08:27:06,972 CRITICAL: Error seen, exiting with status 1
2016-10-01 08:27:06,972 DEBUG: Exiting with error code: 1
2016-10-01 08:27:06,972 DEBUG: Resetting terminal
ianmiell commented 7 years ago

Added hex logging to before (and after):

2016-10-01 08:43:35,585 DEBUG: shutit_pexpect_child.before>>> command -v lsb_release
/usr/bin/lsb_release
<<<
2016-10-01 08:43:35,585 DEBUG: shutit_pexpect_child.after>>>root#R1twaVwn> <<<
2016-10-01 08:43:35,585 DEBUG: Retrieving output from command:  test -a /etc/os-release && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN
2016-10-01 08:43:35,585 DEBUG: Sending in session: target_child
2016-10-01 08:43:35,585 DEBUG: ================================================================================
2016-10-01 08:43:35,586 DEBUG: Sending>>> test -a /etc/os-release && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN<<<
2016-10-01 08:43:35,586 DEBUG: Expecting>>>root#R1twaVwn> <<<
 test -a /etc/os-release && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN
 cat /etc/issue
Debian GNU/Linux 8 \n \l

IST-""FILFINn>  test -a /etc/os-release && echo FILEXIST-""FILFIN || echo FILNEX 
FILEXIST-FILFIN
root#R1twaVwn> 2016-10-01 08:43:35,591 DEBUG: Output (squashed):  cat /etc/issueDebian GNU/Linu [...]
2016-10-01 08:43:35,591 DEBUG: shutit_pexpect_child.before (hex)>>>20636174202f6574632f69737375650d0a44656269616e20474e552f4c696e75782038205c6e205c6c0d0a0d0a<<<
2016-10-01 08:43:35,591 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f7423523174776156776e3e20<<<
2016-10-01 08:43:35,591 DEBUG: shutit_pexpect_child.before>>> cat /etc/issue
Debian GNU/Linux 8 \n \l

<<<
2016-10-01 08:43:35,591 DEBUG: shutit_pexpect_child.after>>>root#R1twaVwn> <<<
'before>>>>: cat /etc/issue\r\nDebian GNU/Linux 8 \\n \\l\r\n\r\n<<<< after:>>>>root#R1twaVwn> <<<<'
ianmiell commented 7 years ago 
2016-10-01 08:43:35,558 DEBUG: ================================================================================
2016-10-01 08:43:35,558 DEBUG: Sending>>> export HISTCONTROL=$HISTCONTROL:ignoredups:ignorespace<<<
2016-10-01 08:43:35,558 DEBUG: Expecting>>>root#R1twaVwn> <<<
 export HISTCONTROL=$HISTCONTROL:ignoredups:ignorespace
 export HISTCONTROL=$HISTCONTROL:ignoredups:ignorespace
root#R1twaVwn> 2016-10-01 08:43:35,560 DEBUG: Output (squashed): root#R1twaVwn>  [...]
2016-10-01 08:43:35,560 DEBUG: shutit_pexpect_child.before (hex)>>>206578706f72742048495354434f4e54524f4c3d2448495354434f4e54524f4c3a69676e6f7265647570733a69676e6f726573706163650d0a<<<
2016-10-01 08:43:35,561 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f7423523174776156776e3e20<<<
2016-10-01 08:43:35,561 DEBUG: shutit_pexpect_child.before>>> export HISTCONTROL=$HISTCONTROL:ignoredups:ignorespace
<<<
2016-10-01 08:43:35,561 DEBUG: shutit_pexpect_child.after>>>root#R1twaVwn> <<<
2016-10-01 08:43:35,561 DEBUG: Expecting: root#R1twaVwn> 
2016-10-01 08:43:35,574 DEBUG: Retrieving output from command:  test -d /tmp/shutit_imiell/Ians-Air.home_imiell_1475307797.11.105043/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN
2016-10-01 08:43:35,574 DEBUG: Sending in session: target_child
2016-10-01 08:43:35,575 DEBUG: ================================================================================
2016-10-01 08:43:35,575 DEBUG: Sending>>> test -d /tmp/shutit_imiell/Ians-Air.home_imiell_1475307797.11.105043/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN<<<
2016-10-01 08:43:35,575 DEBUG: Expecting>>>root#R1twaVwn> <<<
 test -d /tmp/shutit_imiell/Ians-Air.home_imiell_1475307797.11.105043/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN
5043/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN
FILNEXIST-FILFIN
root#R1twaVwn> 2016-10-01 08:43:35,578 DEBUG: Output (squashed):  test -d /tmp/shutit_imiell/Ia [...]
2016-10-01 08:43:35,578 DEBUG: shutit_pexpect_child.before (hex)>>>2074657374202d64202f746d702f7368757469745f696d69656c6c2f49616e732d4169722e686f6d655f696d69656c6c5f313437353330373739372e31312e3130200d353034332f656e7669726f6e6d656e745f6964202626206563686f2046494c45584953542d222246494c46494e207c7c206563686f2046494c4e45584953542d222246494c46494e0d0a46494c4e45584953542d46494c46494e0d0a<<<
2016-10-01 08:43:35,578 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f7423523174776156776e3e20<<<
5043/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFINmp/shutit_imiell/Ians-Air.home_imiell_1475307797.11.10 
FILNEXIST-FILFIN
<<<
2016-10-01 08:43:35,579 DEBUG: shutit_pexpect_child.after>>>root#R1twaVwn> <<<
2016-10-01 08:43:35,579 DEBUG: Retrieving output from command:  command -v lsb_release
2016-10-01 08:43:35,579 DEBUG: Sending in session: target_child
2016-10-01 08:43:35,579 DEBUG: ================================================================================
2016-10-01 08:43:35,579 DEBUG: Sending>>> command -v lsb_release<<<
2016-10-01 08:43:35,579 DEBUG: Expecting>>>root#R1twaVwn> <<<
 command -v lsb_release
root#R1twaVwn>  command -v lsb_release
/usr/bin/lsb_release
root#R1twaVwn> 2016-10-01 08:43:35,582 DEBUG: Output (squashed): root#R1twaVwn>  [...]
2016-10-01 08:43:35,584 DEBUG: shutit_pexpect_child.before (hex)>>>0d1b5b4b<<<
2016-10-01 08:43:35,584 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f7423523174776156776e3e20<<<
<<<
2016-10-01 08:43:35,584 DEBUG: shutit_pexpect_child.after>>>root#R1twaVwn> <<<
2016-10-01 08:43:35,584 DEBUG: Retrieving output from command:  cat /etc/issue
2016-10-01 08:43:35,584 DEBUG: Sending in session: target_child
2016-10-01 08:43:35,584 DEBUG: ================================================================================
2016-10-01 08:43:35,584 DEBUG: Sending>>> cat /etc/issue<<<
2016-10-01 08:43:35,584 DEBUG: Expecting>>>root#R1twaVwn> <<<
 cat /etc/issue
2016-10-01 08:43:35,585 DEBUG: Output (squashed):  command -v lsb_release/usr/bi [...]
2016-10-01 08:43:35,585 DEBUG: shutit_pexpect_child.before (hex)>>>20636f6d6d616e64202d76206c73625f72656c656173650d0a2f7573722f62696e2f6c73625f72656c656173650d0a<<<
2016-10-01 08:43:35,585 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f7423523174776156776e3e20<<<
2016-10-01 08:43:35,585 DEBUG: shutit_pexpect_child.before>>> command -v lsb_release
/usr/bin/lsb_release
<<<
2016-10-01 08:43:35,585 DEBUG: shutit_pexpect_child.after>>>root#R1twaVwn> <<<
2016-10-01 08:43:35,585 DEBUG: Retrieving output from command:  test -a /etc/os-release && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN
2016-10-01 08:43:35,585 DEBUG: Sending in session: target_child
2016-10-01 08:43:35,585 DEBUG: ================================================================================
2016-10-01 08:43:35,586 DEBUG: Sending>>> test -a /etc/os-release && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN<<<
2016-10-01 08:43:35,586 DEBUG: Expecting>>>root#R1twaVwn> <<<
 test -a /etc/os-release && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN
 cat /etc/issue
Debian GNU/Linux 8 \n \l

IST-""FILFINn>  test -a /etc/os-release && echo FILEXIST-""FILFIN || echo FILNEX 
FILEXIST-FILFIN
root#R1twaVwn> 2016-10-01 08:43:35,591 DEBUG: Output (squashed):  cat /etc/issueDebian GNU/Linu [...]
2016-10-01 08:43:35,591 DEBUG: shutit_pexpect_child.before (hex)>>>20636174202f6574632f69737375650d0a44656269616e20474e552f4c696e75782038205c6e205c6c0d0a0d0a<<<
2016-10-01 08:43:35,591 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f7423523174776156776e3e20<<<
2016-10-01 08:43:35,591 DEBUG: shutit_pexpect_child.before>>> cat /etc/issue
Debian GNU/Linux 8 \n \l

<<<
2016-10-01 08:43:35,591 DEBUG: shutit_pexpect_child.after>>>root#R1twaVwn> <<<
'before>>>>: cat /etc/issue\r\nDebian GNU/Linux 8 \\n \\l\r\n\r\n<<<< after:>>>>root#R1twaVwn> <<<<'
2016-10-01 08:43:35,591 CRITICAL: Did not see FIL(N)?EXIST in output:
issue
Debian GNU/Linux 8 \n \l
2016-10-01 08:43:35,592 CRITICAL: Error seen, exiting with status 1
2016-10-01 08:43:35,592 DEBUG: Exiting with error code: 1
2016-10-01 08:43:35,592 DEBUG: Resetting terminal
imiell@Ians-Air:/space/git/git-101-tutorial$ python

Problems are from earlier - full output above.

ianmiell commented 7 years ago

It's a carriage return without a newline (0d).

ianmiell commented 7 years ago

More debug:

2016-10-01 21:00:01,003 DEBUG: ================================================================================
2016-10-01 21:00:01,003 DEBUG: Sending>>> export HISTCONTROL=$HISTCONTROL:ignoredups:ignorespace<<<
2016-10-01 21:00:01,003 DEBUG: Expecting>>>root#ehycl3xJ> <<<
 export HISTCONTROL=$HISTCONTROL:ignoredups:ignorespace
 export HISTCONTROL=$HISTCONTROL:ignoredups:ignorespace
root#ehycl3xJ>  export HISTCONTROL=$HISTCONTROL:ignoredups:ignorespace
root#ehycl3xJ> 
206578706f72742048495354434f4e54524f4c3d2448495354434f4e54524f4c3a69676e6f7265647570733a69676e6f726573706163650d0a726f6f7423656879636c33784a3e20
2016-10-01 21:00:01,008 DEBUG: Output (squashed): root#ehycl3xJ>  [...]
2016-10-01 21:00:01,008 DEBUG: shutit_pexpect_child.before (hex)>>>206578706f72742048495354434f4e54524f4c3d2448495354434f4e54524f4c3a69676e6f7265647570733a69676e6f726573706163650d0a<<<
2016-10-01 21:00:01,009 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f7423656879636c33784a3e20<<<
2016-10-01 21:00:01,009 DEBUG: shutit_pexpect_child.before>>> export HISTCONTROL=$HISTCONTROL:ignoredups:ignorespace
<<<
2016-10-01 21:00:01,009 DEBUG: shutit_pexpect_child.after>>>root#ehycl3xJ> <<<
2016-10-01 21:00:01,009 DEBUG: Expecting: root#ehycl3xJ> 
 echo EXIT_CODE:$?
EXIT_CODE:0
root#ehycl3xJ> 
206563686f20455849545f434f44453a243f0d0a455849545f434f44453a300d0a726f6f7423656879636c33784a3e20
2016-10-01 21:00:01,011 DEBUG: Retrieving output from command:  test -d /tmp/shutit_imiell/Ians-Air.home_imiell_1475351954.19.190905/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN
2016-10-01 21:00:01,012 DEBUG: Sending in session: target_child
2016-10-01 21:00:01,012 DEBUG: ================================================================================
2016-10-01 21:00:01,012 DEBUG: Sending>>> test -d /tmp/shutit_imiell/Ians-Air.home_imiell_1475351954.19.190905/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN<<<
2016-10-01 21:00:01,012 DEBUG: Expecting>>>root#ehycl3xJ> <<<
 test -d /tmp/shutit_imiell/Ians-Air.home_imiell_1475351954.19.190905/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN
0905/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN54.19.19 
FILNEXIST-FILFIN
0905/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN54.19.19 
FILNEXIST-FILFIN
root#ehycl3xJ> 
0d1b5b4b726f6f7423656879636c33784a3e202074657374202d64202f746d702f7368757469745f696d69656c6c2f49616e732d4169722e686f6d655f696d69656c6c5f313437353335313935342e31392e3139200d303930352f656e7669726f6e6d656e745f6964202626206563686f2046494c45584953542d222246494c46494e207c7c206563686f2046494c4e45584953542d222246494c46494e0d0a46494c4e45584953542d46494c46494e0d0a726f6f7423656879636c33784a3e20
2016-10-01 21:00:01,015 DEBUG: Output (squashed): root#ehycl3xJ>  [...]
2016-10-01 21:00:01,015 DEBUG: shutit_pexpect_child.before (hex)>>>0d1b5b4b<<<
2016-10-01 21:00:01,015 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f7423656879636c33784a3e20<<<
<<<
2016-10-01 21:00:01,015 DEBUG: shutit_pexpect_child.after>>>root#ehycl3xJ> <<<
================================================================================

================================================================================
================================================================================

================================================================================
================================================================================
string_without_termcodes_stripped_no_cr

================================================================================
'before>>>>:\r\x1b[K<<<< after:>>>>root#ehycl3xJ> <<<<'
2016-10-01 21:00:01,015 CRITICAL: Did not see FIL(N)?EXIST in output:

2016-10-01 21:00:01,015 CRITICAL: Error seen, exiting with status 1
2016-10-01 21:00:01,016 DEBUG: Exiting with error code: 1
2016-10-01 21:00:01,016 DEBUG: Resetting terminal
imiell@Ians-Air:/space/git/git-101-tutorial$
ianmiell commented 7 years ago 

print all.decode('hex')                                                                                                                                                           

#2016-10-01 21:00:01,015 DEBUG: shutit_pexpect_child.before (hex)>>>0d1b5b4b<<<  
#2016-10-01 21:00:01,015 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f7423656879636c33784a3e20<<<
ianmiell commented 7 years ago

first is what is seen by expect_loop in incoming, then before and after from

0d1b5b4b726f6f742334546b6f747437303e2020636f6d6d616e64202d76206c73625f72656c656173650d0a2f7573722f62696e2f6c73625f72656c656173650d0a726f6f742334546b6f747437303e20
NEW DATA
0d1b5b4b
726f6f742334546b6f747437303e20

so the problem is that the text comes AFTER the expected output.

Looks like this is not fixable except by setting the delaybeforesend to non-zero.

ianmiell commented 7 years ago

Nope, it's not that - just seems to reduce the chances slightly.

ianmiell commented 7 years ago

Output with pexpect objects:


==========In this tutorial you will be asked to set up git on your machine,
create a repository, and add and commit some code to it.

You have a full bash shell, so can use vi, less, man etc..

If any tools are missing or there are bugs raise a github request or contact
@ianmiell on twitter.

CTRL-] (right angle bracket) to continue.

Hit CTRL-h for help, CTRL-s to skip==========

You now have a standard shell. Hit CTRL and then ] at the same time to continue ShutIt run.
Hit CTRL and u to save the state to a docker image
 /tmp/shutit_fixterm
tk.shutit.git_101_tutorial#wSaiu9eH> 2016-10-02 07:46:35,778 INFO: Test skipped

OK!

2016-10-02 07:46:36,782 INFO: Replacing container, please wait...
<pexpect.pty_spawn.spawn object at 0x103114a10>
command: /bin/bash
args: ['/bin/bash']
buffer (last 100 chars): ''
before (last 100 chars): '.home_imiell_1475390780.06.60056\r\n0bf36b73b2a40877f1fb782bcd16760f657df31f9d6a573964dad754f7fe7915\r\n'
after: 'ORIGIN_ENV#IWmV1yhY> '
match: <_sre.SRE_Match object at 0x103158d98>
match_index: 0
exitstatus: None
flag_eof: False
pid: 24989
child_fd: 6
closed: False
timeout: 300
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: None
logfile_send: None
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0
delayafterclose: 0.1
delayafterterminate: 0.1
2016-10-02 07:46:37,397 INFO: Startup command is: docker run --cidfile=/tmp/shutit_imiell/Ians-Air.home_imiell_1475390780.06.60056/cidfiles/imiell_cidfile_Ians-Air.home_imiell_1475390780.06.60056 -t -i imiell/git-101-tutorial:step_4 /bin/bash
2016-10-02 07:46:37,397 INFO: Downloading image, please be patient
<pexpect.pty_spawn.spawn object at 0x10318ad90>
command: /usr/local/bin/docker
args: ['/usr/local/bin/docker', 'run', '--cidfile=/tmp/shutit_imiell/Ians-Air.home_imiell_1475390780.06.60056/cidfiles/imiell_cidfile_Ians-Air.home_imiell_1475390780.06.60056', '-t', '-i', 'imiell/git-101-tutorial:step_4', '/bin/bash']
buffer (last 100 chars): ''
before (last 100 chars): "port SHUTIT_BACKUP_PS1_root=$PS1 && PS1='root#a \r1HnocSI> ' && unset PROMPT_COMMAND && stty cols 320"
after: '\r\nroot#a1HnocSI> '
match: <_sre.SRE_Match object at 0x103158ed0>
match_index: 0
exitstatus: None
flag_eof: False
pid: 26356
child_fd: 5
closed: False
timeout: 300
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: None
logfile_send: None
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0
delayafterclose: 0.1
delayafterterminate: 0.1
<pexpect.pty_spawn.spawn object at 0x10318ad90>
command: /usr/local/bin/docker
args: ['/usr/local/bin/docker', 'run', '--cidfile=/tmp/shutit_imiell/Ians-Air.home_imiell_1475390780.06.60056/cidfiles/imiell_cidfile_Ians-Air.home_imiell_1475390780.06.60056', '-t', '-i', 'imiell/git-101-tutorial:step_4', '/bin/bash']
buffer (last 100 chars): ''
before (last 100 chars): ' shopt -s checkwinsize\r\n'
after: 'root#a1HnocSI> '
match: <_sre.SRE_Match object at 0x103158d30>
match_index: 0
exitstatus: None
flag_eof: False
pid: 26356
child_fd: 5
closed: False
timeout: 300
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: None
logfile_send: None
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0
delayafterclose: 0.1
delayafterterminate: 0.1
<pexpect.pty_spawn.spawn object at 0x10318ad90>
command: /usr/local/bin/docker
args: ['/usr/local/bin/docker', 'run', '--cidfile=/tmp/shutit_imiell/Ians-Air.home_imiell_1475390780.06.60056/cidfiles/imiell_cidfile_Ians-Air.home_imiell_1475390780.06.60056', '-t', '-i', 'imiell/git-101-tutorial:step_4', '/bin/bash']
buffer (last 100 chars): ''
before (last 100 chars): ' stty sane\r\n'
after: 'root#a1HnocSI> '
match: <_sre.SRE_Match object at 0x103158ed0>
match_index: 0
exitstatus: None
flag_eof: False
pid: 26356
child_fd: 5
closed: False
timeout: 300
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: None
logfile_send: None
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0
delayafterclose: 0.1
delayafterterminate: 0.1
<pexpect.pty_spawn.spawn object at 0x10318ad90>
command: /usr/local/bin/docker
args: ['/usr/local/bin/docker', 'run', '--cidfile=/tmp/shutit_imiell/Ians-Air.home_imiell_1475390780.06.60056/cidfiles/imiell_cidfile_Ians-Air.home_imiell_1475390780.06.60056', '-t', '-i', 'imiell/git-101-tutorial:step_4', '/bin/bash']
buffer (last 100 chars): ' export HISTCONTROL=$HISTCONTROL:ignoredups:ignorespace\r\nroot#a1HnocSI> '
before (last 100 chars): ' exp\r\x1b[K'
after: 'root#a1HnocSI> '
match: <_sre.SRE_Match object at 0x103158d30>
match_index: 0
exitstatus: None
flag_eof: False
pid: 26356
child_fd: 5
closed: False
timeout: 300
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: None
logfile_send: None
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0
delayafterclose: 0.1
delayafterterminate: 0.1
<pexpect.pty_spawn.spawn object at 0x10318ad90>
command: /usr/local/bin/docker
args: ['/usr/local/bin/docker', 'run', '--cidfile=/tmp/shutit_imiell/Ians-Air.home_imiell_1475390780.06.60056/cidfiles/imiell_cidfile_Ians-Air.home_imiell_1475390780.06.60056', '-t', '-i', 'imiell/git-101-tutorial:step_4', '/bin/bash']
buffer (last 100 chars): ''
before (last 100 chars): '0.06.60 \r056/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN\r\nFILNEXIST-FILFIN\r\n'
after: 'root#a1HnocSI> '
match: <_sre.SRE_Match object at 0x103158ed0>
match_index: 0
exitstatus: None
flag_eof: False
pid: 26356
child_fd: 5
closed: False
timeout: 300
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: None
logfile_send: None
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0
delayafterclose: 0.1
delayafterterminate: 0.1
<pexpect.pty_spawn.spawn object at 0x10318ad90>
command: /usr/local/bin/docker
args: ['/usr/local/bin/docker', 'run', '--cidfile=/tmp/shutit_imiell/Ians-Air.home_imiell_1475390780.06.60056/cidfiles/imiell_cidfile_Ians-Air.home_imiell_1475390780.06.60056', '-t', '-i', 'imiell/git-101-tutorial:step_4', '/bin/bash']
buffer (last 100 chars): ''
before (last 100 chars): ' command -v lsb_release\r\n/usr/bin/lsb_release\r\n'
after: 'root#a1HnocSI> '
match: <_sre.SRE_Match object at 0x103158e00>
match_index: 0
exitstatus: None
flag_eof: False
pid: 26356
child_fd: 5
closed: False
timeout: 300
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: None
logfile_send: None
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0
delayafterclose: 0.1
delayafterterminate: 0.1
<pexpect.pty_spawn.spawn object at 0x10318ad90>
command: /usr/local/bin/docker
args: ['/usr/local/bin/docker', 'run', '--cidfile=/tmp/shutit_imiell/Ians-Air.home_imiell_1475390780.06.60056/cidfiles/imiell_cidfile_Ians-Air.home_imiell_1475390780.06.60056', '-t', '-i', 'imiell/git-101-tutorial:step_4', '/bin/bash']
buffer (last 100 chars): ''
before (last 100 chars): 'Distributor ID:\tDebian\r\nDescription:\tDebian GNU/Linux 8.4 (jessie)\r\nRelease:\t8.4\r\nCodename:\tjessie\r\n'
after: 'root#a1HnocSI> '
match: <_sre.SRE_Match object at 0x103158ed0>
match_index: 0
exitstatus: None
flag_eof: False
pid: 26356
child_fd: 5
closed: False
timeout: 300
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: None
logfile_send: None
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0
delayafterclose: 0.1
delayafterterminate: 0.1
<pexpect.pty_spawn.spawn object at 0x10318ad90>
command: /usr/local/bin/docker
args: ['/usr/local/bin/docker', 'run', '--cidfile=/tmp/shutit_imiell/Ians-Air.home_imiell_1475390780.06.60056/cidfiles/imiell_cidfile_Ians-Air.home_imiell_1475390780.06.60056', '-t', '-i', 'imiell/git-101-tutorial:step_4', '/bin/bash']
buffer (last 100 chars): ''
before (last 100 chars): 'ell && touch /tmp/shutit_imie \rll/Ians-Air.home_imiell_1475390780.06.60056/environment_id/O2FwbFpB\r\n'
after: 'root#a1HnocSI> '
match: <_sre.SRE_Match object at 0x103158e00>
match_index: 0
exitstatus: None
flag_eof: False
pid: 26356
child_fd: 5
closed: False
timeout: 300
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: None
logfile_send: None
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0
delayafterclose: 0.1
delayafterterminate: 0.1
2016-10-02 07:46:38,307 INFO: State restored.
2016-10-02 07:46:38,307 WARNING: Retrieving output from command:  echo $TMUX
2016-10-02 07:46:38,307 WARNING: Sending:  echo $TMUX
<pexpect.pty_spawn.spawn object at 0x10318ad90>
command: /usr/local/bin/docker
args: ['/usr/local/bin/docker', 'run', '--cidfile=/tmp/shutit_imiell/Ians-Air.home_imiell_1475390780.06.60056/cidfiles/imiell_cidfile_Ians-Air.home_imiell_1475390780.06.60056', '-t', '-i', 'imiell/git-101-tutorial:step_4', '/bin/bash']
buffer (last 100 chars): ''
before (last 100 chars): ' echo $TMUX\r\n\r\n'
after: 'root#a1HnocSI> '
match: <_sre.SRE_Match object at 0x1030ede68>
match_index: 0
exitstatus: None
flag_eof: False
pid: 26356
child_fd: 5
closed: False
timeout: 300
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: None
logfile_send: None
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0
delayafterclose: 0.1
delayafterterminate: 0.1
2016-10-02 07:46:38,310 WARNING: Output (squashed): root#a1HnocSI>  [...]
2016-10-02 07:46:38,310 WARNING: Retrieving output from command:  echo $TERM
2016-10-02 07:46:38,310 WARNING: Sending:  echo $TERM
<pexpect.pty_spawn.spawn object at 0x10318ad90>
command: /usr/local/bin/docker
args: ['/usr/local/bin/docker', 'run', '--cidfile=/tmp/shutit_imiell/Ians-Air.home_imiell_1475390780.06.60056/cidfiles/imiell_cidfile_Ians-Air.home_imiell_1475390780.06.60056', '-t', '-i', 'imiell/git-101-tutorial:step_4', '/bin/bash']
buffer (last 100 chars): ''
before (last 100 chars): ' echo $TERM\r\nxterm\r\n'
after: 'root#a1HnocSI> '
match: <_sre.SRE_Match object at 0x103158ed0>
match_index: 0
exitstatus: None
flag_eof: False
pid: 26356
child_fd: 5
closed: False
timeout: 300
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: None
logfile_send: None
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0
delayafterclose: 0.1
delayafterterminate: 0.1
2016-10-02 07:46:38,313 WARNING: Output (squashed): xtermroot#a1HnocSI>  [...]
<pexpect.pty_spawn.spawn object at 0x10318ad90>
command: /usr/local/bin/docker
args: ['/usr/local/bin/docker', 'run', '--cidfile=/tmp/shutit_imiell/Ians-Air.home_imiell_1475390780.06.60056/cidfiles/imiell_cidfile_Ians-Air.home_imiell_1475390780.06.60056', '-t', '-i', 'imiell/git-101-tutorial:step_4', '/bin/bash']
buffer (last 100 chars): ''
before (last 100 chars): 'st -a /tmp/shutit_fixterm && echo FILEXIST-""FILFIN || echo FI \rLNEXIST-""FILFIN\r\nFILNEXIST-FILFIN\r\n'
after: 'root#a1HnocSI> '
match: <_sre.SRE_Match object at 0x1030ede68>
match_index: 0
exitstatus: None
flag_eof: False
pid: 26356
child_fd: 5
closed: False
timeout: 300
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: None
logfile_send: None
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0
delayafterclose: 0.1
delayafterterminate: 0.1
2016-10-02 07:46:38,317 INFO: Fixing up your terminal, please wait...
<pexpect.pty_spawn.spawn object at 0x10318ad90>
command: /usr/local/bin/docker
args: ['/usr/local/bin/docker', 'run', '--cidfile=/tmp/shutit_imiell/Ians-Air.home_imiell_1475390780.06.60056/cidfiles/imiell_cidfile_Ians-Air.home_imiell_1475390780.06.60056', '-t', '-i', 'imiell/git-101-tutorial:step_4', '/bin/bash']
buffer (last 100 chars): ''
before (last 100 chars): ' whoami\r\nroot\r\n'
after: 'root#a1HnocSI> '
match: <_sre.SRE_Match object at 0x103158ed0>
match_index: 0
exitstatus: None
flag_eof: False
pid: 26356
child_fd: 5
closed: False
timeout: 300
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: None
logfile_send: None
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0
delayafterclose: 0.1
delayafterterminate: 0.1
<pexpect.pty_spawn.spawn object at 0x10318ad90>
command: /usr/local/bin/docker
args: ['/usr/local/bin/docker', 'run', '--cidfile=/tmp/shutit_imiell/Ians-Air.home_imiell_1475390780.06.60056/cidfiles/imiell_cidfile_Ians-Air.home_imiell_1475390780.06.60056', '-t', '-i', 'imiell/git-101-tutorial:step_4', '/bin/bash']
buffer (last 100 chars): ''
before (last 100 chars): ' id -n -g\r\nroot\r\n'
after: 'root#a1HnocSI> '
match: <_sre.SRE_Match object at 0x1030ede68>
match_index: 0
exitstatus: None
flag_eof: False
pid: 26356
child_fd: 5
closed: False
timeout: 300
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: None
logfile_send: None
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0
delayafterclose: 0.1
delayafterterminate: 0.1
<pexpect.pty_spawn.spawn object at 0x10318ad90>
command: /usr/local/bin/docker
args: ['/usr/local/bin/docker', 'run', '--cidfile=/tmp/shutit_imiell/Ians-Air.home_imiell_1475390780.06.60056/cidfiles/imiell_cidfile_Ians-Air.home_imiell_1475390780.06.60056', '-t', '-i', 'imiell/git-101-tutorial:step_4', '/bin/bash']
buffer (last 100 chars): ''
before (last 100 chars): ' touch /tmp/shutit_fixterm\r\n'
after: 'root#a1HnocSI> '
match: <_sre.SRE_Match object at 0x103158ed0>
match_index: 0
exitstatus: None
flag_eof: False
pid: 26356
child_fd: 5
closed: False
timeout: 300
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: None
logfile_send: None
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0
delayafterclose: 0.1
delayafterterminate: 0.1
<pexpect.pty_spawn.spawn object at 0x103114a10>
command: /bin/bash
args: ['/bin/bash']
buffer (last 100 chars): ''
before (last 100 chars): "7651fcc7babc2bbf9737326b26fe2c9aebba86550c4857c4123d57d64f5111 bash -c 'cat > /tmp/shutit_fixterm'\r\n"
after: 'ORIGIN_ENV#IWmV1yhY> '
match: <_sre.SRE_Match object at 0x103158ed0>
match_index: 0
exitstatus: None
flag_eof: False
pid: 24989
child_fd: 6
closed: False
timeout: 300
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: None
logfile_send: None
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0
delayafterclose: 0.1
delayafterterminate: 0.1
<pexpect.pty_spawn.spawn object at 0x10318ad90>
command: /usr/local/bin/docker
args: ['/usr/local/bin/docker', 'run', '--cidfile=/tmp/shutit_imiell/Ians-Air.home_imiell_1475390780.06.60056/cidfiles/imiell_cidfile_Ians-Air.home_imiell_1475390780.06.60056', '-t', '-i', 'imiell/git-101-tutorial:step_4', '/bin/bash']
buffer (last 100 chars): ' chown root /tmp/shutit_fixterm && chgrp root /tmp/shutit_fixter\x1b[Km\r\n'
before (last 100 chars): ' chown root /tmp/shutit_fixterm && chgrp root /tmp/shutit_fixterm \r\x1b[A'
after: 'root#a1HnocSI> '
match: <_sre.SRE_Match object at 0x103158c60>
match_index: 0
exitstatus: None
flag_eof: False
pid: 26356
child_fd: 5
closed: False
timeout: 300
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: None
logfile_send: None
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0
delayafterclose: 0.1
delayafterterminate: 0.1
<pexpect.pty_spawn.spawn object at 0x10318ad90>
command: /usr/local/bin/docker
args: ['/usr/local/bin/docker', 'run', '--cidfile=/tmp/shutit_imiell/Ians-Air.home_imiell_1475390780.06.60056/cidfiles/imiell_cidfile_Ians-Air.home_imiell_1475390780.06.60056', '-t', '-i', 'imiell/git-101-tutorial:step_4', '/bin/bash']
buffer (last 100 chars): ''
before (last 100 chars): ' chmod 777 /tmp/shutit_fixterm\r\n'
after: 'root#a1HnocSI> '
match: <_sre.SRE_Match object at 0x1030ede68>
match_index: 0
exitstatus: None
flag_eof: False
pid: 26356
child_fd: 5
closed: False
timeout: 300
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: None
logfile_send: None
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0
delayafterclose: 0.1
delayafterterminate: 0.1
<pexpect.pty_spawn.spawn object at 0x10318ad90>
command: /usr/local/bin/docker
args: ['/usr/local/bin/docker', 'run', '--cidfile=/tmp/shutit_imiell/Ians-Air.home_imiell_1475390780.06.60056/cidfiles/imiell_cidfile_Ians-Air.home_imiell_1475390780.06.60056', '-t', '-i', 'imiell/git-101-tutorial:step_4', '/bin/bash']
buffer (last 100 chars): ''
before (last 100 chars): ' /tmp/shutit_fixterm_stty && echo FILEXIST-""FILFIN || ec \rho FILNEXIST-""FILFIN\r\nFILNEXIST-FILFIN\r\n'
after: 'root#a1HnocSI> '
match: <_sre.SRE_Match object at 0x1030ede68>
match_index: 0
exitstatus: None
flag_eof: False
pid: 26356
child_fd: 5
closed: False
timeout: 300
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: None
logfile_send: None
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0
delayafterclose: 0.1
delayafterterminate: 0.1
<pexpect.pty_spawn.spawn object at 0x10318ad90>
command: /usr/local/bin/docker
args: ['/usr/local/bin/docker', 'run', '--cidfile=/tmp/shutit_imiell/Ians-Air.home_imiell_1475390780.06.60056/cidfiles/imiell_cidfile_Ians-Air.home_imiell_1475390780.06.60056', '-t', '-i', 'imiell/git-101-tutorial:step_4', '/bin/bash']
buffer (last 100 chars): ''
before (last 100 chars): ' stty >  /tmp/shutit_fixterm_stty\r\n'
after: 'root#a1HnocSI> '
match: <_sre.SRE_Match object at 0x103158c60>
match_index: 0
exitstatus: None
flag_eof: False
pid: 26356
child_fd: 5
closed: False
timeout: 300
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: None
logfile_send: None
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0
delayafterclose: 0.1
delayafterterminate: 0.1

==========Configure git to tell it who you are (user.name and user.email). Don't forget that CTRL-h will give you hints.

Hit CTRL-h for help, CTRL-s to skip==========

You now have a standard shell. Hit CTRL and then ] at the same time to continue ShutIt run.
Hit CTRL and u to save the state to a docker image
 /tmp/shutit_fixterm
root#a1HnocSI> 2016-10-02 07:46:39,161 INFO: Test skipped

OK!

2016-10-02 07:46:40,166 INFO: Replacing container, please wait...
<pexpect.pty_spawn.spawn object at 0x103114a10>
command: /bin/bash
args: ['/bin/bash']
buffer (last 100 chars): ''
before (last 100 chars): '.home_imiell_1475390780.06.60056\r\n877651fcc7babc2bbf9737326b26fe2c9aebba86550c4857c4123d57d64f5111\r\n'
after: 'ORIGIN_ENV#IWmV1yhY> '
match: <_sre.SRE_Match object at 0x103158c60>
match_index: 0
exitstatus: None
flag_eof: False
pid: 24989
child_fd: 6
closed: False
timeout: 300
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: None
logfile_send: None
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0
delayafterclose: 0.1
delayafterterminate: 0.1
2016-10-02 07:46:40,744 INFO: Startup command is: docker run --cidfile=/tmp/shutit_imiell/Ians-Air.home_imiell_1475390780.06.60056/cidfiles/imiell_cidfile_Ians-Air.home_imiell_1475390780.06.60056 -t -i imiell/git-101-tutorial:step_5 /bin/bash
2016-10-02 07:46:40,744 INFO: Downloading image, please be patient
<pexpect.pty_spawn.spawn object at 0x103114810>
command: /usr/local/bin/docker
args: ['/usr/local/bin/docker', 'run', '--cidfile=/tmp/shutit_imiell/Ians-Air.home_imiell_1475390780.06.60056/cidfiles/imiell_cidfile_Ians-Air.home_imiell_1475390780.06.60056', '-t', '-i', 'imiell/git-101-tutorial:step_5', '/bin/bash']
buffer (last 100 chars): ''
before (last 100 chars): "port SHUTIT_BACKUP_PS1_root=$PS1 && PS1='root#i \r4Jab1c4> ' && unset PROMPT_COMMAND && stty cols 320"
after: '\r\nroot#i4Jab1c4> '
match: <_sre.SRE_Match object at 0x1031a3030>
match_index: 0
exitstatus: None
flag_eof: False
pid: 26369
child_fd: 5
closed: False
timeout: 300
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: None
logfile_send: None
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0
delayafterclose: 0.1
delayafterterminate: 0.1
<pexpect.pty_spawn.spawn object at 0x103114810>
command: /usr/local/bin/docker
args: ['/usr/local/bin/docker', 'run', '--cidfile=/tmp/shutit_imiell/Ians-Air.home_imiell_1475390780.06.60056/cidfiles/imiell_cidfile_Ians-Air.home_imiell_1475390780.06.60056', '-t', '-i', 'imiell/git-101-tutorial:step_5', '/bin/bash']
buffer (last 100 chars): ''
before (last 100 chars): ' shopt -s checkwinsize\r\n'
after: 'root#i4Jab1c4> '
match: <_sre.SRE_Match object at 0x103158e00>
match_index: 0
exitstatus: None
flag_eof: False
pid: 26369
child_fd: 5
closed: False
timeout: 300
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: None
logfile_send: None
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0
delayafterclose: 0.1
delayafterterminate: 0.1
<pexpect.pty_spawn.spawn object at 0x103114810>
command: /usr/local/bin/docker
args: ['/usr/local/bin/docker', 'run', '--cidfile=/tmp/shutit_imiell/Ians-Air.home_imiell_1475390780.06.60056/cidfiles/imiell_cidfile_Ians-Air.home_imiell_1475390780.06.60056', '-t', '-i', 'imiell/git-101-tutorial:step_5', '/bin/bash']
buffer (last 100 chars): ''
before (last 100 chars): ' stty sane\r\n'
after: 'root#i4Jab1c4> '
match: <_sre.SRE_Match object at 0x103158f38>
match_index: 0
exitstatus: None
flag_eof: False
pid: 26369
child_fd: 5
closed: False
timeout: 300
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: None
logfile_send: None
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0
delayafterclose: 0.1
delayafterterminate: 0.1
<pexpect.pty_spawn.spawn object at 0x103114810>
command: /usr/local/bin/docker
args: ['/usr/local/bin/docker', 'run', '--cidfile=/tmp/shutit_imiell/Ians-Air.home_imiell_1475390780.06.60056/cidfiles/imiell_cidfile_Ians-Air.home_imiell_1475390780.06.60056', '-t', '-i', 'imiell/git-101-tutorial:step_5', '/bin/bash']
buffer (last 100 chars): ''
before (last 100 chars): ' export HISTCONTROL=$HISTCONTROL:ignoredups:ignorespace\r\n'
after: 'root#i4Jab1c4> '
match: <_sre.SRE_Match object at 0x103158e00>
match_index: 0
exitstatus: None
flag_eof: False
pid: 26369
child_fd: 5
closed: False
timeout: 300
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: None
logfile_send: None
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0
delayafterclose: 0.1
delayafterterminate: 0.1
<pexpect.pty_spawn.spawn object at 0x103114810>
command: /usr/local/bin/docker
args: ['/usr/local/bin/docker', 'run', '--cidfile=/tmp/shutit_imiell/Ians-Air.home_imiell_1475390780.06.60056/cidfiles/imiell_cidfile_Ians-Air.home_imiell_1475390780.06.60056', '-t', '-i', 'imiell/git-101-tutorial:step_5', '/bin/bash']
buffer (last 100 chars): ' test -d /tmp/shutit_imiell/Ians-Air.home_imiell_1475390780.06.60 \r056/en'
before (last 100 chars): ' test -d /tmp/shutit_imiell/Ians-Air.home_imiell_1475390780.06.60 \r\r\x1b[K\x1b[A'
after: 'root#i4Jab1c4> '
match: <_sre.SRE_Match object at 0x103158ed0>
match_index: 0
exitstatus: None
flag_eof: False
pid: 26369
child_fd: 5
closed: False
timeout: 300
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: None
logfile_send: None
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0
delayafterclose: 0.1
delayafterterminate: 0.1
'before>>>>: test -d /tmp/shutit_imiell/Ians-Air.home_imiell_1475390780.06.60 \r\r\x1b[K\x1b[A<<<< after:>>>>root#i4Jab1c4> <<<<'
2016-10-02 07:46:41,462 CRITICAL: Did not see FIL(N)?EXIST in output:

 RITICAL: Error seen, exiting with status 1
imiell@Ians-Air:/space/git/git-101-tutorial$
ianmiell commented 7 years ago 
2016-10-02 07:56:41,611 DEBUG: ================================================================================
2016-10-02 07:56:41,611 DEBUG: Sending>>> export HISTCONTROL=$HISTCONTROL:ignoredups:ignorespace<<<
2016-10-02 07:56:41,611 DEBUG: Expecting>>>root#HKXV2yBl> <<<
 export HISTCONTROL=$HISTCONTROL:ignoredups:ignorespace
 export Hincoming
 export H
206578706f72742048
incomingdone
ISTCONTROincoming
ISTCONTRO
495354434f4e54524f
incomingdone
Lincoming
L
4c
incomingdone
=$HISTCONTROincoming
=$HISTCONTRO
3d2448495354434f4e54524f
incomingdone
L:ignoredups:ignoreincoming
L:ignoredups:ignore
4c3a69676e6f7265647570733a69676e6f7265
incomingdone
spaincoming
spa
737061
incomingdone
ceincoming
ce
6365
incomingdone

root#HKXV2yBl> incoming

root#HKXV2yBl> 
0d0a726f6f7423484b58563279426c3e20
incomingdone
2016-10-02 07:56:41,616 DEBUG: Output (squashed): root#HKXV2yBl>  [...]
2016-10-02 07:56:41,616 DEBUG: shutit_pexpect_child.before (hex)>>>206578706f72742048495354434f4e54524f4c3d2448495354434f4e54524f4c3a69676e6f7265647570733a69676e6f726573706163650d0a<<<
2016-10-02 07:56:41,616 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f7423484b58563279426c3e20<<<
2016-10-02 07:56:41,616 DEBUG: shutit_pexpect_child.before>>> export HISTCONTROL=$HISTCONTROL:ignoredups:ignorespace
<<<
2016-10-02 07:56:41,616 DEBUG: shutit_pexpect_child.after>>>root#HKXV2yBl> <<<
2016-10-02 07:56:41,616 DEBUG: Expecting: root#HKXV2yBl> 
incoming
 echo EXIT_CODE:$?
EXIT_CODE:0
root#HKXV2yBl> 
206563686f20455849545f434f44453a243f0d0a455849545f434f44453a300d0a726f6f7423484b58563279426c3e20
incomingdone
2016-10-02 07:56:41,619 DEBUG: Retrieving output from command:  test -d /tmp/shutit_imiell/Ians-Air.home_imiell_1475391384.01.11193/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN
2016-10-02 07:56:41,619 DEBUG: Sending in session: target_child
2016-10-02 07:56:41,619 DEBUG: ================================================================================
2016-10-02 07:56:41,619 DEBUG: Sending>>> test -d /tmp/shutit_imiell/Ians-Air.home_imiell_1475391384.01.11193/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN<<<
2016-10-02 07:56:41,619 DEBUG: Expecting>>>root#HKXV2yBl> <<<
 test -d /tmp/shutit_imiell/Ians-Air.home_imiell_1475391384.01.11193/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN
193/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN384.01.11 
FILNEXIST-FILFIN
root#HKXV2yBl> incoming
193/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN384.01.11 
FILNEXIST-FILFIN
root#HKXV2yBl> 
0d1b5b4b726f6f7423484b58563279426c3e202074657374202d64202f746d702f7368757469745f696d69656c6c2f49616e732d4169722e686f6d655f696d69656c6c5f313437353339313338342e30312e3131200d3139332f656e7669726f6e6d656e745f6964202626206563686f2046494c45584953542d222246494c46494e207c7c206563686f2046494c4e45584953542d222246494c46494e0d0a46494c4e45584953542d46494c46494e0d0a726f6f7423484b58563279426c3e20
incomingdone
2016-10-02 07:56:41,624 DEBUG: Output (squashed): root#HKXV2yBl>  [...]
2016-10-02 07:56:41,624 DEBUG: shutit_pexpect_child.before (hex)>>>0d1b5b4b<<<
2016-10-02 07:56:41,624 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f7423484b58563279426c3e20<<<
<<<
2016-10-02 07:56:41,624 DEBUG: shutit_pexpect_child.after>>>root#HKXV2yBl> <<<
'before>>>>:\r\x1b[K<<<< after:>>>>root#HKXV2yBl> <<<<'
2016-10-02 07:56:41,624 CRITICAL: Did not see FIL(N)?EXIST in output:

2016-10-02 07:56:41,624 CRITICAL: Error seen, exiting with status 1
2016-10-02 07:56:41,625 DEBUG: Exiting with error code: 1
2016-10-02 07:56:41,625 DEBUG: Resetting terminal
imiell@Ians-Air:/space/git/git-101-tutorial$

matching code:

    def expect_loop(self, timeout=-1):                                                                                                                                            
        """Blocking expect"""                                                                                                                                                     
        spawn = self.spawn                                                                                                                                                        
        from . import EOF, TIMEOUT                                                                                                                                                

        if timeout is not None:                                                                                                                                                   
            end_time = time.time() + timeout                                                                                                                                      

        try:                                                                                                                                                                      
            incoming = spawn.buffer                                                                                                                                               
            spawn.buffer = spawn.string_type()  # Treat buffer as new data                                                                                                        
            while True:                                                                                                                                                           
                idx = self.new_data(incoming)                                                                                                                                     
                # Keep reading until exception or return.                                                                                                                         
                if idx is not None:                                                                                                                                               
                    return idx                                                                                                                                                    
                # No match at this point                                                                                                                                          
                if (timeout is not None) and (timeout < 0):                                                                                                                       
                    return self.timeout()                                                                                                                                         
                # Still have time left, so read more data                                                                                                                         
                incoming = spawn.read_nonblocking(spawn.maxread, timeout)                                                                                                         
                print 'incoming'                                                                                                                                                  
                print incoming                                                                                                                                                    
                print incoming.encode('hex')                                                                                                                                      
                print 'incomingdone'                                                                                                                                              
                if self.spawn.delayafterread is not None:                                                                                                                         
                    time.sleep(self.spawn.delayafterread)                                                                                                                         
                if timeout is not None:                                                                                                                                           
                    timeout = end_time - time.time()                                                                                                                              
        except EOF as e:                                                                                                                                                          
            return self.eof(e)                                                                                                                                                    
        except TIMEOUT as e:                                                                                                                                                      
            return self.timeout(e)                                                                                                                                                
        except:                                                                                                                                                                   
            self.errored()                                                                                                                                                        
            raise
ianmiell commented 7 years ago

HERE (BUFFER IS HERE) HERE

Problem is in first section here. Buffer should be empty, but is not!

2016-10-02 08:03:55,876 DEBUG: ================================================================================
2016-10-02 08:03:55,876 DEBUG: Sending>>> command -v lsb_release<<<
2016-10-02 08:03:55,877 DEBUG: Expecting>>>root#sTpytyq0> <<<
 command -v lsb_release
root#sTpytyq0>  command -v lsb_release
/usr/bin/lsb_release
root#sTpytyq0> incoming
root#sTpytyq0>  command -v lsb_release
/usr/bin/lsb_release
root#sTpytyq0> 
0d1b5b4b726f6f742373547079747971303e2020636f6d6d616e64202d76206c73625f72656c656173650d0a2f7573722f62696e2f6c73625f72656c656173650d0a726f6f742373547079747971303e20
incomingdone
HERE
 command -v lsb_release
/usr/bin/lsb_release
root#sTpytyq0> 
HERE
2016-10-02 08:03:55,879 DEBUG: Output (squashed): root#sTpytyq0>  [...]
2016-10-02 08:03:55,879 DEBUG: shutit_pexpect_child.before (hex)>>>0d1b5b4b<<<
2016-10-02 08:03:55,879 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f742373547079747971303e20<<<
<<<
2016-10-02 08:03:55,879 DEBUG: shutit_pexpect_child.after>>>root#sTpytyq0> <<<
2016-10-02 08:03:55,879 DEBUG: Retrieving output from command:  cat /etc/issue
2016-10-02 08:03:55,879 DEBUG: Sending in session: target_child
2016-10-02 08:03:55,879 DEBUG: ================================================================================
2016-10-02 08:03:55,879 DEBUG: Sending>>> cat /etc/issue<<<
2016-10-02 08:03:55,880 DEBUG: Expecting>>>root#sTpytyq0> <<<
 cat /etc/issue
HERE

HERE
2016-10-02 08:03:55,880 DEBUG: Output (squashed):  command -v lsb_release/usr/bi [...]
2016-10-02 08:03:55,880 DEBUG: shutit_pexpect_child.before (hex)>>>20636f6d6d616e64202d76206c73625f72656c656173650d0a2f7573722f62696e2f6c73625f72656c656173650d0a<<<
2016-10-02 08:03:55,880 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f742373547079747971303e20<<<
2016-10-02 08:03:55,880 DEBUG: shutit_pexpect_child.before>>> command -v lsb_release
/usr/bin/lsb_release
<<<
2016-10-02 08:03:55,880 DEBUG: shutit_pexpect_child.after>>>root#sTpytyq0> <<<
2016-10-02 08:03:55,880 DEBUG: Retrieving output from command:  test -a /etc/os-release && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN
2016-10-02 08:03:55,880 DEBUG: Sending in session: target_child
2016-10-02 08:03:55,881 DEBUG: ================================================================================
2016-10-02 08:03:55,881 DEBUG: Sending>>> test -a /etc/os-release && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN<<<
2016-10-02 08:03:55,881 DEBUG: Expecting>>>root#sTpytyq0> <<<
 test -a /etc/os-release && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN
 cat /etc/issue
Debian GNU/Linux 8 \n \l

IST-""FILFIN0>  test -a /etc/os-release && echo FILEXIST-""FILFIN || echo FILNEX 
FILEXIST-FILFIN
root#sTpytyq0> incoming
 cat /etc/issue
Debian GNU/Linux 8 \n \l

IST-""FILFIN0>  test -a /etc/os-release && echo FILEXIST-""FILFIN || echo FILNEX 
FILEXIST-FILFIN
root#sTpytyq0> 
20636174202f6574632f69737375650d0a44656269616e20474e552f4c696e75782038205c6e205c6c0d0a0d0a726f6f742373547079747971303e202074657374202d61202f6574632f6f732d72656c65617365202626206563686f2046494c45584953542d222246494c46494e207c7c206563686f2046494c4e4558200d4953542d222246494c46494e0d0a46494c45584953542d46494c46494e0d0a726f6f742373547079747971303e20
incomingdone
HERE
IST-""FILFINc/os-release && echo FILEXIST-""FILFIN || echo FILNEX 
FILEXIST-FILFIN
root#sTpytyq0> 
HERE
2016-10-02 08:03:55,885 DEBUG: Output (squashed):  cat /etc/issueDebian GNU/Linu [...]
2016-10-02 08:03:55,885 DEBUG: shutit_pexpect_child.before (hex)>>>20636174202f6574632f69737375650d0a44656269616e20474e552f4c696e75782038205c6e205c6c0d0a0d0a<<<
2016-10-02 08:03:55,885 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f742373547079747971303e20<<<
2016-10-02 08:03:55,885 DEBUG: shutit_pexpect_child.before>>> cat /etc/issue
Debian GNU/Linux 8 \n \l

<<<
2016-10-02 08:03:55,885 DEBUG: shutit_pexpect_child.after>>>root#sTpytyq0> <<<
'before>>>>: cat /etc/issue\r\nDebian GNU/Linux 8 \\n \\l\r\n\r\n<<<< after:>>>>root#sTpytyq0> <<<<'
2016-10-02 08:03:55,885 CRITICAL: Did not see FIL(N)?EXIST in output:
issue
Debian GNU/Linux 8 \n \l
2016-10-02 08:03:55,885 CRITICAL: Error seen, exiting with status 1
2016-10-02 08:03:55,885 DEBUG: Exiting with error code: 1
2016-10-02 08:03:55,886 DEBUG: Resetting terminal
imiell@Ians-Air:/space/git/git-101-tutorial$
ianmiell commented 7 years ago

Fixing the buffer is not sufficient: I think I need also to read in the whole buffer into the before if the buffer exists...

2016-10-02 08:15:47,761 DEBUG: ================================================================================
2016-10-02 08:15:47,761 DEBUG: Sending>>> test -d /tmp/shutit_imiell/Ians-Air.home_imiell_1475392461.98.984238/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN<<<
2016-10-02 08:15:47,761 DEBUG: Expecting>>>root#DntyACoD> <<<
 test -d /tmp/shutit_imiell/Ians-Air.home_imiell_1475392461.98.984238/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN
4238/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN61.98.98 
FILNEXIST-FILFIN
root#DntyACoD> incoming
4238/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN61.98.98 
FILNEXIST-FILFIN
root#DntyACoD> 
0d1b5b4b726f6f7423446e747941436f443e202074657374202d64202f746d702f7368757469745f696d69656c6c2f49616e732d4169722e686f6d655f696d69656c6c5f313437353339323436312e39382e3938200d343233382f656e7669726f6e6d656e745f6964202626206563686f2046494c45584953542d222246494c46494e207c7c206563686f2046494c4e45584953542d222246494c46494e0d0a46494c4e45584953542d46494c46494e0d0a726f6f7423446e747941436f443e20
incomingdone
PROBLEM: FIXING
2016-10-02 08:15:47,765 DEBUG: Output (squashed): root#DntyACoD>  [...]
2016-10-02 08:15:47,765 DEBUG: shutit_pexpect_child.before (hex)>>>0d1b5b4b<<<
2016-10-02 08:15:47,765 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f7423446e747941436f443e20<<<
<<<
2016-10-02 08:15:47,765 DEBUG: shutit_pexpect_child.after>>>root#DntyACoD> <<<
'before>>>>:\r\x1b[K<<<< after:>>>>root#DntyACoD> <<<<'
2016-10-02 08:15:47,766 CRITICAL: Did not see FIL(N)?EXIST in output:

2016-10-02 08:15:47,766 CRITICAL: Error seen, exiting with status 1
2016-10-02 08:15:47,766 DEBUG: Exiting with error code: 1
2016-10-02 08:15:47,766 DEBUG: Resetting terminal
ianmiell commented 7 years ago 

    def expect(self,                                                                                                                                                              
               expect,                                                                                                                                                            
               timeout=None):                                                                                                                                                     
        """Handle child expects, with EOF and TIMEOUT handled                                                                                                                     
        """                                                                                                                                                                       
        if type(expect) == str:                                                                                                                                                   
            expect = [expect]                                                                                                                                                     
        # TODO: correct self.pexpect_child.buffer and append buffer to self.pexpect.before...                                                                                     
        return self.pexpect_child.expect(expect + [pexpect.TIMEOUT] + [pexpect.EOF], timeout=timeout)
ianmiell commented 7 years ago

Nope, that didn't work either!

ianmiell commented 7 years ago

More output with before, after and buffer recorded:


2016-10-02 09:52:44,928 DEBUG: ================================================================================
2016-10-02 09:52:44,928 DEBUG: Sending>>> test -d /tmp/shutit_imiell/Ians-Air.home_imiell_1475398343.93.927499/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN<<<
2016-10-02 09:52:44,929 DEBUG: Expecting>>>root#mWwdv5hE> <<<
 test -d /tmp/shutit_imiell/Ians-Air.home_imiell_1475398343.93.927499/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN
 test -d /tmp/shutit_imiell/Ians-Air.home_imiell_1475398343incoming
 test -d /tmp/shutit_imiell/Ians-Air.home_imiell_1475398343
2074657374202d64202f746d702f7368757469745f696d69656c6c2f49616e732d4169722e686f6d655f696d69656c6c5f31343735333938333433
incomingdone
7499/environment_id && echoincoming
7499/environment_id && echo
2e39332e3932200d373439392f656e7669726f6e6d656e745f6964202626206563686f
incomingdone
 FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN
incoming
 FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN

2046494c45584953542d222246494c46494e207c7c206563686f2046494c4e45584953542d222246494c46494e0d0a
incomingdone
FILNEXIST-FILFIN
root#mWwdv5hE> incoming
FILNEXIST-FILFIN
root#mWwdv5hE> 
46494c4e45584953542d46494c46494e0d0a726f6f74236d577764763568453e20
incomingdone
2016-10-02 09:52:44,934 DEBUG: Output (squashed):  test -d /tmp/shutit_imiell/Ia [...]
2016-10-02 09:52:44,934 DEBUG: shutit_pexpect_child.before (hex)>>>2074657374202d64202f746d702f7368757469745f696d69656c6c2f49616e732d4169722e686f6d655f696d69656c6c5f313437353339383334332e39332e3932200d373439392f656e7669726f6e6d656e745f6964202626206563686f2046494c45584953542d222246494c46494e207c7c206563686f2046494c4e45584953542d222246494c46494e0d0a46494c4e45584953542d46494c46494e0d0a<<<
2016-10-02 09:52:44,934 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f74236d577764763568453e20<<<
2016-10-02 09:52:44,935 DEBUG: shutit_pexpect_child.buffer(hex)>>><<<
7499/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFINmp/shutit_imiell/Ians-Air.home_imiell_1475398343.93.92 
FILNEXIST-FILFIN
<<<
2016-10-02 09:52:44,935 DEBUG: shutit_pexpect_child.after>>>root#mWwdv5hE> <<<
2016-10-02 09:52:44,935 DEBUG: shutit_pexpect_child.buffer>>><<<
2016-10-02 09:52:44,935 DEBUG: Retrieving output from command:  command -v lsb_release
2016-10-02 09:52:44,935 DEBUG: Sending in session: target_child
2016-10-02 09:52:44,935 DEBUG: ================================================================================
2016-10-02 09:52:44,935 DEBUG: Sending>>> command -v lsb_release<<<
2016-10-02 09:52:44,936 DEBUG: Expecting>>>root#mWwdv5hE> <<<
 command -v lsb_release
 command -v lsb_release
incoming
 command -v lsb_release

20636f6d6d616e64202d76206c73625f72656c656173650d0a
incomingdone
/usr/bin/lsb_release
incoming
/usr/bin/lsb_release

2f7573722f62696e2f6c73625f72656c656173650d0a
incomingdone
root#mWwdv5hE> incoming
root#mWwdv5hE> 
726f6f74236d577764763568453e20
incomingdone
2016-10-02 09:52:44,938 DEBUG: Output (squashed): /usr/bin/lsb_releaseroot#mWwdv [...]
2016-10-02 09:52:44,938 DEBUG: shutit_pexpect_child.before (hex)>>>20636f6d6d616e64202d76206c73625f72656c656173650d0a2f7573722f62696e2f6c73625f72656c656173650d0a<<<
2016-10-02 09:52:44,938 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f74236d577764763568453e20<<<
2016-10-02 09:52:44,938 DEBUG: shutit_pexpect_child.buffer(hex)>>><<<
2016-10-02 09:52:44,938 DEBUG: shutit_pexpect_child.before>>> command -v lsb_release
/usr/bin/lsb_release
<<<
2016-10-02 09:52:44,939 DEBUG: shutit_pexpect_child.after>>>root#mWwdv5hE> <<<
2016-10-02 09:52:44,939 DEBUG: shutit_pexpect_child.buffer>>><<<
2016-10-02 09:52:44,939 DEBUG: Sending in session: target_child
2016-10-02 09:52:44,939 DEBUG: ================================================================================
2016-10-02 09:52:44,939 DEBUG: Sending>>> lsb_release -a<<<
2016-10-02 09:52:44,939 DEBUG: Expecting>>>root#mWwdv5hE> <<<
 lsb_release -a
 lsb_release -a
incoming
 lsb_release -a

206c73625f72656c65617365202d610d0a
incomingdone
No LSB modules are available.
Distributor ID: Debian
Description:    Debian GNU/Linux 8.4 (jessie)
Release:    8.4
Codename:   jessie
incoming
No LSB modules are available.
Distributor ID: Debian
Description:    Debian GNU/Linux 8.4 (jessie)
Release:    8.4
Codename:   jessie

4e6f204c5342206d6f64756c65732061726520617661696c61626c652e0d0a4469737472696275746f722049443a0944656269616e0d0a4465736372697074696f6e3a0944656269616e20474e552f4c696e757820382e3420286a6573736965290d0a52656c656173653a09382e340d0a436f64656e616d653a096a65737369650d0a
incomingdone
root#mWwdv5hE> incoming
root#mWwdv5hE> 
726f6f74236d577764763568453e20
incomingdone
2016-10-02 09:52:45,133 DEBUG: Output (squashed): No LSB modules are available.D [...]
2016-10-02 09:52:45,133 DEBUG: shutit_pexpect_child.before (hex)>>>206c73625f72656c65617365202d610d0a4e6f204c5342206d6f64756c65732061726520617661696c61626c652e0d0a4469737472696275746f722049443a0944656269616e0d0a4465736372697074696f6e3a0944656269616e20474e552f4c696e757820382e3420286a6573736965290d0a52656c656173653a09382e340d0a436f64656e616d653a096a65737369650d0a<<<
2016-10-02 09:52:45,133 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f74236d577764763568453e20<<<
2016-10-02 09:52:45,133 DEBUG: shutit_pexpect_child.buffer(hex)>>><<<
2016-10-02 09:52:45,133 DEBUG: shutit_pexpect_child.before>>> lsb_release -a
No LSB modules are available.
Distributor ID: Debian
Description:    Debian GNU/Linux 8.4 (jessie)
Release:    8.4
Codename:   jessie
<<<
2016-10-02 09:52:45,133 DEBUG: shutit_pexpect_child.after>>>root#mWwdv5hE> <<<
2016-10-02 09:52:45,133 DEBUG: shutit_pexpect_child.buffer>>><<<
2016-10-02 09:52:45,134 DEBUG: Sending in session: target_child
2016-10-02 09:52:45,134 DEBUG: ================================================================================
2016-10-02 09:52:45,134 DEBUG: Sending>>> mkdir -p /tmp/shutit_imiell/Ians-Air.home_imiell_1475398343.93.927499/environment_id && chmod -R 777 /tmp/shutit_imiell && touch /tmp/shutit_imiell/Ians-Air.home_imiell_1475398343.93.927499/environment_id/ZZO0ervN<<<
2016-10-02 09:52:45,134 DEBUG: Expecting>>>root#mWwdv5hE> <<<
 mkdir -p /tmp/shutit_imiell/Ians-Air.home_imiell_1475398343.93.927499/environment_id && chmod -R 777 /tmp/shutit_imiell && touch /tmp/shutit_imiell/Ians-Air.home_imiell_1475398343.93.927499/environment_id/ZZO0ervN
 mkdir -incoming
 mkdir -
206d6b646972202d
incomingdone
p /tmp/shutiincoming
p /tmp/shuti
70202f746d702f7368757469
incomingdone
t_imiell/Ians-Air.homincoming
t_imiell/Ians-Air.hom
745f696d69656c6c2f49616e732d4169722e686f6d
incomingdone
e_imiell_1475398incoming
e_imiell_1475398
655f696d69656c6c5f31343735333938
incomingdone
2749incoming
274993.9 
3334332e39332e39200d32373439
incomingdone
9/environincoming
9/environ
392f656e7669726f6e
incomingdone
ment_id incoming
ment_id 
6d656e745f696420
incomingdone
&incoming
&
26
incomingdone
& chmod -R 777 /incoming
& chmod -R 777 /
262063686d6f64202d5220373737202f
incomingdone
tmp/shutit_imiell &incoming
tmp/shutit_imiell &
746d702f7368757469745f696d69656c6c2026
incomingdone
& touch /tmp/shutit_incoming
& touch /tmp/shutit_
2620746f756368202f746d702f7368757469745f
incomingdone
ell/Ians-Air.incoming
ell/Ians-Air.
696d69200d656c6c2f49616e732d4169722e
incomingdone
home_imincoming
home_im
686f6d655f696d
incomingdone
iell_1incoming
iell_1
69656c6c5f31
incomingdone
475398343.93.927499/eincoming
475398343.93.927499/e
3437353339383334332e39332e3932373439392f65
incomingdone
nvironment_incoming
nvironment_
6e7669726f6e6d656e745f
incomingdone
id/ZZO0eincoming
id/ZZO0e
69642f5a5a4f3065
incomingdone
rvN
incoming
rvN

72764e0d0a
incomingdone
root#mWwdv5hE> incoming
root#mWwdv5hE> 
726f6f74236d577764763568453e20
incomingdone
2016-10-02 09:52:45,156 DEBUG: Output (squashed):  mkdir -p /tmp/shutit_imiell/I [...]
2016-10-02 09:52:45,157 DEBUG: shutit_pexpect_child.before (hex)>>>206d6b646972202d70202f746d702f7368757469745f696d69656c6c2f49616e732d4169722e686f6d655f696d69656c6c5f313437353339383334332e39332e39200d32373439392f656e7669726f6e6d656e745f69642026262063686d6f64202d5220373737202f746d702f7368757469745f696d69656c6c20262620746f756368202f746d702f7368757469745f696d69200d656c6c2f49616e732d4169722e686f6d655f696d69656c6c5f313437353339383334332e39332e3932373439392f656e7669726f6e6d656e745f69642f5a5a4f306572764e0d0a<<<
2016-10-02 09:52:45,157 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f74236d577764763568453e20<<<
2016-10-02 09:52:45,157 DEBUG: shutit_pexpect_child.buffer(hex)>>><<<
ell/Ians-Air.home_imiell_1475398343.93.927499/environment_id/ZZO0ervN/shutit_imi t_imiell/Ians-Air.home_imiell_1475398343.93.9 
<<<
2016-10-02 09:52:45,157 DEBUG: shutit_pexpect_child.after>>>root#mWwdv5hE> <<<
2016-10-02 09:52:45,157 DEBUG: shutit_pexpect_child.buffer>>><<<
2016-10-02 09:52:45,158 DEBUG: Expecting: root#mWwdv5hE> 
incoming
 echo EXIT_C
206563686f20455849545f43
incomingdone
incoming
ODE:$?
EXIT_CODE:0

4f44453a243f0d0a455849545f434f44453a300d0a
incomingdone
incoming
root#mWwdv5hE> 
726f6f74236d577764763568453e20
incomingdone
2016-10-02 09:52:45,159 INFO: State restored.
2016-10-02 09:52:45,160 WARNING: Retrieving output from command:  echo $TMUX
2016-10-02 09:52:45,160 DEBUG: Sending in session: target_child
2016-10-02 09:52:45,160 DEBUG: ================================================================================
2016-10-02 09:52:45,160 DEBUG: Sending>>> echo $TMUX<<<
2016-10-02 09:52:45,160 DEBUG: Expecting>>>root#mWwdv5hE> <<<
 echo $TMUX
 echo $TMUX

root#mWwdv5hE> incoming
 echo $TMUX

root#mWwdv5hE> 
206563686f2024544d55580d0a0d0a726f6f74236d577764763568453e20
incomingdone
2016-10-02 09:52:45,162 DEBUG: Output (squashed): root#mWwdv5hE>  [...]
2016-10-02 09:52:45,162 DEBUG: shutit_pexpect_child.before (hex)>>>206563686f2024544d55580d0a0d0a<<<
2016-10-02 09:52:45,162 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f74236d577764763568453e20<<<
2016-10-02 09:52:45,162 DEBUG: shutit_pexpect_child.buffer(hex)>>><<<
2016-10-02 09:52:45,162 DEBUG: shutit_pexpect_child.before>>> echo $TMUX

<<<
2016-10-02 09:52:45,162 DEBUG: shutit_pexpect_child.after>>>root#mWwdv5hE> <<<
2016-10-02 09:52:45,163 DEBUG: shutit_pexpect_child.buffer>>><<<
2016-10-02 09:52:45,163 WARNING: Retrieving output from command:  echo $TERM
2016-10-02 09:52:45,163 DEBUG: Sending in session: target_child
2016-10-02 09:52:45,163 DEBUG: ================================================================================
2016-10-02 09:52:45,163 DEBUG: Sending>>> echo $TERM<<<
2016-10-02 09:52:45,163 DEBUG: Expecting>>>root#mWwdv5hE> <<<
 echo $TERM
 echo $TERM
xterm
root#mWwdv5hE> incoming
 echo $TERM
xterm
root#mWwdv5hE> 
206563686f20245445524d0d0a787465726d0d0a726f6f74236d577764763568453e20
incomingdone
2016-10-02 09:52:45,165 DEBUG: Output (squashed): xtermroot#mWwdv5hE>  [...]
2016-10-02 09:52:45,165 DEBUG: shutit_pexpect_child.before (hex)>>>206563686f20245445524d0d0a787465726d0d0a<<<
2016-10-02 09:52:45,165 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f74236d577764763568453e20<<<
2016-10-02 09:52:45,165 DEBUG: shutit_pexpect_child.buffer(hex)>>><<<
2016-10-02 09:52:45,165 DEBUG: shutit_pexpect_child.before>>> echo $TERM
xterm
<<<
2016-10-02 09:52:45,165 DEBUG: shutit_pexpect_child.after>>>root#mWwdv5hE> <<<
2016-10-02 09:52:45,165 DEBUG: shutit_pexpect_child.buffer>>><<<
2016-10-02 09:52:45,166 DEBUG: Retrieving output from command:  test -a /tmp/shutit_fixterm && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN
2016-10-02 09:52:45,166 DEBUG: Sending in session: target_child
2016-10-02 09:52:45,166 DEBUG: ================================================================================
2016-10-02 09:52:45,166 DEBUG: Sending>>> test -a /tmp/shutit_fixterm && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN<<<
2016-10-02 09:52:45,166 DEBUG: Expecting>>>root#mWwdv5hE> <<<
 test -a /tmp/shutit_fixterm && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN
LNEXIST-""FILFINutit_fixterm && echo FILEXIST-""FILFIN || echo FI 
FILNEXIST-FILFIN
root#mWwdv5hE> incoming
LNEXIST-""FILFINutit_fixterm && echo FILEXIST-""FILFIN || echo FI 
FILNEXIST-FILFIN
root#mWwdv5hE> 
2074657374202d61202f746d702f7368757469745f6669787465726d202626206563686f2046494c45584953542d222246494c46494e207c7c206563686f204649200d4c4e45584953542d222246494c46494e0d0a46494c4e45584953542d46494c46494e0d0a726f6f74236d577764763568453e20
incomingdone
2016-10-02 09:52:45,169 DEBUG: Output (squashed):  test -a /tmp/shutit_fixterm & [...]
2016-10-02 09:52:45,169 DEBUG: shutit_pexpect_child.before (hex)>>>2074657374202d61202f746d702f7368757469745f6669787465726d202626206563686f2046494c45584953542d222246494c46494e207c7c206563686f204649200d4c4e45584953542d222246494c46494e0d0a46494c4e45584953542d46494c46494e0d0a<<<
2016-10-02 09:52:45,169 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f74236d577764763568453e20<<<
2016-10-02 09:52:45,169 DEBUG: shutit_pexpect_child.buffer(hex)>>><<<
LNEXIST-""FILFIN:45,169 DEBUG: shutit_pexpect_child.before>>> test -a /tmp/shutit_fixterm && echo FILEXIST-""FILFIN || echo FI 
FILNEXIST-FILFIN
<<<
2016-10-02 09:52:45,169 DEBUG: shutit_pexpect_child.after>>>root#mWwdv5hE> <<<
2016-10-02 09:52:45,170 DEBUG: shutit_pexpect_child.buffer>>><<<
2016-10-02 09:52:45,171 INFO: Fixing up your terminal, please wait...
2016-10-02 09:52:45,171 DEBUG: Sending file contents beginning: "ELF>@@H,@8@@@@@@88@8@@@LL``p(( [...]" to file: /tmp/shutit_fixterm
2016-10-02 09:52:45,171 DEBUG: Retrieving output from command:  whoami
2016-10-02 09:52:45,171 DEBUG: Sending in session: target_child
2016-10-02 09:52:45,172 DEBUG: ================================================================================
2016-10-02 09:52:45,172 DEBUG: Sending>>> whoami<<<
2016-10-02 09:52:45,172 DEBUG: Expecting>>>root#mWwdv5hE> <<<
 whoami
 whoami
incoming
 whoami

2077686f616d690d0a
incomingdone
root
incoming
root

726f6f740d0a
incomingdone
root#mWwdv5hE> incoming
root#mWwdv5hE> 
726f6f74236d577764763568453e20
incomingdone
2016-10-02 09:52:45,175 DEBUG: Output (squashed): rootroot#mWwdv5hE>  [...]
2016-10-02 09:52:45,176 DEBUG: shutit_pexpect_child.before (hex)>>>2077686f616d690d0a726f6f740d0a<<<
2016-10-02 09:52:45,176 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f74236d577764763568453e20<<<
2016-10-02 09:52:45,176 DEBUG: shutit_pexpect_child.buffer(hex)>>><<<
2016-10-02 09:52:45,176 DEBUG: shutit_pexpect_child.before>>> whoami
root
<<<
2016-10-02 09:52:45,176 DEBUG: shutit_pexpect_child.after>>>root#mWwdv5hE> <<<
2016-10-02 09:52:45,176 DEBUG: shutit_pexpect_child.buffer>>><<<
2016-10-02 09:52:45,176 DEBUG: Retrieving output from command:  id -n -g
2016-10-02 09:52:45,176 DEBUG: Sending in session: target_child
2016-10-02 09:52:45,176 DEBUG: ================================================================================
2016-10-02 09:52:45,176 DEBUG: Sending>>> id -n -g<<<
2016-10-02 09:52:45,177 DEBUG: Expecting>>>root#mWwdv5hE> <<<
 id -n -g
 id -n -g
incoming
 id -n -g

206964202d6e202d670d0a
incomingdone
root
incoming
root

726f6f740d0a
incomingdone
root#mWwdv5hE> incoming
root#mWwdv5hE> 
726f6f74236d577764763568453e20
incomingdone
2016-10-02 09:52:45,180 DEBUG: Output (squashed): rootroot#mWwdv5hE>  [...]
2016-10-02 09:52:45,180 DEBUG: shutit_pexpect_child.before (hex)>>>206964202d6e202d670d0a726f6f740d0a<<<
2016-10-02 09:52:45,181 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f74236d577764763568453e20<<<
2016-10-02 09:52:45,181 DEBUG: shutit_pexpect_child.buffer(hex)>>><<<
2016-10-02 09:52:45,181 DEBUG: shutit_pexpect_child.before>>> id -n -g
root
<<<
2016-10-02 09:52:45,181 DEBUG: shutit_pexpect_child.after>>>root#mWwdv5hE> <<<
2016-10-02 09:52:45,181 DEBUG: shutit_pexpect_child.buffer>>><<<
2016-10-02 09:52:45,182 DEBUG: Sending in session: target_child
2016-10-02 09:52:45,182 DEBUG: ================================================================================
2016-10-02 09:52:45,182 DEBUG: Sending>>> touch /tmp/shutit_fixterm<<<
2016-10-02 09:52:45,182 DEBUG: Expecting>>>root#mWwdv5hE> <<<
 touch /tmp/shutit_fixterm
 touch /tmp/shutit_fixterm
incoming
 touch /tmp/shutit_fixterm

20746f756368202f746d702f7368757469745f6669787465726d0d0a
incomingdone
root#mWwdv5hE> incoming
root#mWwdv5hE> 
726f6f74236d577764763568453e20
incomingdone
2016-10-02 09:52:45,185 DEBUG: Output (squashed): root#mWwdv5hE>  [...]
2016-10-02 09:52:45,186 DEBUG: shutit_pexpect_child.before (hex)>>>20746f756368202f746d702f7368757469745f6669787465726d0d0a<<<
2016-10-02 09:52:45,186 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f74236d577764763568453e20<<<
2016-10-02 09:52:45,186 DEBUG: shutit_pexpect_child.buffer(hex)>>><<<
2016-10-02 09:52:45,186 DEBUG: shutit_pexpect_child.before>>> touch /tmp/shutit_fixterm
<<<
2016-10-02 09:52:45,186 DEBUG: shutit_pexpect_child.after>>>root#mWwdv5hE> <<<
2016-10-02 09:52:45,186 DEBUG: shutit_pexpect_child.buffer>>><<<
2016-10-02 09:52:45,186 DEBUG: Expecting: root#mWwdv5hE> 
incoming
 echo EXIT_CODE:$?
EXIT_CODE:0
root#mWwdv5hE> 
206563686f20455849545f434f44453a243f0d0a455849545f434f44453a300d0a726f6f74236d577764763568453e20
incomingdone
2016-10-02 09:52:45,188 DEBUG: Sending in session: host_child
2016-10-02 09:52:45,188 DEBUG: ================================================================================
2016-10-02 09:52:45,188 DEBUG: Sending>>> cat /tmp/shutit_imielltmp_bqogfDPO | docker exec -i e851c85bebcc2e26b1710a6a259e4c4600dec72d1a1cfb0973731383d9960844 bash -c 'cat > /tmp/shutit_fixterm'<<<
2016-10-02 09:52:45,188 DEBUG: Expecting>>>ORIGIN_ENV#S7U1fCEF> <<<
 cat /tmp/shutit_imielltmp_bqogfDPO | docker exec -i e851c85bebcc2e26b1710a6a259e4c4600dec72d1a1cfb0973731383d9960844 bash -c 'cat > /tmp/shutit_fixterm'
 cat /tmp/shuincoming
 cat /tmp/shu
20636174202f746d702f736875
incomingdone
tit_imielltmp_bqogfDincoming
tit_imielltmp_bqogfD
7469745f696d69656c6c746d705f62716f676644
incomingdone
PO | docker exeincoming
PO | docker exe
504f207c20646f636b657220657865
incomingdone
c -i e851c85bebincoming
c -i e851c85beb
63202d692065383531633835626562
incomingdone
cc2e26b1710incoming
cc2e26b1710
6363326532366231373130
incomingdone
a6a259incoming
a6a259
613661323539
incomingdone
e4c4600incoming
e4c4600
65346334363030
incomingdone
dec72dincoming
dec72d
646563373264
incomingdone
1a1cfb09incoming
1a1cfb09
3161316366623039
incomingdone
7373138incoming
7373138
37333733313338
incomingdone
3d996084incoming
3d996084
3364393936303834
incomingdone
4 bash incoming
4 bash 
34206261736820
incomingdone
-c 'cat incoming
-c 'cat 
2d63202763617420
incomingdone
> /tmpincoming
> /tmp
3e202f746d70
incomingdone
/shincoming
/sh
2f7368
incomingdone
utitincoming
utit
75746974
incomingdone
_fixtincoming
_fixt
5f66697874
incomingdone
erm'
incoming
erm'

65726d270d0a
incomingdone
ORIGIN_ENV#S7U1fCEF> incoming
ORIGIN_ENV#S7U1fCEF> 
4f524947494e5f454e562353375531664345463e20
incomingdone
2016-10-02 09:52:45,350 DEBUG: Output (squashed): ORIGIN_ENV#S7U1fCEF>  [...]
2016-10-02 09:52:45,351 DEBUG: shutit_pexpect_child.before (hex)>>>20636174202f746d702f7368757469745f696d69656c6c746d705f62716f676644504f207c20646f636b65722065786563202d6920653835316338356265626363326532366231373130613661323539653463343630306465633732643161316366623039373337333133383364393936303834342062617368202d632027636174203e202f746d702f7368757469745f6669787465726d270d0a<<<
2016-10-02 09:52:45,351 DEBUG: shutit_pexpect_child.after (hex)>>>4f524947494e5f454e562353375531664345463e20<<<
2016-10-02 09:52:45,351 DEBUG: shutit_pexpect_child.buffer(hex)>>><<<
2016-10-02 09:52:45,351 DEBUG: shutit_pexpect_child.before>>> cat /tmp/shutit_imielltmp_bqogfDPO | docker exec -i e851c85bebcc2e26b1710a6a259e4c4600dec72d1a1cfb0973731383d9960844 bash -c 'cat > /tmp/shutit_fixterm'
<<<
2016-10-02 09:52:45,351 DEBUG: shutit_pexpect_child.after>>>ORIGIN_ENV#S7U1fCEF> <<<
2016-10-02 09:52:45,351 DEBUG: shutit_pexpect_child.buffer>>><<<
2016-10-02 09:52:45,351 DEBUG: Sending in session: target_child
2016-10-02 09:52:45,352 DEBUG: ================================================================================
2016-10-02 09:52:45,352 DEBUG: Sending>>> chown root /tmp/shutit_fixterm && chgrp root /tmp/shutit_fixterm<<<
2016-10-02 09:52:45,352 DEBUG: Expecting>>>root#mWwdv5hE> <<<
root#mWwdv5hE>  chown root /tmp/shutit_fixterm && chgrp root /tmp/shutit_fixterm
root#mWwdv5hE>  chown root /tmp/shutit_fixterm && chgrp root /tmp/shutit_fixterm
 chown root /tmp/shutit_fixterm && chgrp root /tmp/shutit_fixterm 
2063686f776e20726f6f74202f746d702f7368757469745f6669787465726d20262620636867727020726f6f74202f746d702f7368757469745f6669787465726d200d1b5b41726f6f74236d577764763568453e202063686f776e20726f6f74202f746d702f7368757469745f6669787465726d20262620636867727020726f6f74202f746d702f7368757469745f6669787465721b5b4b6d0d0a
incomingdone                                       root#mWwdv5hE>  [...]
2016-10-02 09:52:45,354 DEBUG: shutit_pexpect_child.before (hex)>>>2063686f776e20726f6f74202f746d702f7368757469745f6669787465726d20262620636867727020726f6f74202f746d702f7368757469745f6669787465726d200d1b5b41<<<
2016-10-02 09:52:45,354 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f74236d577764763568453e20<<<
2016-10-02 09:52:45,354 DEBUG: shutit_pexpect_child.buffer(hex)>>>2063686f776e20726f6f74202f746d702f7368757469745f6669787465726d20262620636867727020726f6f74202f746d702f7368757469<<<f6669787465721b5b4b6d0d0a<<<
2016-10-02 09:52:45,354 DEBUG: shutit_pexpect_child.after>>>root#mWwdv5hE> <<<shutit_fixterm && chgrp root /tmp/shutit_fixterm 
2016-10-02 09:52:45,354 DEBUG: shutit_pexpect_child.buffer>>> chown root /tmp/shutit_fixterm && chgrp root /tmp/shutit_fixterm
<<<
2016-10-02 09:52:45,354 DEBUG: Expecting: root#mWwdv5hE> 
incoming
 echo EXIT_CODE:$?

206563686f20455849545f434f44453a243f0d0a
incomingdone
incoming
root#mWwdv5hE>  echo EXIT_CODE:$?
EXIT_CODE:0
root#mWwdv5hE> 
726f6f74236d577764763568453e20206563686f20455849545f434f44453a243f0d0a455849545f434f44453a300d0a726f6f74236d577764763568453e20
incomingdone
2016-10-02 09:52:45,358 DEBUG: Un-clean login (1), trying:  chown root /tmp/shutit_fixterm && chgrp root /tmp/shutit_fixterm
 echo EXIT_CODE:$?

2016-10-02 09:52:45,358 DEBUG: Un-clean login (2), trying: root#mWwdv5hE> 
2016-10-02 09:52:45,358 DEBUG: Un-clean login (3), trying: root#mWwdv5hE> 
2016-10-02 09:52:45,358 DEBUG: Expecting: root#mWwdv5hE> 
2016-10-02 09:52:45,359 DEBUG: Sending in session: target_child
2016-10-02 09:52:45,359 DEBUG: ================================================================================
2016-10-02 09:52:45,359 DEBUG: Sending>>> chmod 777 /tmp/shutit_fixterm<<<
2016-10-02 09:52:45,359 DEBUG: Expecting>>>root#mWwdv5hE> <<<
 chmod 777 /tmp/shutit_fixterm
 chmod 777 /tmp/shutit_fixterm
incoming
 chmod 777 /tmp/shutit_fixterm

2063686d6f6420373737202f746d702f7368757469745f6669787465726d0d0a
incomingdone
root#mWwdv5hE> incoming
root#mWwdv5hE> 
726f6f74236d577764763568453e20
incomingdone
2016-10-02 09:52:45,362 DEBUG: Output (squashed): root#mWwdv5hE>  [...]
2016-10-02 09:52:45,362 DEBUG: shutit_pexpect_child.before (hex)>>>2063686d6f6420373737202f746d702f7368757469745f6669787465726d0d0a<<<
2016-10-02 09:52:45,362 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f74236d577764763568453e20<<<
2016-10-02 09:52:45,363 DEBUG: shutit_pexpect_child.buffer(hex)>>><<<
2016-10-02 09:52:45,363 DEBUG: shutit_pexpect_child.before>>> chmod 777 /tmp/shutit_fixterm
<<<
2016-10-02 09:52:45,363 DEBUG: shutit_pexpect_child.after>>>root#mWwdv5hE> <<<
2016-10-02 09:52:45,363 DEBUG: shutit_pexpect_child.buffer>>><<<
2016-10-02 09:52:45,363 DEBUG: Expecting: root#mWwdv5hE> 
incoming
 echo EXIT_CODE:$?
EXIT_CODE:0

206563686f20455849545f434f44453a243f0d0a455849545f434f44453a300d0a
incomingdone
incoming
root#mWwdv5hE> 
726f6f74236d577764763568453e20
incomingdone
2016-10-02 09:52:45,364 DEBUG: Retrieving output from command:  test -a /tmp/shutit_fixterm_stty && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN
2016-10-02 09:52:45,365 DEBUG: Sending in session: target_child
2016-10-02 09:52:45,365 DEBUG: ================================================================================
2016-10-02 09:52:45,365 DEBUG: Sending>>> test -a /tmp/shutit_fixterm_stty && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN<<<
2016-10-02 09:52:45,365 DEBUG: Expecting>>>root#mWwdv5hE> <<<
 test -a /tmp/shutit_fixterm_stty && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN
 test -a /tmp/shutit_fixterm_stty && echo FILEXIST-""FILFIN || eincoming
 test -a /tmp/shutit_fixterm_stty && echo FILEXIST-""FILFIN || e
2074657374202d61202f746d702f7368757469745f6669787465726d5f73747479202626206563686f2046494c45584953542d222246494c46494e207c7c2065
incomingdone
ho FILNEXIST-""FILFIN
incoming
ho FILNEXIST-""FILFIN

63200d686f2046494c4e45584953542d222246494c46494e0d0a
incomingdone
FILNEXIST-FILFIN
incoming
FILNEXIST-FILFIN

46494c4e45584953542d46494c46494e0d0a
incomingdone
root#mWwdv5hE> incoming
root#mWwdv5hE> 
726f6f74236d577764763568453e20
incomingdone
2016-10-02 09:52:45,367 DEBUG: Output (squashed):  test -a /tmp/shutit_fixterm_s [...]
2016-10-02 09:52:45,367 DEBUG: shutit_pexpect_child.before (hex)>>>2074657374202d61202f746d702f7368757469745f6669787465726d5f73747479202626206563686f2046494c45584953542d222246494c46494e207c7c206563200d686f2046494c4e45584953542d222246494c46494e0d0a46494c4e45584953542d46494c46494e0d0a<<<
2016-10-02 09:52:45,367 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f74236d577764763568453e20<<<
2016-10-02 09:52:45,367 DEBUG: shutit_pexpect_child.buffer(hex)>>><<<
ho FILNEXIST-""FILFIN68 DEBUG: shutit_pexpect_child.before>>> test -a /tmp/shutit_fixterm_stty && echo FILEXIST-""FILFIN || ec 
FILNEXIST-FILFIN
<<<
2016-10-02 09:52:45,368 DEBUG: shutit_pexpect_child.after>>>root#mWwdv5hE> <<<
2016-10-02 09:52:45,368 DEBUG: shutit_pexpect_child.buffer>>><<<
2016-10-02 09:52:45,368 DEBUG: Sending in session: target_child
2016-10-02 09:52:45,368 DEBUG: ================================================================================
2016-10-02 09:52:45,368 DEBUG: Sending>>> stty >  /tmp/shutit_fixterm_stty<<<
2016-10-02 09:52:45,368 DEBUG: Expecting>>>root#mWwdv5hE> <<<
 stty >  /tmp/shutit_fixterm_stty
 stty >  /tmp/shutit_fixterincoming
 stty >  /tmp/shutit_fixter
2073747479203e20202f746d702f7368757469745f666978746572
incomingdone
m_stty
incoming
m_stty

6d5f737474790d0a
incomingdone
root#mWwdv5hE> incoming
root#mWwdv5hE> 
726f6f74236d577764763568453e20
incomingdone
2016-10-02 09:52:45,372 DEBUG: Output (squashed): root#mWwdv5hE>  [...]
2016-10-02 09:52:45,372 DEBUG: shutit_pexpect_child.before (hex)>>>2073747479203e20202f746d702f7368757469745f6669787465726d5f737474790d0a<<<
2016-10-02 09:52:45,372 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f74236d577764763568453e20<<<
2016-10-02 09:52:45,372 DEBUG: shutit_pexpect_child.buffer(hex)>>><<<
2016-10-02 09:52:45,372 DEBUG: shutit_pexpect_child.before>>> stty >  /tmp/shutit_fixterm_stty
<<<
2016-10-02 09:52:45,372 DEBUG: shutit_pexpect_child.after>>>root#mWwdv5hE> <<<
2016-10-02 09:52:45,372 DEBUG: shutit_pexpect_child.buffer>>><<<
2016-10-02 09:52:45,372 DEBUG: Expecting: root#mWwdv5hE> 
incoming
 echo EXIT_CODE:$?

206563686f20455849545f434f44453a243f0d0a
incomingdone
incoming
EXIT_CODE:0
root#mWwdv5hE> 
455849545f434f44453a300d0a726f6f74236d577764763568453e20
incomingdone

==========Configure git to tell it who you are (user.name and user.email). Don't forget that CTRL-h will give you hints.

Hit CTRL-h for help, CTRL-s to skip==========

You now have a standard shell. Hit CTRL and then ] at the same time to continue ShutIt run.
Hit CTRL and u to save the state to a docker image
 /tmp/shutit_fixterm
root#mWwdv5hE> 2016-10-02 09:52:45,964 INFO: Test skipped

OK!

2016-10-02 09:52:46,969 INFO: Replacing container, please wait...
2016-10-02 09:52:47,073 DEBUG: Sending in session: host_child
2016-10-02 09:52:47,073 DEBUG: ================================================================================
2016-10-02 09:52:47,073 DEBUG: Sending>>> docker rm -f e851c85bebcc2e26b1710a6a259e4c4600dec72d1a1cfb0973731383d9960844 && rm -f /tmp/shutit_imiell/Ians-Air.home_imiell_1475398343.93.927499/cidfiles/imiell_cidfile_Ians-Air.home_imiell_1475398343.93.927499<<<
2016-10-02 09:52:47,073 DEBUG: Expecting>>>ORIGIN_ENV#S7U1fCEF> <<<
 docker rm -f e851c85bebcc2e26b1710a6a259e4c4600dec72d1a1cfb0973731383d9960844 && rm -f /tmp/shutit_imiell/Ians-Air.home_imiell_1475398343.93.927499/cidfiles/imiell_cidfile_Ians-Air.home_imiell_1475398343.93.927499
 docker rmincoming
 docker rm
20646f636b657220726d
incomingdone
 -f e851c85bebincoming
 -f e851c85beb
202d662065383531633835626562
incomingdone
cc2e26b171incoming
cc2e26b171
63633265323662313731
incomingdone
0a6a259e4cincoming
0a6a259e4c
30613661323539653463
incomingdone
4600dec72dincoming
4600dec72d
34363030646563373264
incomingdone
1a1cfb09incoming
1a1cfb09
3161316366623039
incomingdone
73731383incoming
73731383
3733373331333833
incomingdone
d996084incoming
d996084
64393936303834
incomingdone
4 && rmincoming
4 && rm
3420262620726d
incomingdone
 -f /tmincoming
 -f /tm
202d66202f746d
incomingdone
p/shutiincoming
p/shuti
702f7368757469
incomingdone
t_imincoming
t_im
745f696d
incomingdone
iell/Iaincoming
iell/Ia
69656c6c2f4961
incomingdone
ns-Airincoming
ns-Air
6e732d416972
incomingdone
.home_imiincoming
.home_imi
2e686f6d655f696d69
incomingdone
ell_147incoming
ell_147
656c6c5f313437
incomingdone
5398343.9incoming
5398343.9
353339383334332e39
incomingdone
3.9274incoming
3.9274
332e39323734
incomingdone
99/cidfiincoming
99/cidfi
39392f6369646669
incomingdone
les/imincoming
les/im
6c65732f696d
incomingdone
iell_ciincoming
iell_ci
69656c6c5f6369
incomingdone
dfileincoming
dfile
6466696c65
incomingdone
_Ians-Aincoming
_Ians-A
5f49616e732d41
incomingdone
ir.hoincoming
ir.ho
69722e686f
incomingdone
me_imieincoming
me_imie
6d655f696d6965
incomingdone
ll_14incoming
ll_14
6c6c5f3134
incomingdone
753983incoming
753983
373533393833
incomingdone
43.93.incoming
43.93.
34332e39332e
incomingdone
92749incoming
92749
3932373439
incomingdone
9
incoming
9

390d0a
incomingdone
e851c85bebcc2e26b1710a6a259e4c4600dec72d1a1cfb0973731383d9960844
incoming
e851c85bebcc2e26b1710a6a259e4c4600dec72d1a1cfb0973731383d9960844

653835316338356265626363326532366231373130613661323539653463343630306465633732643161316366623039373337333133383364393936303834340d0a
incomingdone
ORIGIN_ENV#S7U1fCEF> incoming
ORIGIN_ENV#S7U1fCEF> 
4f524947494e5f454e562353375531664345463e20
incomingdone
2016-10-02 09:52:47,546 DEBUG: Output (squashed): e851c85bebcc2e26b1710a6a259e4c [...]
2016-10-02 09:52:47,546 DEBUG: shutit_pexpect_child.before (hex)>>>20646f636b657220726d202d66206538353163383562656263633265323662313731306136613235396534633436303064656337326431613163666230393733373331333833643939363038343420262620726d202d66202f746d702f7368757469745f696d69656c6c2f49616e732d4169722e686f6d655f696d69656c6c5f313437353339383334332e39332e3932373439392f63696466696c65732f696d69656c6c5f63696466696c655f49616e732d4169722e686f6d655f696d69656c6c5f313437353339383334332e39332e3932373439390d0a653835316338356265626363326532366231373130613661323539653463343630306465633732643161316366623039373337333133383364393936303834340d0a<<<
2016-10-02 09:52:47,546 DEBUG: shutit_pexpect_child.after (hex)>>>4f524947494e5f454e562353375531664345463e20<<<
2016-10-02 09:52:47,546 DEBUG: shutit_pexpect_child.buffer(hex)>>><<<
2016-10-02 09:52:47,546 DEBUG: shutit_pexpect_child.before>>> docker rm -f e851c85bebcc2e26b1710a6a259e4c4600dec72d1a1cfb0973731383d9960844 && rm -f /tmp/shutit_imiell/Ians-Air.home_imiell_1475398343.93.927499/cidfiles/imiell_cidfile_Ians-Air.home_imiell_1475398343.93.927499
e851c85bebcc2e26b1710a6a259e4c4600dec72d1a1cfb0973731383d9960844
<<<
2016-10-02 09:52:47,546 DEBUG: shutit_pexpect_child.after>>>ORIGIN_ENV#S7U1fCEF> <<<
2016-10-02 09:52:47,546 DEBUG: shutit_pexpect_child.buffer>>><<<
2016-10-02 09:52:47,547 INFO: Startup command is: docker run --cidfile=/tmp/shutit_imiell/Ians-Air.home_imiell_1475398343.93.927499/cidfiles/imiell_cidfile_Ians-Air.home_imiell_1475398343.93.927499 -t -i imiell/git-101-tutorial:step_5 /bin/bash
2016-10-02 09:52:47,547 INFO: Downloading image, please be patient
2016-10-02 09:52:47,657 DEBUG: sessions before: {'target_child': <shutit_pexpect.ShutItPexpectSession object at 0x110219250>, 'host_child': <shutit_pexpect.ShutItPexpectSession object at 0x110219c50>}
2016-10-02 09:52:47,658 DEBUG: sessions after: {'target_child': <shutit_pexpect.ShutItPexpectSession object at 0x10f722cd0>, 'host_child': <shutit_pexpect.ShutItPexpectSession object at 0x110219c50>}
incoming
root@73da21abf428:/myproject# 
726f6f74403733646132316162663432383a2f6d7970726f6a6563742320
incomingdone
2016-10-02 09:52:48,271 DEBUG: root@73da21abf428:/myproject#
2016-10-02 09:52:48,271 DEBUG: Prompt found, breaking out
2016-10-02 09:52:48,271 DEBUG: Checking exit status
2016-10-02 09:52:48,271 DEBUG: Expecting: ['\r\n.*[@#$] ']
incoming
 echo EXIT_CODE:$?
EXIT_CODE:0
root@73da21abf428:/myproject# 
206563686f20455849545f434f44453a243f0d0a455849545f434f44453a300d0a726f6f74403733646132316162663432383a2f6d7970726f6a6563742320
incomingdone
2016-10-02 09:52:48,274 DEBUG: Un-clean login (1), trying:   echo EXIT_CODE:$?
2016-10-02 09:52:48,274 DEBUG: Un-clean login (2), trying: 
EXIT_CODE:0
root@73da21abf428:/myproject# 
2016-10-02 09:52:48,274 DEBUG: Getting cid
2016-10-02 09:52:48,274 DEBUG: cid: 73da21abf428a503a3997d9ebf87d01e6d097f2e59b3846bb31fff089c532133
2016-10-02 09:52:48,274 DEBUG: Sending in session: target_child
2016-10-02 09:52:48,275 DEBUG: ================================================================================
2016-10-02 09:52:48,275 DEBUG: Sending>>> export SHUTIT_BACKUP_PS1_root=$PS1 && PS1='root#yVt1PHtT> ' && unset PROMPT_COMMAND && stty cols 320<<<
2016-10-02 09:52:48,275 DEBUG: Expecting>>>['\r\nroot#yVt1PHtT> ']<<<
 export SHUTIT_BACKUP_PS1_root=$PS1 && PS1='root#yVt1PHtT> ' && unset PROMPT_COMMAND && stty cols 320
Vt1PHtT> ' && unset PROMPT_COMMAND && stty cols 320
incoming
Vt1PHtT> ' && unset PROMPT_COMMAND && stty cols 320

206578706f7274205348555449545f4241434b55505f5053315f726f6f743d24505331202626205053313d27726f6f742379200d567431504874543e202720262620756e7365742050524f4d50545f434f4d4d414e44202626207374747920636f6c73203332300d0a
incomingdone
root#yVt1PHtT> incoming
root#yVt1PHtT> 
726f6f742379567431504874543e20
incomingdone
2016-10-02 09:52:48,282 DEBUG: Output (squashed):  export SHUTIT_BACKUP_PS1_root [...]
2016-10-02 09:52:48,282 DEBUG: shutit_pexpect_child.before (hex)>>>206578706f7274205348555449545f4241434b55505f5053315f726f6f743d24505331202626205053313d27726f6f742379200d567431504874543e202720262620756e7365742050524f4d50545f434f4d4d414e44202626207374747920636f6c7320333230<<<
2016-10-02 09:52:48,282 DEBUG: shutit_pexpect_child.after (hex)>>>0d0a726f6f742379567431504874543e20<<<
2016-10-02 09:52:48,282 DEBUG: shutit_pexpect_child.buffer(hex)>>><<<
Vt1PHtT> ' && unset PROMPT_COMMAND && stty cols 320<<<fore>>> export SHUTIT_BACKUP_PS1_root=$PS1 && PS1='root#y 
2016-10-02 09:52:48,283 DEBUG: shutit_pexpect_child.after>>>
root#yVt1PHtT> <<<
2016-10-02 09:52:48,283 DEBUG: shutit_pexpect_child.buffer>>><<<
Vt1PHtT> ' && unset PROMPT_COMMAND && stty cols 320<<<S1_root=$PS1 && PS1='root#y 
2016-10-02 09:52:48,283 DEBUG: Resetting default expect to: root#yVt1PHtT> 
2016-10-02 09:52:48,283 DEBUG: Sending in session: target_child
2016-10-02 09:52:48,283 DEBUG: ================================================================================
2016-10-02 09:52:48,283 DEBUG: Sending>>> shopt -s checkwinsize<<<
2016-10-02 09:52:48,283 DEBUG: Expecting>>>root#yVt1PHtT> <<<
 shopt -s checkwinsize
 shopt -s checkwinsize
incoming
 shopt -s checkwinsize

2073686f7074202d7320636865636b77696e73697a650d0a
incomingdone
root#yVt1PHtT> incoming
root#yVt1PHtT> 
726f6f742379567431504874543e20
incomingdone
2016-10-02 09:52:48,286 DEBUG: Output (squashed): root#yVt1PHtT>  [...]
2016-10-02 09:52:48,286 DEBUG: shutit_pexpect_child.before (hex)>>>2073686f7074202d7320636865636b77696e73697a650d0a<<<
2016-10-02 09:52:48,286 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f742379567431504874543e20<<<
2016-10-02 09:52:48,286 DEBUG: shutit_pexpect_child.buffer(hex)>>><<<
2016-10-02 09:52:48,286 DEBUG: shutit_pexpect_child.before>>> shopt -s checkwinsize
<<<
2016-10-02 09:52:48,286 DEBUG: shutit_pexpect_child.after>>>root#yVt1PHtT> <<<
2016-10-02 09:52:48,286 DEBUG: shutit_pexpect_child.buffer>>><<<
2016-10-02 09:52:48,287 DEBUG: Sending in session: target_child
2016-10-02 09:52:48,287 DEBUG: ================================================================================
2016-10-02 09:52:48,287 DEBUG: Sending>>> stty sane<<<
2016-10-02 09:52:48,287 DEBUG: Expecting>>>root#yVt1PHtT> <<<
 stty sane
 stty sane
incoming
 stty sane

20737474792073616e650d0a
incomingdone
root#yVt1PHtT> incoming
root#yVt1PHtT> 
726f6f742379567431504874543e20
incomingdone
2016-10-02 09:52:48,290 DEBUG: Output (squashed): root#yVt1PHtT>  [...]
2016-10-02 09:52:48,290 DEBUG: shutit_pexpect_child.before (hex)>>>20737474792073616e650d0a<<<
2016-10-02 09:52:48,290 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f742379567431504874543e20<<<
2016-10-02 09:52:48,290 DEBUG: shutit_pexpect_child.buffer(hex)>>><<<
2016-10-02 09:52:48,290 DEBUG: shutit_pexpect_child.before>>> stty sane
<<<
2016-10-02 09:52:48,291 DEBUG: shutit_pexpect_child.after>>>root#yVt1PHtT> <<<
2016-10-02 09:52:48,291 DEBUG: shutit_pexpect_child.buffer>>><<<
2016-10-02 09:52:48,291 DEBUG: Sending in session: target_child
2016-10-02 09:52:48,291 DEBUG: ================================================================================
2016-10-02 09:52:48,291 DEBUG: Sending>>> export HISTCONTROL=$HISTCONTROL:ignoredups:ignorespace<<<
2016-10-02 09:52:48,291 DEBUG: Expecting>>>root#yVt1PHtT> <<<
 export HISTCONTROL=$HISTCONTROL:ignoredups:ignorespace
 export HISTCONTROL=$HISTCONTROL:ignoredups:ignorespace
root#yVt1PHtT> incoming
 export HISTCONTROL=$HISTCONTROL:ignoredups:ignorespace
root#yVt1PHtT> 
206578706f72742048495354434f4e54524f4c3d2448495354434f4e54524f4c3a69676e6f7265647570733a69676e6f726573706163650d0a726f6f742379567431504874543e20
incomingdone
2016-10-02 09:52:48,308 DEBUG: Output (squashed): root#yVt1PHtT>  [...]
2016-10-02 09:52:48,308 DEBUG: shutit_pexpect_child.before (hex)>>>206578706f72742048495354434f4e54524f4c3d2448495354434f4e54524f4c3a69676e6f7265647570733a69676e6f726573706163650d0a<<<
2016-10-02 09:52:48,308 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f742379567431504874543e20<<<
2016-10-02 09:52:48,308 DEBUG: shutit_pexpect_child.buffer(hex)>>><<<
2016-10-02 09:52:48,308 DEBUG: shutit_pexpect_child.before>>> export HISTCONTROL=$HISTCONTROL:ignoredups:ignorespace
<<<
2016-10-02 09:52:48,308 DEBUG: shutit_pexpect_child.after>>>root#yVt1PHtT> <<<
2016-10-02 09:52:48,308 DEBUG: shutit_pexpect_child.buffer>>><<<
2016-10-02 09:52:48,308 DEBUG: Expecting: root#yVt1PHtT> 
incoming
 echo EXIT_CODE:$?
EXIT_CODE:0
root#yVt1PHtT> 
206563686f20455849545f434f44453a243f0d0a455849545f434f44453a300d0a726f6f742379567431504874543e20
incomingdone
2016-10-02 09:52:48,312 DEBUG: Retrieving output from command:  test -d /tmp/shutit_imiell/Ians-Air.home_imiell_1475398343.93.927499/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN
2016-10-02 09:52:48,312 DEBUG: Sending in session: target_child
2016-10-02 09:52:48,312 DEBUG: ================================================================================
2016-10-02 09:52:48,312 DEBUG: Sending>>> test -d /tmp/shutit_imiell/Ians-Air.home_imiell_1475398343.93.927499/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN<<<
2016-10-02 09:52:48,312 DEBUG: Expecting>>>root#yVt1PHtT> <<<
 test -d /tmp/shutit_imiell/Ians-Air.home_imiell_1475398343.93.927499/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN
7499/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN43.93.92 
FILNEXIST-FILFIN
root#yVt1PHtT> incoming
7499/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN43.93.92 
FILNEXIST-FILFIN
root#yVt1PHtT> 
0d1b5b4b726f6f742379567431504874543e202074657374202d64202f746d702f7368757469745f696d69656c6c2f49616e732d4169722e686f6d655f696d69656c6c5f313437353339383334332e39332e3932200d373439392f656e7669726f6e6d656e745f6964202626206563686f2046494c45584953542d222246494c46494e207c7c206563686f2046494c4e45584953542d222246494c46494e0d0a46494c4e45584953542d46494c46494e0d0a726f6f742379567431504874543e20
incomingdone
2016-10-02 09:52:48,317 DEBUG: Output (squashed): root#yVt1PHtT>  [...]
2016-10-02 09:52:48,317 DEBUG: shutit_pexpect_child.before (hex)>>>0d1b5b4b<<<
2016-10-02 09:52:48,317 DEBUG: shutit_pexpect_child.after (hex)>>>726f6f742379567431504874543e20<<<
2016-10-02 09:52:48,317 DEBUG: shutit_pexpect_child.buffer(hex)>>>2074657374202d64202f746d702f7368757469745f696d69656c6c2f49616e732d4169722e686f6d655f696d69656c6c5f313437353339383334332e39332e3932200d373439392f656e7669726f6e6d656e745f6964202626206563686f2046494c45584953542d222246494c46494e207c7c206563686f2046494c4e45584953542d222246494c46494e0d0a46494c4e45584953542d46494c46494e0d0a726f6f742379567431504874543e20<<<
<<<
2016-10-02 09:52:48,317 DEBUG: shutit_pexpect_child.after>>>root#yVt1PHtT> <<<
7499/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFINmp/shutit_imiell/Ians-Air.home_imiell_1475398343.93.92 
FILNEXIST-FILFIN
root#yVt1PHtT> <<<
'before>>>>:\r\x1b[K<<<< after:>>>>root#yVt1PHtT> <<<<'
2016-10-02 09:52:48,318 CRITICAL: Did not see FIL(N)?EXIST in output:

2016-10-02 09:52:48,318 CRITICAL: Error seen, exiting with status 1
2016-10-02 09:52:48,318 DEBUG: Exiting with error code: 1
2016-10-02 09:52:48,318 DEBUG: Resetting terminal
ianmiell commented 7 years ago

0d's are in the 'before' which is messing things up. I need to replace all 0ds in string before which are not in a 0d0a pair. There may be different contexts we're seeing problems in.

ianmiell commented 7 years ago

testing in testing branch; will merge when ok

ianmiell commented 7 years ago

pexpect doesn't even send it through

2016-10-02 14:29:20,082 DEBUG: ================================================================================
2016-10-02 14:29:20,082 DEBUG: Sending>>> test -d /tmp/shutit_imiell/Ians-Air.home_imiell_1475414907.89.892829/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN<<<
2016-10-02 14:29:20,082 DEBUG: Expecting>>>root#uYam8458> <<<
 test -d /tmp/shutit_imiell/Ians-Air.home_imiell_1475414907.89.892829/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN
root#uYam8458> incoming
root#uYam8458> 
0d1b5b4b726f6f74237559616d383435383e20
incomingdone
2016-10-02 14:29:20,083 DEBUG: Output (squashed): root#uYam8458>  [...]
2016-10-02 14:29:20,084 DEBUG: shutit_pexpect_child.buffer(hex)>>>

<<<
2016-10-02 14:29:20,084 DEBUG: shutit_pexpect_child.buffer>>>

<<<
2016-10-02 14:29:20,084 DEBUG: shutit_pexpect_child.before (hex)>>>
1b5b4b
<<<
2016-10-02 14:29:20,084 DEBUG: shutit_pexpect_child.before>>>

<<<
2016-10-02 14:29:20,084 DEBUG: shutit_pexpect_child.after (hex)>>>
726f6f74237559616d383435383e20
<<<
2016-10-02 14:29:20,084 DEBUG: shutit_pexpect_child.after>>>
root#uYam8458> 
<<<
HERE

HERE
'before>>>>:\x1b[K<<<< after:>>>>root#uYam8458> <<<<'
2016-10-02 14:29:20,084 CRITICAL: Did not see FIL(N)?EXIST in output:

2016-10-02 14:29:20,085 CRITICAL: Error seen, exiting with status 1
2016-10-02 14:29:20,085 DEBUG: Exiting with error code: 1
2016-10-02 14:29:20,085 DEBUG: Resetting terminal

is it time to consider taking over pexpect?

ianmiell commented 7 years ago

Some improvements made, but def a problem with pexpect persists:

2016-10-02 18:33:23,434 DEBUG: ================================================================================
2016-10-02 18:33:23,434 DEBUG: Sending>>> export HISTCONTROL=$HISTCONTROL:ignoredups:ignorespace<<<
2016-10-02 18:33:23,434 DEBUG: Expecting>>>root#VGioKtb9> <<<
 export HISTCONTROL=$HISTCONTROL:ignoredups:ignorespace
 export HISTCONTROL=$HISTCONTROL:ignoredups:ignorespace
root#VGioKtb9> 2016-10-02 18:33:23,438 DEBUG: Output (squashed): root#VGioKtb9>  [...]
2016-10-02 18:33:23,438 DEBUG: shutit_pexpect_child.buffer(hex)>>>

<<<
2016-10-02 18:33:23,438 DEBUG: shutit_pexpect_child.buffer>>>

<<<
2016-10-02 18:33:23,438 DEBUG: shutit_pexpect_child.before (hex)>>>
206578706f72742048495354434f4e54524f4c3d2448495354434f4e54524f4c3a69676e6f7265647570733a69676e6f726573706163650d0a
<<<
2016-10-02 18:33:23,438 DEBUG: shutit_pexpect_child.before>>>
 export HISTCONTROL=$HISTCONTROL:ignoredups:ignorespace

<<<
2016-10-02 18:33:23,438 DEBUG: shutit_pexpect_child.after (hex)>>>
726f6f74235647696f4b7462393e20
<<<
2016-10-02 18:33:23,438 DEBUG: shutit_pexpect_child.after>>>
root#VGioKtb9> 
<<<
2016-10-02 18:33:23,439 DEBUG: Expecting: root#VGioKtb9> 
2016-10-02 18:33:23,443 DEBUG: Retrieving output from command:  test -d /tmp/shutit_imiell/Ians-Air.home_imiell_1475429590.57.565074/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN
2016-10-02 18:33:23,443 DEBUG: Sending in session: target_child
2016-10-02 18:33:23,443 DEBUG: ================================================================================
2016-10-02 18:33:23,443 DEBUG: Sending>>> test -d /tmp/shutit_imiell/Ians-Air.home_imiell_1475429590.57.565074/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN<<<
2016-10-02 18:33:23,444 DEBUG: Expecting>>>root#VGioKtb9> <<<
 test -d /tmp/shutit_imiell/Ians-Air.home_imiell_1475429590.57.565074/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN
5074/environment_id && echo FILEXIST-""FILFIN || echo FILNEXIST-""FILFIN90.57.56 
FILNEXIST-FILFIN
root#VGioKtb9> 2016-10-02 18:33:23,446 DEBUG: Output (squashed): root#VGioKtb9>  [...]
2016-10-02 18:33:23,446 DEBUG: shutit_pexpect_child.buffer(hex)>>>

<<<
2016-10-02 18:33:23,446 DEBUG: shutit_pexpect_child.buffer>>>

<<<
2016-10-02 18:33:23,447 DEBUG: shutit_pexpect_child.before (hex)>>>
0d1b5b4b
<<<
2016-10-02 18:33:23,447 DEBUG: shutit_pexpect_child.before>>>

<<<
2016-10-02 18:33:23,447 DEBUG: shutit_pexpect_child.after (hex)>>>
726f6f74235647696f4b7462393e20
<<<
2016-10-02 18:33:23,447 DEBUG: shutit_pexpect_child.after>>>
root#VGioKtb9> 
<<<
'before>>>>:\r\x1b[K<<<< after:>>>>root#VGioKtb9> <<<<'
2016-10-02 18:33:23,447 CRITICAL: Did not see FIL(N)?EXIST in output:

2016-10-02 18:33:23,447 CRITICAL: Error seen, exiting with status 1
2016-10-02 18:33:23,447 DEBUG: Exiting with error code: 1
2016-10-02 18:33:23,447 DEBUG: Resetting terminal
ianmiell commented 7 years ago

There are numerous issues here, which boil down to:

the reported output cannot be trusted.

ianmiell commented 7 years ago

Next idea is simply to leverage the retry functionality. If anything appears amiss, eg:

then retry the send.

ianmiell commented 7 years ago

If I stick a big sleep in before bash builtins (eg command, test) then the output is stable.

ianmiell commented 7 years ago

delaybeforesend should be as per default.

mjudeikis commented 7 years ago

congradz :+1: