Reading last error message in log file

Question

In Python 2.7 I have the following code inside certain loop

file = open("log.txt", 'a+')
last_position = file.tell()
subprocess.Popen(["os_command_producing_error"], stderr = file)
file.seek(last_position)
error = file.read()
print(error) # example of some action with the error

The intention is that the error that was just given by stderr gets, say printed, while file is keeping the whole record.

I am a beginner in Python and I am not clear what happens in the stderr = file.

My problem is that error keeps being empty, even though errors keep getting logged in the file.

Could someone explain why?

I have tried adding closing and opening the file again, or file.flush() right after the subprocess line. But still the same effect.

Edit: The code in the answer below makes sense to me and it seems to work for for the author of that post. For me (in Windows) it is not working. It gives an empty err and an empty file log.txt. If I run it line by line (e.g. debugging) it does work. How to understand and solve this problem?

Edit: I changed the Popen with call and now it works. I guess call waits for the subprocess to finish in order to continue with the script.

Perhaps you can flush the file first, before moving the file pointer. But I'd go with close and reopen. — , Sep 19 '15 at 05:46
@Evert I find a problem: when raise the error, then the program will exit. so we can't flush or close the file. — Remi Guan, Sep 19 '15 at 05:51
Sorry, that doesn't make sense. What error do you want to raise? What `try` statement (I don't see any)? If there is more context to it than the above, it might be good to show it. — , Sep 19 '15 at 06:18
Given your initial code, without a try-except clause, why didn't subprocess raise an exception in the first place why you tried to run that code? Because I think it should, but you claim your code made it through (with an non-existing command) to the end. Which makes me think that command was either successfully executed, or no attempt to execute was made by the underlying shell. In both cases, the log file would not be updated, and `error` would indeed be empty. — , Sep 19 '15 at 06:29
@Evert My code is inside a `try:` and inside a loop too. I didn't include them here. The OS command for sure writes to stderr and also to stdout. — Anna Taurogenireva, Sep 19 '15 at 06:33

score 1 · Accepted Answer · edited May 23 '17 at 11:51

error is empty because you are reading too soon before the process has a chance to write anything to the file. Popen() starts a new process; it does not wait for it to finish.

call() is equivalent to Popen().wait() that does wait for the child process to exit that is why you should see non-empty error in this case (if the subprocess does write anything to stderr).

#!/usr/bin/env python
import subprocess

with open("log.txt", 'a+') as file:
   subprocess.check_call(["os_command_producing_error"], stderr=file)
   error = file.read()
print(error)

You should be careful with mixing buffered (.read()) and unbuffered I/O (subprocess).

You don't need the external file here, to read the error:

#!/usr/bin/env python
import subprocess

error = subprocess.check_output(["os_command_producing_error"],
                                stderr=subprocess.STDOUT)
print(error)

It merges stderr and stdout and returns the output.

If you don't want to capture stdout then to get only stderr, you could use Popen.communicate():

#!/usr/bin/env python
import subprocess

p = subprocess.Popen(["os_command_producing_error"], stderr=subprocess.PIPE)
error = p.communicate()[1]
print(error)

You could both capture stderr and append it to a file:

#!/usr/bin/env python
import subprocess

error = bytearray()
p = subprocess.Popen(["os_command_producing_error"],
                     stderr=subprocess.PIPE, bufsize=1)
with p.stderr as pipe, open('log.txt', 'ab') as file:
    for line in iter(pipe.readline, b''):
        error += line
        file.write(line)
p.wait()
print(error)

See Python: read streaming input from subprocess.communicate().

Thank you. There are some commands there that I think I will not be able to use, like `check_output` or `with`. I have Python 3.. and 2.7 in my laptop, but I think I will need to run the script in some places with 2.4. — Anna Taurogenireva, Sep 20 '15 at 13:07
The third code snippet should work. I think I had tried that one at some point but got rid of it because I thought the command was supposed to communicate through `stdout` and I wasn't seeing the messages in `p.communicate()[0]`. If I knew I had only to change it to `p.communicate()[1]` ... — Anna Taurogenireva, Sep 20 '15 at 13:23
@MlazhinkaShungGronzalezLeWy: your question says *Python 2.7*. The code in my answer works without any changes on Python 2.7 and 3. It can be adapted to work on Python 2.4 (that also has `subprocess` module) e.g., here's [how to emulate `check_output()` on earlier Python versions](http://stackoverflow.com/a/2924457/4279). You should mention explicitly in your question what python versions you need to support. — jfs, Sep 20 '15 at 13:30

Remi Guan · Answer 2 · 2015-09-19T07:48:35.890

0

Try these following codes:

file = open("log.txt", 'a+')
sys.stderr = file
last_position = file.tell()
try:
    subprocess.call(["os_command_producing_error"])
except:
    file.close()
    err_file = open("log.txt", 'r')
    err_file.seek(last_position)
    err = err_file.read()
    print err
    err_file.close()

sys.stderr map the standard error message like sys.stdout(map standard output) and sys.stdin(map standard input).

And this will map the standard error to file. So all of the standard error will be write to the file log.txt.

edited Sep 19 '15 at 07:48

answered Sep 19 '15 at 05:36

Remi Guan

21,506
17
64
87

Now it is not writing anything in log.txt – Anna Taurogenireva Sep 19 '15 at 05:44
My Python is ``2.7.10``, and the code can work. Would you try to use `file = open("log.txt", 'w')` instead `file = open("log.txt", 'a+')`? – Remi Guan Sep 19 '15 at 05:49
Your code works. But the important part is to latter read that **last** error message from the file and do things with it. I have a `last_position = file.tell()` before the subprocess to know where we were in the file before the subprocess call. Then a `file.seek(last_position)` after it, and `err = file.read()` following. This is to get the last error message in `err`. – Anna Taurogenireva Sep 19 '15 at 06:10
Yes, just tried. `print err` doesn't print anything. – Anna Taurogenireva Sep 19 '15 at 06:21
Hum...maybe I should close the file and open it in `r` mode again. Let me edit my answer. – Remi Guan Sep 19 '15 at 06:22
You might consider different underlying OSes. Perhaps one OS let's subprocess throw an error before the underlying shell sends an error message. Seems unlikely, but unless you know the intrinsics of subprocess, I could potentially see that happen. – Sep 19 '15 at 06:27
@Evert Hum...I'm on Arch Linux. – Remi Guan Sep 19 '15 at 06:28
Inserting `file.close(); file = open("log.txt", 'r')` as the first two lines of the `except:` and empty `err` and empty file. – Anna Taurogenireva Sep 19 '15 at 06:28
Sorry. that still gives empty err and empty log.txt It is weird. – Anna Taurogenireva Sep 19 '15 at 06:37
Gosh, which system are you on? – Remi Guan Sep 19 '15 at 06:39
I am using Windows. Does it work properly in Linux? The code totally makes sense, except that I don't know what happens with stderr in the subprocess. – Anna Taurogenireva Sep 19 '15 at 06:41
Yeah, I'm on Arch Linux and the code work perfectly. I don't understand why doesn't the code work on windows. – Remi Guan Sep 19 '15 at 06:43
Ha! If I give it a `time.sleep(5)` it works. The solution might have to do with coercing somehow the OS to pass the stderr to the file. – Anna Taurogenireva Sep 19 '15 at 07:44
Great! I understand: because Linux will write the error message to file right now, but Windows will wait some time. And let me edit my answer :) – Remi Guan Sep 19 '15 at 07:48

Reading last error message in log file

2 Answers2