Ruby logger (#251)

* Add logger for ruby environment

* Update readme and example for ruby logger

* ruby-env: log load time for user code

environments/ruby/README.md

@@ -9,8 +9,9 @@ The environment works via convention where you create a Ruby method
 called `handler` with a single optional argument, a `Fission::Context`
 object.
 
-The `Fission::Context` object gives access to the Rack env, and a
-request object. Please see `fission/context.rb` for the public api.
+The `Fission::Context` object gives access to the Rack env, a
+request object, and a logger. Please see `fission/context.rb` for the
+public api.
 
 The `Fission::Request` object is a subclass of `Rack::Request` and
 provides access to parameters and headers. See `fission/request.rb`

environments/ruby/fission/context.rb

@@ -1,9 +1,14 @@
 # frozen_string_literal: true
 
 require_relative 'request'
+require 'forwardable'
 
 module Fission
   class Context
+    extend Forwardable
+
+    def_instance_delegator :request, :logger
+
     attr_reader :env
 
     def initialize(env)

environments/ruby/fission/handler.rb

@@ -5,14 +5,18 @@ require_relative 'context'
 module Fission
   module Handler
     def self.call(env)
+      context = Context.new(env)
+
       response = if method(:handler).arity > 0
-        handler(Context.new(env))
+        handler(context)
       else
         handler
       end
 
       response.is_a?(Array) ? response : Rack::Response.new([response]).finish
-    rescue
+
+    rescue => e
+      context.logger.error(%(Function failed - #{e}\n#{e.backtrace.join("\n")}))
       Rack::Response.new(['500 Internal Server Error'], 500, {}).finish
     end
   end

environments/ruby/fission/specializer.rb

@@ -1,13 +1,21 @@
 # frozen_string_literal: true
+require 'benchmark'
 
 module Fission
   CODE_PATH = '/userfunc/user'
 
   module Specializer
     def self.call(env)
-      load CODE_PATH
+      request = Request.new(env)
+
+      request.logger.info("Codepath defaulting to #{CODE_PATH}")
+      time = Benchmark.measure { load CODE_PATH }
+      request.logger.info("User code loaded in #{(time.real * 1000).round(3)}ms")
+
       Rack::Response.new([], 201).finish
-    rescue
+
+    rescue => e
+      request.logger.error(%(Specialization failed - #{e}\n#{e.backtrace.join("\n")}))
       Rack::Response.new(['500 Internal Server Error'], 500, {}).finish
     end
   end

environments/ruby/server.rb

@@ -1,12 +1,13 @@
 # frozen_string_literal: true
 
 require 'rack'
+require 'logger'
 
 require_relative 'fission/specializer'
 require_relative 'fission/handler'
 
 app = Rack::Builder.new do
-  use Rack::CommonLogger, $stderr
+  use Rack::Logger, Logger::DEBUG
 
   map "/specialize" do
     run Fission::Specializer

examples/ruby/request_data.rb

@@ -1,18 +1,19 @@
 # frozen_string_literal: true
 def handler(context)
-  request = context.request
+  context.logger.info("Received request")
+
   msg = <<~MSG
     ---ENV---
-    #{request.env.map { |h| h.join('=') }.join("\n") }
+    #{context.request.env.map { |h| h.join('=') }.join("\n") }
 
     ---HEADERS---
-    #{request.headers.map { |h| h.join(': ') }.join("\n") }
+    #{context.request.headers.map { |h| h.join(': ') }.join("\n") }
 
     ---PARAMS---
-    #{request.params.map { |h| h.join('=') }.join("\n") }
+    #{context.request.params.map { |h| h.join('=') }.join("\n") }
 
     --BODY--
-    #{request.body.read}
+    #{context.request.body.read}
   MSG
 
   Rack::Response.new([msg]).finish