Trace proxying

src/prax/application.cr

@@ -93,7 +93,9 @@ module Prax
       channel = Channel(String).new
       spawner.channel.send({channel, command})
 
-      case message = channel.receive
+      message = channel.receive
+      Prax.logger.debug { "executed command #{command.inspect} and received message #{message.inspect}" }
+      case message
       when "error"
         raise ErrorStartingApplication.new
       when "exception"

src/prax/middlewares/proxy_middleware.cr

@@ -16,14 +16,17 @@ module Prax
         request, client = handler.request, handler.client
         Prax.logger.debug { "#{request.method} #{request.uri}" }
 
+        Prax.logger.debug { "sending request from client to server" }
         server << "#{request.method} #{request.uri} #{request.http_version}\r\n"
         proxy_headers(request, handler.tcp_socket, handler.ssl?).each(&.to_s(server))
         server << "\r\n"
 
         if (len = request.content_length) > 0
           copy_stream(client, server, len)
         end
+        Prax.logger.debug { "done sending request from client to server" }
 
+        Prax.logger.debug { "returning response from server to client" }
         response = Parser.new(server).parse_response
         response.to_s(client)
 
@@ -34,8 +37,9 @@ module Prax
         elsif response.header("Connection") == "close"
           copy_stream(server, client)
         else
-          # TODO: read until EOF / connection close?
+          copy_stream(server, client)
         end
+        Prax.logger.debug { "done returning response from server to client" }
       end
 
       # FIXME: should dup the headers to avoid altering the request
@@ -61,23 +65,33 @@ module Prax
       private def copy_stream(input, output, len)
         buffer = uninitialized UInt8[2048]
 
+        Prax.logger.debug { "copying stream" }
         while len > 0
+          Prax.logger.debug { "about to read bytes" }
           count = input.read(buffer.to_slice[0, Math.min(len, buffer.size)])
+          Prax.logger.debug { "read #{count.inspect} bytes" }
           break if count == 0
 
           output.write(buffer.to_slice[0, count])
+          Prax.logger.debug { "wrote #{count.inspect} bytes" }
           len -= count
         end
+        Prax.logger.debug { "finished copying stream" }
       end
 
       private def copy_stream(input, output)
         buffer = uninitialized UInt8[2048]
 
+        Prax.logger.debug { "copying stream" }
         loop do
+          Prax.logger.debug { "about to read bytes" }
           count = input.read(buffer.to_slice[0, buffer.size])
+          Prax.logger.debug { "read #{count.inspect} bytes" }
           break if count == 0
           output.write(buffer.to_slice[0, count])
+          Prax.logger.debug { "wrote #{count.inspect} bytes" }
         end
+        Prax.logger.debug { "finished copying stream" }
       end
     end
   end

src/prax/server.cr

@@ -22,8 +22,11 @@ module Prax
       # each server accepts connections in its own fiber
       servers.each_with_index do |server, index|
         spawn do
+          Prax.logger.debug { "beginning to handle clients" }
           while socket = server.accept?
+            Prax.logger.debug { "spawning handler for client" }
             spawn handle_client(socket, index == 1)
+            Prax.logger.debug { "spawned handler for client" }
           end
         end
       end
@@ -83,8 +86,10 @@ module Prax
       debug_exception(ex)
 
     ensure
+      Prax.logger.debug { "closing socket" }
       ssl_socket.try(&.close) if ssl_socket
       socket.close
+      Prax.logger.debug { "closed socket" }
     end
 
     private def debug_exception(ex)