53

Pretty new to Jenkins and I have simple yet annoying problem. When I run job (Build) on Jenkins I am triggering ruby command to execute my test script.

Problem is Jenkins is not displaying output in real time from console. Here is trigger log.

Building in workspace /var/lib/jenkins/workspace/foo_bar
No emails were triggered.
[foo_bar] $ /bin/sh -xe /tmp/hudson4042436272524123595.sh
+ ruby /var/lib/jenkins/test-script.rb

Basically it hangs on this output until build is complete than it just shows full output. Funny thing is this is not consistent behavior, sometimes it works as it should. But most of the time there is no real time console output.

Jenkins version: 1.461

Haris Krajina
  • 14,824
  • 12
  • 64
  • 81
  • 1
    How powerful is the server you are running on and how long does this script take to execute? This sounds like delay due to an overloaded server to me. I have seen similar symptoms when my Jenkins master is running at full capacity. – CIGuy Jul 24 '12 at 15:22
  • Thank you for interests, that actually makes sense. In this case we are talking about EC2 instance `small`, http://aws.amazon.com/ec2/instance-types/ but it is only process running. Could it be you need more than that? – Haris Krajina Sep 17 '12 at 08:03
  • It depends how many jobs are running, but yes, I would expect to see delay if you have more than a few jobs running on a small instance simultaneously. – CIGuy Sep 17 '12 at 15:21
  • 1
    I have a similar problem, however, the machine is over spec'd and under utilised. Also running the python script outside of jenkins works in realtime as expected.The job calls a python script which tails the logfile of another process. The logfile updates in realtime, the jenkins output is dumped in blocks as if it's waiting to fill a buffer. – Craig Oct 19 '12 at 11:33
  • Hi Craig, you were right buffering output was a problem. Using `STDOUT.sync=true` solved the problem. – Haris Krajina Oct 19 '12 at 12:12
  • I have the same challenge with maven. All the output of a maven call is only flushed, once the call terminated. Does anyone else have this? – Marty Feb 19 '19 at 13:13

9 Answers9

72

To clarify some of the answers.

  • ruby or python or any sensible scripting language will buffer the output; this is in order to minimize the IO; writing to disk is slow, writing to a console is slow...
  • usually the data gets flush()'ed automatically after you have enough data in the buffer with special handling for newlines. e.g. writing a string without newline then sleep() would not write anything until after the sleep() is complete (I'm only using sleep as an example, feel free to substitute with any other expensive system call).

e.g. this would wait 8 seconds, print one line, wait 5 more seconds, print a second line.

from time import sleep

def test():
    print "ok",
    time.sleep(3)
    print "now",
    time.sleep(5)
    print "done"
    time.sleep(5)
    print "again"

test()
  • for ruby, STDOUT.sync = true, turns the autoflush on; all writes to STDOUT are followed by flush(). This would solve your problem but result in more IO.

    STDOUT.sync = true
    
  • for python, you can use python -u or the environment variable PYTHONUNBUFFERED to make stdin/stdout/stout not buffered, but there are other solutions that do not change stdin or stderr

    export PYTHONUNBUFFERED=1
    
  • for perl, you have autoflush

    autoflush STDOUT 1;
    
Community
  • 1
  • 1
dnozay
  • 23,846
  • 6
  • 82
  • 104
16

Make sure your script is flushing its stdout and stderr. In my case I had a buffering issue similar to what you describe but I was using python. The following python code fixed it for me:

import sys
sys.stdout.flush()

I'm not a Ruby coder, but Google reveals the following:

$stdout.flush
Jens
  • 69,818
  • 15
  • 125
  • 179
Craig
  • 991
  • 1
  • 13
  • 28
  • Hi, Craig thank you for the answer `STDOUT.flush` or `$stdout.flush` will work. Problem is that you will need to put many of these commands trough out the script to flush buffer when needed. I will post solution that basically covers synced buffer flush to output. – Haris Krajina Oct 19 '12 at 12:06
  • thanks, it really solved my problem, since it works well under shell without flush, therefore I didn't think about it. – Larry Cai May 18 '13 at 14:46
9

It seems to me that python -u works as well.

E.g. In batch command

python -u foo.py
Alan Wang
  • 465
  • 5
  • 5
4

Easiest solution here is to turn on syncing buffer to output. Something that @Craig wrote about in his answer but one line solution that will cover whole script, and not require you to flush buffer many times.

Just write

STDOUT.sync = true

Logic behind is simple, to avoid using IO operations many times output is buffered. To disable this use

STDOUT.sync = false

This is Ruby solution ofc.

Haris Krajina
  • 14,824
  • 12
  • 64
  • 81
3

Each of the other answers is specific to one program or another, but I found a more general solution here:

https://unix.stackexchange.com/a/25378

You can use stdbuf to alter the buffering behavior of any program.

In my case, I was piping output from a shell script through tee and grep to split lines into either the console or a file based on content. The console was hanging as described by OP. This solved it:

./slowly_parse.py login.csv |tee >(grep -v LOG: > out.csv) | stdbuf -oL -eL grep LOG:

Eventually I discovered I could just pass --line-buffered to grep for the same result:

./slowly_parse.py login.csv |tee >(grep -v LOG: > out.csv) | grep --line-buffered LOG:
Community
  • 1
  • 1
dokkaebi
  • 9,004
  • 3
  • 42
  • 60
3

The other answers are correct in saying that you need to ensure standard output is not buffered.

The other thing to be aware of is that Jenkins itself does line by line buffering. If you have a slow-running process that emits single characters (for example, an nunit test suite summary that prints a . for a successful test and an E for an error) you will not see anything until the end of line.

[True for my Jenkins 1.572 running on a Windows box.]

yoyo
  • 8,310
  • 4
  • 56
  • 50
1

For some commands, including tee a the best choice for unbuffering is a program called unbuffer from expect package.

Usage example:

instead of

somecommand | tee /some/path

do

somecommand | unbuffer -p tee /some/path

Sources and more info:

Greg Dubicki
  • 5,983
  • 3
  • 55
  • 68
0

The Operating-System is buffering output-data by nature, to save CPU, and so does Jenkins.

Looks like you are using a shell-command to run your Ruby script -
I suggest running your Ruby script directly via the dedicated plugin:

Jenkins Ruby Plugin

(may need to install it)

Gonen
  • 4,005
  • 1
  • 31
  • 39
  • I will try this, it will take some time. Thanks. – Haris Krajina Jul 25 '12 at 08:19
  • Hello, this is not working :( Tried it same results. Also as solution is not very practical since ruby code is saved in Jenkins job, version-ing is much harder that way. – Haris Krajina Jul 26 '12 at 09:10
  • 1
    I agree about the "non-source-control" nature of that solution - it is better to manage any script outside of Jenkins, and just call it from the job. (true for shell/batch blocks in Jenkins as well) – Gonen Jul 26 '12 at 09:48
0

Python buffered its output traces and print it at the end of script to minimize writing on console as writing to console is slow.

You can use following command after your traces. It will flush all traces to console, which are queued before that command.

sys.stdout.flush()