From b171f90e9247487fb26bd195e0bdc3178c830e46 Mon Sep 17 00:00:00 2001 From: Karchnu Date: Mon, 24 Aug 2020 16:57:02 +0200 Subject: [PATCH] New logging system. --- src/websocketd.cr | 103 +++++++++++++++++++++++++--------------------- 1 file changed, 57 insertions(+), 46 deletions(-) diff --git a/src/websocketd.cr b/src/websocketd.cr index da78f86..8cb499d 100644 --- a/src/websocketd.cr +++ b/src/websocketd.cr @@ -3,6 +3,8 @@ require "ipc" require "socket" require "./colors" +require "colorize" + require "json" require "socket" @@ -16,7 +18,7 @@ require "./instance_storage.cr" # All modifications to standard libraries go there. require "./lib_modifications.cr" -class CLI +class Context # service instance parameters # they can be changed via the cli class_property service_name : String = "websocket" @@ -26,25 +28,40 @@ class CLI class_property verbosity : Int32 = 1 end +class Log + def self.debug(message) + STDOUT << ":: ".colorize(:green) << message.colorize(:white) << "\n" if ::Context.verbosity > 2 + end + def self.info(message) + STDOUT << ":: ".colorize(:blue) << message.colorize(:white) << "\n" if ::Context.verbosity > 1 + end + def self.warning(message) + STDERR << "?? ".colorize(:yellow) << message.colorize(:yellow) << "\n" if ::Context.verbosity > 0 + end + def self.error(message) + STDERR << "!! ".colorize(:red) << message.colorize(:red) << "\n" if ::Context.verbosity > 0 + end +end + OptionParser.parse do |parser| parser.on "-l host", "--l host", "IP address to listen on." do |h| - CLI.host = h + Context.host = h end parser.on "-p port", "--port port", "Port to listen on." do |port| - CLI.port_to_listen = port.to_u16 + Context.port_to_listen = port.to_u16 end parser.on "-s service-name", "--service-name service-name", "Service name." do |name| - CLI.service_name = name + Context.service_name = name end parser.on "-t timer-delay", "--timer-delay timer-delay", "Timer delay (in seconds)" do |t| - CLI.timer_delay = t.to_i32 * 1000 # stored in ms + Context.timer_delay = t.to_i32 * 1000 # stored in ms end parser.on "-v verbosity-level", "--verbosity level", "Verbosity." do |opt| - CLI.verbosity = opt.to_i + Context.verbosity = opt.to_i end parser.on "-h", "--help", "Show this help" do @@ -58,11 +75,11 @@ def sending_ping_messages begin ws.ping "hello from #{fd}" rescue e - puts "#{CRED}Exception: #{e}#{CRESET}, already closed client #{fd}" + Log.error "Exception: #{e}, already closed client #{fd}" begin Context.context.remove_fd fd rescue e - puts "#{CRED}Cannot remove #{fd} from clients: #{e}#{CRESET}" + Log.error "Cannot remove #{fd} from clients: #{e}" end end end @@ -86,7 +103,7 @@ def ws_http_upgrade(client) # FIXME: check they actually wanted to upgrade to websocket key = request.headers["Sec-WebSocket-Key"] response_key = Digest::SHA1.base64digest key + "258EAFA5-E914-47DA-95CA-C5AB0DC85B11" - # puts response_key + # Log.debug response_key # HTTP inside bru headers_header = "HTTP/1.1 101 Switching Protocols" @@ -113,7 +130,7 @@ def ws_http_upgrade(client) wsclient = WebSocket.new client wsclient.on_pong do |m| - puts "pong #{m}" + Log.debug "pong #{m}" end # registering the client into storing structures to avoid being garbage collected @@ -122,7 +139,7 @@ def ws_http_upgrade(client) return req_service, request rescue e - puts "#{CRED}Exception in ws_http_upgrade#{CRESET}: #{CBLUE}#{e}#{CRESET}" + Log.error "Exception in ws_http_upgrade: #{e}" raise "DROP IT" end @@ -161,7 +178,7 @@ def handle_new_clients(service, server) # If not found, we use the client address from the socket. real_ip_address = request.headers["X-Real-IP"] || client.remote_address.address - puts "trackingd - sending the IP address #{real_ip_address} to fd #{serverfd}" + Log.info "trackingd - sending the IP address #{real_ip_address} to fd #{serverfd}" # sfd = Context.context.switchtable[client.fd] # message = IPC::Message.from_json(JSON).to_packet # => JSON has to include these attributes: mtype, utype, payload @@ -173,16 +190,16 @@ def handle_new_clients(service, server) # serv.send message.to_packet end - info "#{CBLUE}new client:#{CRESET} #{client.fd}" + Log.debug "new client: #{client.fd}" rescue e - puts "Exception in handle_new_client: #{CRED}#{e}#{CRESET}" + Log.error "Exception in handle_new_client: #{e}" unless client.nil? client.close end end def ws_cb_out(fd : Int32, pm : Pointer(LibIPC::Message)) - # info "OUT fd is #{fd}" + # Log.info "OUT fd is #{fd}" wsclient = Context.context.fd_to_websocket[fd] message = IPC::Message.new pm @@ -198,13 +215,13 @@ def ws_cb_out(fd : Int32, pm : Pointer(LibIPC::Message)) return LibIPC::IPCCB::NoError rescue e - puts "#{CRED}Exception during message transfer:#{CRESET} #{e}" + Log.error "Exception during message transfer: #{e}" Context.context.remove_fd fd return LibIPC::IPCCB::Error end def ws_cb_in(fd : Int32, pm : LibIPC::Message*, more_to_read : Int16*) - # info "IN fd is #{fd}" + # Log.debug "IN fd is #{fd}" wsclient = Context.context.fd_to_websocket[fd] @@ -212,7 +229,7 @@ def ws_cb_in(fd : Int32, pm : LibIPC::Message*, more_to_read : Int16*) begin message = wsclient.run_once rescue e - puts "#{CRED}run_once FAILED#{CRESET}: #{e}" + Log.error "run_once FAILED: #{e}" Context.context.remove_fd fd return LibIPC::IPCCB::Error end @@ -224,13 +241,13 @@ def ws_cb_in(fd : Int32, pm : LibIPC::Message*, more_to_read : Int16*) end if wsclient.closed? - info "#{CBLUE}client is closed#{CRESET}" + Log.info "client closed the connection" Context.context.remove_fd fd return LibIPC::IPCCB::Closing end if message.nil? - puts "#{CRED}message is nil#{CRESET}" + Log.error "Reveiced a nil message" Context.context.remove_fd fd return LibIPC::IPCCB::Closing end @@ -246,97 +263,91 @@ def ws_cb_in(fd : Int32, pm : LibIPC::Message*, more_to_read : Int16*) # every other option should be dropped case message when WebSocket::Error - puts "#{CRED}An error occured#{CRESET}" + Log.error "An error occured" Context.context.remove_fd fd return LibIPC::IPCCB::Error when WebSocket::Ping - puts "#{CBLUE}Received a ping message#{CRESET}" + Log.debug "Received a ping message" Context.context.remove_fd fd return LibIPC::IPCCB::Ignore when WebSocket::Pong - puts "#{CBLUE}Received a pong message#{CRESET}" + Log.debug "Received a pong message" return LibIPC::IPCCB::Ignore when WebSocket::Close - puts "#{CBLUE}Received a close message#{CRESET}" + Log.debug "Received a close message" Context.context.remove_fd fd return LibIPC::IPCCB::Closing when WebSocket::NotFinal - puts "#{CBLUE}Received only part of a message: NOT IMPLEMENTED#{CRESET}" + Log.warning "Received only part of a message: NOT IMPLEMENTED" Context.context.remove_fd fd return LibIPC::IPCCB::Error when Bytes # TODO: when receiving a binary message # we should test the format and maybe its content - puts "#{CBLUE}Received a binary message: NOT IMPLEMENTED, YET#{CRESET}" + Log.error "Received a binary message: NOT IMPLEMENTED, YET" Context.context.remove_fd fd return LibIPC::IPCCB::Error else - puts "#{CRED}Received a websocket message with unknown type#{CRESET}" + Log.error "Received a websocket message with unknown type" end end return LibIPC::IPCCB::Error rescue e - puts "#{CRED}Exception (receiving a message)#{CRESET} #{e}" + Log.error "Exception (receiving a message) #{e}" # tcp = WrappedTCPFileDescriptor.new(fd: fd, family: Socket::Family::INET) # tcp.close Context.context.remove_fd fd return LibIPC::IPCCB::Error end -def info(str : String) - if CLI.verbosity > 0 - puts str - end -end - class Context class_property context = InstanceStorage.new end def main # by default, listen on any IP address - server = TCPServer.new(CLI.host, CLI.port_to_listen) - service = IPC::Server.new CLI.service_name + server = TCPServer.new(Context.host, Context.port_to_listen) + service = IPC::Server.new Context.service_name service << server.fd # Every few seconds, the service should trigger the timer # Allowing the sending of Ping messages to clients - service.base_timer = CLI.timer_delay - service.timer = CLI.timer_delay + service.base_timer = Context.timer_delay + service.timer = Context.timer_delay service.loop do |event| - # info "current state of the context:" + # Log.info "current state of the context:" # service.pp case event when IPC::Event::Timer - info "#{CORANGE}IPC::Event::Timer#{CRESET}" + Log.debug "IPC::Event::Timer" sending_ping_messages when IPC::Event::Connection - info "#{CBLUE}IPC::Event::Connection#{CRESET}: fd #{event.fd}" + Log.debug "IPC::Event::Connection: fd #{event.fd}" when IPC::Event::Disconnection - info "#{CBLUE}IPC::Event::Disconnection#{CRESET}: fd #{event.fd}" + Log.debug "IPC::Event::Disconnection: fd #{event.fd}" Context.context.remove_fd event.fd when IPC::Event::ExtraSocket - info "#{CBLUE}IPC::Event::ExtraSocket#{CRESET}: fd #{event.fd}" + Log.debug "IPC::Event::ExtraSocket: fd #{event.fd}" if server.fd != event.fd raise "Error: the only extra socket should be the TCP/WS server" end handle_new_clients(service, server) when IPC::Event::Switch - info "\033[36mIPC::Event::Switch#{CRESET}: fd #{event.fd}" + Log.debug "IPC::Event::Switch: fd #{event.fd}" # raise "Not implemented." when IPC::Event::MessageSent - info "#{CBLUE}IPC::Event::MessageSent#{CRESET}: fd #{event.fd}" + Log.debug "IPC::Event::MessageSent: fd #{event.fd}" when IPC::Event::MessageReceived - info "#{CBLUE}IPC::Event::Message#{CRESET}: fd #{event.fd}" + Log.debug "IPC::Event::Message: fd #{event.fd}" raise "Not implemented." end