Blog Posts

Make evrything louder! Stream processing in Ruby with ARGF

If you’ve ever used a terminal before (and surely you have, since you’ve taken interest in this blog post), it’s more than likely that you’ve had an opportunity of working with streams. Streams were implemented in unix system in 1973 by Ken Thompson, not long after Douglas McIlroy righlty observed, that one program’s output is often the input of another. The usefulness of streams comes to light everytime we use ls | grep part_of_name_i_remember. Making our scripts capable of processing data this way isn’t that difficult. And so, let us scream out our logs!

# in log.txt
Lorem ipsum dolor sit amet, consectetur adipiscing elit.
Nullam pretium consectetur pellentesque.
# in screemer.rb
#!/usr/bin/env ruby
print ARGF.read.upcase
tail log.txt | screamer.rb
LOREM IPSUM DOLOR SIT AMET, CONSECTETUR ADIPISCING ELIT.
NULLAM PRETIUM CONSECTETUR PELLENTESQUE.

Hmm…not bad! ARGF is a stream that’s capable of processing files given as arguments to the script. Each of them is stored in the ARGV array. However, if the array is empty, ARGF will read from the input stream STDIN. Truth be told, reading files from our drive is not exactly what we had in mind. Let’s try and scream out data that’s being currently logged by the rails console. To do that, we will use tail program with the --follow flag, which on a ongoing basis reads data that’s currently being written to the file.

tail -f log/development.log | screamer.rb

Aaaand nothing happens. It’s because the script is waiting for the end of the stream. In this case we used tail -f and pipe, so the output stream will never end. Only when we end tail with something like killall tail, we will see the buffered data. Let’s fix our script then.

# in screamer.rb
#!/usr/bin/env ruby
ARGF.each_line do |line|
  print line.upcase
end
tail -f log/development.log | screemer
# example logs ↓
STARTED GET "/ASSETS/ICONS/BACKON.PNG" FOR 127.0.0.1 AT 2016-10-04 00:42:29 +0200
STARTED GET "/ASSETS/ICONS/NEXTON.PNG" FOR 127.0.0.1 AT 2016-10-04 00:42:29 +0200
STARTED GET "/ASSETS/ICONS/LASTON.PNG" FOR 127.0.0.1 AT 2016-10-04 00:42:29 +0200
STARTED GET "/ASSETS/ARROW_DOWN.PNG" FOR 127.0.0.1 AT 2016-10-04 00:42:29 +0200

Now, ARGF reads the input stream in newline-separated batches and displays our data as it comes. We’re almost at the finish line. What’s left to do is to make sure our data is sent directly as an output. By default, it’s being buffered until our program ends. If we chose to use that script in the middle of tail -f log/development.log | screamer | grep some_string, we would see nothing. There are two ways of changing that:

  • setting output stream synchronization: STDOUT.sync, so the data is not buffered
  • emptying buffer manually STDOUT.flush

We’ll go with the first method. On top of that, we’re gonna add some extra sugar, and implement some code to catch the ‘broken pipe’ error, because programming veterans don’t treat scripts with kid gloves. ctrl-c rox!

# in screamer.rb
#!/usr/bin/env ruby
begin
  STDOUT.sync = true
  ARGF.each_line do |line|
    print line.upcase
  end
rescue Errno::EPIPE
  exit 0 # exit code 0 in most shells means that everything is ok
end

Everything’s nice and fine, but as far as functionalities go, changing font size inside logs is not very sophisticated and sought out one. Let’s write something more interesting then. How about colorful logs? Or audio notifications in case of an error? Yes, I’m aware that in the development process it is kinda hard to miss an error, but wouldn’t work become more fun if after every mistake you were vocally reprimended by the system itself? For the colored output we’ll use the simple colorize gem, which expands the ‘String’ with additional methods. If our terminal (or emulator thereof) supports ANSI escape sequences, we can color our world in a very simple way. For example, like this:

'VeryAnnoyingError'.red

To play sounds we can use the aplay application, which by default is available on most of the systems and does well with wav files. We can also record our own sample with arecord my_wav_file_name. If we want to use mp3 files we can use mpg123 program, which is available in repositories all over the web.

require 'colorize'

begin
  ARGF.each_line do |line|
    print case line
    # we use regexp to react to specyfic line
    when /Started.*?"\/(?!assets)/ then line.light_blue
    when /Processing/ then line.green
    when /Render/ then line.light_cyan
    when /Error/
        Process.detach(
          Process.spawn("aplay #{File.expand_path('~/error_sound.wav')}", err: '/dev/null', out: '/dev/null')
        )
      line.red
    end
  end
rescue Errno::EPIPE
  exit 0
end

This code contains a line that requires some deeper explanation:

Process.detach(
  Process.spawn("aplay #{File.expand_path('~/error_sound.wav')}", err: '/dev/null', out: '/dev/null')
)

With the use of Process.spawn, we create a child process which runs the shell command we issued. On top of that, in the options hash we make it redirect the output and error streams to the system’s black hole - /dev/null. Thanks to that that aplay doesn’t bother us with unnecessary messages. The spawn methods doesn’t wait for any return. It immediately returns pid of the process, which we send to the detach method so It protects us from the emergence of zombie processes. I strongly advise you to dig into documentation and find out how exactly this method works. However, if we want to use a short sound sample and don’t care much about all this asynchronous mumbo-jumbo, far better solution would be to run this command with a simple ‘system’ method. This is how the final effect looks like:

Now, that you’ve got a solid grasp on the basics, I encourage you to go on and experiment on your own!