New logging system.

dev
Karchnu 2020-08-24 16:57:02 +02:00
parent 4ba0b805a2
commit b171f90e92
1 changed files with 57 additions and 46 deletions

View File

@ -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