6

I'm writing a backup script I intend to execute in a cronjob every night.

The script sets sys.stdout and sys.stderr to an output file to keep a log of what happens.

To do the backup I use the following code

cmd = 'rsync -av --del --stats --filter "- .thumbnails/" ' + \ '--filter "- *~" --filter "- *.iso" --filter "- lost+found/" ' + \ '--filter "- .cache/" --filter "- tmp/" --filter "- *.mp3" ' + \ '--filter "- *.log" ' + srcDir + ' ' + dstDir print "Executing '"+cmd+"' ..." try: sys.stdout.flush() sys.stderr.flush() retcode = subprocess.call( cmd, stdin = sys.stdin, stdout = sys.stdout, stderr=sys.stderr, shell=False ) if retcode < 0: print >>sys.stderr, "Command was terminated by signal", -retcode elif retcode > 0: print >>sys.stderr, "Command returned code ", retcode except OSError, e: print >>sys.stderr, "Execution failed:", e

I add print statements before and after the subprocess call. The problem is that I get the output of the subprocess call before any output of my print instructions before the call. I added the flush() calls but it has no effect.

Why is this happening and how could I change this behaviour ?

Improve this question
6
  • 1
    How are you setting sys.stdout and sys.stderr? Commented Oct 31, 2009 at 17:10
  • 1
    It seems correct and shouldn't behave like that (and doesn't when I try), could you describe your environment (OS, shell from which you launch the script)? Commented Oct 31, 2009 at 17:32
  • Why don't you use existing tools such as rsnapshot (it also uses rsync). Commented Oct 31, 2009 at 20:02
  • First, the script above cannot work, because you have to provide call() with a list of arguments — not a string of space-separated arguments — if you are going to supply "shell=False". So call() should have complained "No such file or directory". Second, as RedGlyph says, the script both looks correct and works for us when we ourselves try it. Could you share with us more about the environment you are working in? On any system where Python handles I/O correctly, the script should work really well — you've written it to do the flushing correctly from what we can see from here! Commented Oct 31, 2009 at 22:46
  • @Sebastian: don't know of the existence of rsnapshot. Here I control what I do. I send the log file in a mail, etc. Commented Nov 1, 2009 at 12:49

3 Answers 3

Reset to default
3

I just found the solution here in a Stackoverflow answer.

Replace 

sys.stderr = sys.stdout = logFile = open( tmpLogFileName, 'a' )

with 

sys.stderr = sys.stdout = logFile = open( tmpLogFileName, 'a', 0 )

This tells python to not assign any output buffer to file.

Improve this answer
Sign up to request clarification or add additional context in comments.

3 Comments

But this is giving up too soon! :-) We want to help you figure out why flush() isn't working; if you just turn off the buffering, the real problem — whatever it was — won't get fixed. :-)
:] That's the solution. I'm not giving up. I think the real problem is inside flush. Investigating and solving this is beyond my competence and my needs.
Well, that was an interesting pitfall, glad you overcame it :-)
0

Have you tried putting the flush calls outside the try block?

Improve this answer

1 Comment

No because this should not should have no effect on the output behavior. It looks like the flush is not flushing in fact. Adding >>sys.stdout to the print "Executing" instruction doesn't change de the behavior.
0

Why are you printing to stderr? If the subprocess is writing to stdout while you are writing to stderr, that could explain the odd interleaving.

Improve this answer

3 Comments

I assume the call blocks until the called command ends. Otherwise I wouldn't be able to get the return code.
The call does block, as you say, so you can retrieve the return code. But that doesn't explain why you are printing to stderr. If you use the same file as the subcommand, perhaps the output would be properly interleaved.
I'm using the same file because I have the instruction 'sys.stdout = sys.stderr = logFile = open( "/tmp/backup.log", "a" )' at the start of the program. Beside specifying stdout=sys.stdout etc. sets the log file as stdout file for the called command. It works. It is just that flush() is not really writing the buffered data to disk.

Start asking to get answers

Find the answer to your question by asking.

Ask question

Explore related questions

See similar questions with these tags.