warning: syswrite for buffered IO

[japgolly]

Minor one here:

1. Create an appender that logs to stdout.
2. Run your awesome ruby app and mute stdout a la

ruby my_amazing_app.rb >/dev/null

1. You will see the following warning printed to stderr:

blah/logging-1.7.1/lib/logging/appenders/io.rb:72: warning: syswrite for buffered IO

Searched around then got bored :P Looks like something somewhere needs a :stream or :streaming option to be set to false.

[TwP]

Please take a look at the appenders.rb example. It demonstrates the built-in method for creating a STDOUT appender.

logger = Logging.logger['Example']
logger.add_appenders Logging.appenders.stdout

The built-in STDOUT appender properly sets the sync flag on the IO stream to avoid the syswrite warning. If you are in more of a do it yourself mood, you can set the sync flag on STDOUT yourself:

STDOUT.sync = true

And that should also take care of the warning.

[japgolly]

This seems to be a different problem. Tried to reproduce outside of my app: failed. (frustrating!) Instead, added this to logging/appenders/io.rb (so line #72 is me)

 70     def canonical_write( str )                                                                                           
 71       return self if @io.nil?                                                                                            
 72       STDERR.puts({name: name, sync: (@io.sync rescue nil), stdout: STDOUT == @io, io: @io.inspect}.inspect)                              
 73       @io.syswrite str                                                                                                   
 74       self                                                                                                               

and the output I get is this:

{:name=>"stdout", :sync=>true, :stdout=>true, :io=>"#<IO:<STDOUT>>"}
/home/golly/.rvm/gems/ruby-1.9.3-p125/gems/logging-1.7.1/lib/logging/appenders/io.rb:73: warning: syswrite for buffered IO

Have you seen this in any other scenarios? Or know of anything else that causes this?

[TwP]

This kind of problem arises when syswrite is mixed with other buffered output methods such as puts. There is a StackOverflow thread describing this problem. And the example below will produce the error as well.

File.open('tmp.txt', 'w') { |io|
  # io.sync = true
  io.syswrite io.sync
  io.syswrite "\n"

  io.puts "Sync is => #{io.sync}"

  io.syswrite "test line\n"
}

Un-commenting the io.sync = true line will remedy the problem.

[japgolly]

Got it. Sent pull request. https://github.com/TwP/logging/pull/33

[mixellent]

Found the same issue for logging-rails gem, I got:

gems/logging-1.6.2/lib/logging/appenders/io.rb:65: warning: syswrite for buffered IO

Is there a similar solution available for the logging-rails project?

[mixellent]

Ok I guess the logging-rails project has a dependency on the logging gem v1.6.1. Is there a newer version out for the logging gem which contains the above fix?

Also, does the logging-rails gem work in Heroku?

[TwP]

The Heroku question is a good one. I have not tried it, nor have I heard of anyone attempting such a thing.

It "should" work since it is just a gem dependency that inserts the Logging framework into Rails. Give it a go and report back here! We could add a section to the readme about Heroku compatibility.

And a new version of the logging-rails gem has been released that addresses the syswrite warnings. The version requirement for Logging is less restrictive allowing the newer gem versions to be used.

[mixellent]

So I guess I am the first one attempting it :) So far I was not able to print out my logs from logging-rails to the Heroku log file. I have just read however that by default Heroku's logger is set to Logger::INFO. So I will try it again by changing the log settings to DEBUG mode (heroku config:add LOG_LEVEL=DEBUG) since I am currently printing out all my logs in DEBUG mode.

Also, from Heroku's site: "anything written to standard out (stdout) or standard error (stderr) is captured into your logs. This means that you can log from anywhere in your application code with a simple output statement." I am not sure if this affects the log settings file used for your gem.

In case you are interested, Heroku shows their logging handling in the following link: https://devcenter.heroku.com/articles/logging.

I will continue testing the logging-rails gem on Heroku next week. Hopefully, with the above changes I will get it working. I will report back with my findings.

BTW, Thanks for this Gem! :)

[TwP]

Thanks for posting the Heroku link. In order to support their logplex project, Heroku is inserting a little bit of code that redefines the Rails logger(s) in much the same way the logging-rails gem does.

In the best case scenario, the last plugin loaded is the one that wins. In the worst case scenario, you'll end up with mixed mode logging ... some log statements being handled by the Heroku logger, and some log statements being handled by the Logging framework.

So I cannot give you a definitive answer. I'll reach out to the Heroku folk and see if there is a way to get these two systems to cooperate.

[mixellent]

Sorry about the delay in my response, I basically tried to set Heroku's LOG_LEVEL setting to DEBUG, but I was unable to see any logs I wrote as part of the logging-rails framework. I only saw 'puts' statements I added in my code.

So it seems as Heroku is ignoring all input coming from logging-rails. Did you get a chance to verify with Heroku directly?

[mixellent]

UPDATE: I finally managed to get logging-rails to play nicely with Heroku. Note: I am using Unicorn on Rails 3.1.3, so I had to apply changes as outlined in the following link: http://help.papertrailapp.com/discussions/questions/116-logging-from-heroku-apps-using-unicorn.

Here are the steps I took, specifically in the config/logging/rb file.

1) Heroku doesn't play nicely with log files creation, so I had to remove my Logging.appenders.rolling_file declarations:

my_logger.add_appenders(
    Logging.appenders.file('log/1.log',
                          :layout => layout)
    )

2) I had to remove the following declaration:

Logging.logger.root.appenders = config.log_to unless config.log_to.empty?

3) Add stdout logging to each of your log files (remove any file appenders):

my_logger = Logging.logger['MyClass']
  my_logger.add_appenders(
      Logging.appenders.stdout
  )

Having followed those steps, I was able to see my logs inside the Heroku log stream!

Keep in mind that with Heroku, you won't be able to see all your logs separately per file. You have a single stream containing all your logs. However, you can use Papertrail (papertrailapp.com) which is a nice tool I discovered today that allows you to retrieve all logs directly from Heroku and it will archive your logs for a week or so. It also allows you to perform alerts whenever a specific error is being written to your log.

[crc83]

When I use console appender Sysout I receive warining in console

###/gems/shared/gems/logging-1.8.1/lib/logging/appenders/io.rb:75 warning: syswrite for buffered IO

But when I use Syserr, I don't receive it Some explanations I found here: http://stackoverflow.com/questions/6711750/consequences-of-unbuffered-file-i-o