Not all messages from a DS are logged when launched from Astor

[mrosanes]

Not all messages from a DS are logged on log file when the DS is launched from Astor

Hi,

I have a DS that is executing a command on another machine thanks to ssh and subprocess.Popen. I am logging the errors on a .log file thanks to Tango logger.

When the DS is executed from the terminal the whole error log is correctly stored on a log file.
However when the DS is launched from astor, for some reason, only a small part of the error log is stored; not all messages are stored in the log file.

It would be possible to see the whole error log when launching the DS from astor as well?

I have previously created this issue in logviewer issues, but it is not related to logviewer, as the log file is already affected.
For more details about this issue, please, follow this link:
tango-controls/LogViewer#2

[bourtemb]

Hi @mrosanes,
I guess the origin of your problem comes from environment variables which are different when you launch your DS from a terminal and when the Starter launches it.
Astor does not start your device server. It's the Starter device server which does it for you and the DS will be started with the same environment as your Starter device server.
What I suspect in your case is that when the Starter is starting your device server, it is using Python3 instead of Python 2.x when you start your DS from a terminal.
If this is the case, you could fix your Starter environment so that it uses python 2.x instead of python3.

There has been a recent fix in PyTango to fix exceptions propagation when using Python3, This might be linked:
tango-controls/pytango#215
tango-controls/pytango#225

Hoping this helps,
Reynald

[mrosanes]

Hi Reynald,

As you pointed, it seems that the problem is coming from the environment variables. If we launch the Starter from a terminal, all logs are reported correctly.

In our case it is not coming from Python2-Python3 difference because we are still not have Python3 in this host, but we will follow in our research. Many thanks for the hint.

[mrosanes]

Thanks again Reynald, as we pointed out in the last message, if the Starter is launched from a terminal, all logs are reported correctly. This is not the case if the Starter is automatically executed by restarting the host.

Would you have an idea of which environment variables could be affecting the Tango logging of messages?

[bourtemb]

When looking at the log files you posted in tango-controls/LogViewer#2, my first guess was really that the Starter is getting another version of python when started with the host.
So, I would look at variables like PATH, PYTHONPATH, LD_LIBRARY_PATH.

[bourtemb]

@mrosanes , any update on this issue?

[mrosanes]

Hi @bourtemb; we did not find which combination of variables is giving place to this behavior of incomplete logs.

For the moment we applied a workaround by launching the DS using screen command:
screen -dm -S TXMAutoPreprocessing-$1 python /homelocal/sicilia/lib/python/site-packages/TXMAutoPreprocessing/TXMAutoPreprocessing.py $*
(instead of launching it from the entry point created with the setup.py file).

If the DS is executed with screen, the complete logs are available, and can be visualized in logviewer.

[mrosanes]

Hi @bourtemb,

I have simplified the DS to reproduce the problem (in a Debian8). I attach the python 'dslogs' DS:
dslogs.txt
It only contains a single command, named 'run_command'. This command performs an ssh to a machine, and executes a division by 0.

--
If I create a launcher as:

#!/bin/bash
python /homelocal/sicilia/ds/dslogs.py $*

And I execute the DS from the terminal:
./dslogs dslog

The complete logs are reported:
testdslog_ct_logs_from_terminal.log

--

If I execute the same DS from Astor; some logs are missing:
testdslog_ct_logs_astor.log

[bourtemb]

And I guess if the Starter is running in a terminal, all the logs are reported? As you wrote before.

[mrosanes]

In fact no, in this case I launched the Starter from a terminal to perform the tests in the debian8 machine:

/usr/lib/tango/Starter ct64debian8

[bourtemb]

Hi @mrosanes
I could reproduce your problem thanks to the example you provided.

I could make it work by invoking ssh with -tt option instead of -t and also by changing the ssh config so it does not ask for a password when it connects to localhost via the Starter.

The best way to debug this problem was by adding lines logging the content of result and errors variables.

With -t option instead of -tt, when the DS was started with the Starter, I could see the following error:

Pseudo-terminal will not be allocated because stdin is not a terminal.

This post helped me to figure out the -tt option: https://stackoverflow.com/questions/7114990/pseudo-terminal-will-not-be-allocated-because-stdin-is-not-a-terminal

Then, before I got the ssh config right, it was displaying permission denied errors.

You can refer to this post on stackoverflow to get an idea on how to configure ssh correctly:
https://stackoverflow.com/questions/3466626/how-to-permanently-add-a-private-key-with-ssh-add-on-ubuntu

In my case, editing .ssh/config (with correct file permissions) was enough.

Hoping this helps.
Reynald

[mrosanes]

Great!
With the option -tt I would say that the whole error log is reported.

For the ssh configuration I was putting my host in the authorized_keys; it seems to work as well.

Many thanks,
marc