[ts-gen] redirecting shim output to python script

[Bill Pippin]

Mike,

Glad to hear from you.  About your python code, I don't routinely
program in python, since I prefer Ruby, so I might miss some fine
details in your code.  So, others with more facility in python
should feel free to contribute as well.

You ask about the "once" option:

> What does the 'once' statement -- copied from /exs/kill.rb -- do?

The once option ensures that in risk mode, the shim tries to connect
to the upstream IB tws exactly once; without it, a risk mode shim
can try to connect up to eight times, incrementing the client id each
time.

Since the downstream needs to know the client id in order to refer
to orders in future sessions, some users will want to prevent such
retries, and the "once" option allows you to do this, though at the
cost of possibly having the shim terminate with an
ib_tws_handshake_failure exception, number 523, with text message:
"the IB tws server handshake failed".

About your popen call:
 
> ... is the following call correct ...

    0. > self.shimProcess = subprocess.Popen(
    1. > '/usr/local/shim --risk cout save once',
    2. > bufsize=0,
    3. > shell=True,
    4. > stdin=subprocess.PIPE,
    5. > stdout=subprocess.PIPE,
    6. > stderr=subprocess.STDOUT)

In the text above, I've added the line numbers as references.  As for
line [0], you definitely want a popen; I use a similar approach with
Ruby, and this approach is applicable for other scripting languages as
well.

    2. > bufsize=0,
    3. > shell=True,

I would suggest you ultimately change to bufsize=1, to get line
buffered input, which is, after all, the way the shim is sending
it to your script, although you probably want to stick with
unbuffered IO as long as you are debugging.  The use of shell=true
makes sense to me as long as your're working on Unix, though
python programmers may want to chime in here.

> ... so that the shim input/output is logged in a file?

    1. > '/usr/local/shim --risk cout save once',

Do you want the shim output to be logged to a file, as well as
over a pipe?  If so, you should say so, by including the file
option.  The file and cout options are old, and so are covered
in the manual, in the help, and with the file option used as well
in both risk.rb and test.rb.

With no log option, neither file, nor cout, nor logd, the shim
insists on opening a log file anyway.  Otherwise, if you use any
non-empty subset of these three options, the shim takes you at your
word, and logs to just the ones you ask for.  If you want log
output to be directed only to the stdout, then the "cout" option
is just what you need.

    4. > stdin=subprocess.PIPE,
    5. > stdout=subprocess.PIPE,
    6. > stderr=subprocess.STDOUT)

Once given "cout", and ignoring the question of a log file for now,
then if the python plumbing in [4-6] is what you want, and lines [4-5]
give you a full-duplex pipe, you need to get ahold of your ends of
the pipe file descriptors, and be writing to, and reading from,
subprocess.PIPE[1] and subprocess.PIPE[0], or whatever the correct
python syntax for those endpoints is. 

Consider similar code in ruby, adapted from exs/loop.rb:

    path = "/home/pippin/tsi"
    prog = "shim --data file cout save"
    exec = "#{path}/#{prog}"

    shim = IO.popen(exec, "w+");
    shim.puts                                  "wait  4;\n";
    shim.puts "select acct;	                wait  0;\n"
    shim.puts "select next;	                wait  1;\n"
    shim.puts "cancel acct;	                wait  0;\n"
    shim.puts "select next;	                wait  0;\n"
    shim.puts "select open;	                wait  1;\n"
    shim.puts "select time;"
    shim.puts "select bars STK:SMART:AMAT:USD;\nwait 20;\n"
    shim.puts "cancel bars STK:SMART:AMAT:USD;\nwait 10;\n"
    shim.puts "exit;\n"
    shim.close_write
    while line = shim.gets do
#     puts line			# can trace shim output here
    end

In the code above, shim is a full-duplex file handle returned
by IO.popen.  The waits are not necessary, but are for user
convenience in debugging; I'm reading the stderr, and using a
shim monitor via tail(1) processing as this runs, about which
more below, and it's easier to assign credit/blame if the script
is stepping through its commands to the shim.

Its essential that puts come before gets.  It's very easy here
to write code that deadlocks, and you may want to consider using
select, in Ruby terms IO.select(), to either time out your read
on the pipe stdin, or multiplex your reads on the pipe stdin and
the subprocess stderr, or both.

Buffering may also give you headaches; just because you've put to
the pipe doesn't mean the text has been sent on to the child shim.
Presumably you already know this, since you had bufsize=0 in your
call.  In the above Ruby script, I have to use shim.close_write
or some other command that causes a flush of the write channel in
order to prevent deadlock.

> I am having a little difficulty in redirecting the shim output to
> a python subprocess.  From print statements, I can see that the
> shim output is not making it into the python script.

Yes, but why?  Because the python plumbing is set wrong, or your
script does not include code to read the PIPE[0] fd, or there is
no input on that descriptor, or your script has deadlocked?

You should be able to verify to your own satisfaction that a
shim process with the cout option produces output --- with tick
subscriptions, copious output --- on the stdout.  Once given
such a test, then the problem *must* lie in your script.

In that case the questions I raise above are of interest, and
in particular the last two raise the issue of deadlock, always
a likely cause of problems when using full-duplex pipes.

Ultimately deadlock --- and again, deadlock is the most likely
reason not to see input --- is a script debugging problem, and
although you are free to post to this list with such questions,
please understand that I personally will not be free to debug
your python scripts for you.

You may want to run the pure shim regression scripts in exs, that
is the four character file names not having a file extension, and
(as noted in exs/Readme) validated via the script exs/prog.sh.

You also probably want to have a separate, tail'd konsole open
while you run these scripts, using, say,

    bin/tail.window log/ShimText 2

This should allow you to know what exactly the shim is writing.
Once you begin debugging your own scripts, you should provide
both the file and cout options to the shim subprocess, and use
the bin/tail.window script to monitor the shim.  That way, when
you run into deadlock, you have some hope of guessing where
and when it occurred.

In particular, this shim-monitor approach will help you see that
such deadlocks aren't in the shim.  It just keeps on ticking; if
it has connected to a working IB tws, and gets valid command
input, the related requests go upstream, and the resulting
messages come flooding back.

Thanks,

Bill