websocket: use log instead submodule logger (1/4) (#5921)

pull/5924/head
Carlos Esquerdo Bernat 2020-07-22 16:31:22 +02:00 committed by GitHub
parent 44c280e522
commit 0d8ebf5845
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
8 changed files with 82 additions and 137 deletions

View File

@ -2,20 +2,20 @@ module websocket
fn (ws &Client) send_message_event(msg &Message) {
ws.eb.publish('on_message', ws, msg)
l.d('sending on_message event')
ws.log.debug('sending on_message event')
}
fn (ws &Client) send_error_event(err string) {
ws.eb.publish('on_error', ws, err)
l.d('sending on_error event')
ws.log.debug('sending on_error event')
}
fn (ws &Client) send_close_event() {
ws.eb.publish('on_close', ws, voidptr(0))
l.d('sending on_close event')
ws.log.debug('sending on_close event')
}
fn (ws &Client) send_open_event() {
ws.eb.publish('on_open', ws, voidptr(0))
l.d('sending on_open event')
ws.log.debug('sending on_open event')
}

View File

@ -1,7 +1,7 @@
module websocket
fn (mut ws Client) read_handshake(seckey string) {
l.d('reading handshake...')
ws.log.debug('reading handshake...')
mut bytes_read := 0
max_buffer := 1024
buffer_size := 1
@ -12,10 +12,11 @@ fn (mut ws Client) read_handshake(seckey string) {
res = ws.read_from_server(buffer + bytes_read, buffer_size)
}
if res == 0 || res == -1 {
l.f('read_handshake: Failed to read handshake.')
ws.log.fatal('read_handshake: Failed to read handshake.')
}
if buffer[bytes_read] == `\n` && buffer[bytes_read - 1] == `\r` && buffer[bytes_read -
2] == `\n` && buffer[bytes_read - 3] == `\r` {
if buffer[bytes_read] == `\n` &&
buffer[bytes_read - 1] == `\r` && buffer[bytes_read - 2] == `\n` &&
buffer[bytes_read - 3] == `\r` {
break
}
bytes_read += buffer_size
@ -25,11 +26,11 @@ fn (mut ws Client) read_handshake(seckey string) {
}
fn (mut ws Client) handshake_handler(handshake_response, seckey string) {
l.d('handshake_handler:\r\n${handshake_response}')
ws.log.debug('handshake_handler:\r\n$handshake_response')
lines := handshake_response.split_into_lines()
header := lines[0]
if !header.starts_with('HTTP/1.1 101') && !header.starts_with('HTTP/1.0 101') {
l.f('handshake_handler: invalid HTTP status response code')
ws.log.fatal('handshake_handler: invalid HTTP status response code')
}
for i in 1 .. lines.len {
if lines[i].len <= 0 || lines[i] == '\r\n' {
@ -44,13 +45,13 @@ fn (mut ws Client) handshake_handler(handshake_response, seckey string) {
ws.flags << .has_connection
}
'Sec-WebSocket-Accept', 'sec-websocket-accept' {
l.d('comparing hashes')
l.d('seckey: ${seckey}')
ws.log.debug('comparing hashes')
ws.log.debug('seckey: $seckey')
challenge := create_key_challenge_response(seckey)
l.d('challenge: ${challenge}')
l.d('response: ${keys[1]}')
ws.log.debug('challenge: $challenge')
ws.log.debug('response: ${keys[1]}')
if keys[1].trim_space() != challenge {
l.e('handshake_handler: Sec-WebSocket-Accept header does not match computed sha1/base64 response.')
ws.log.error('handshake_handler: Sec-WebSocket-Accept header does not match computed sha1/base64 response.')
}
ws.flags << .has_accept
unsafe {
@ -65,9 +66,9 @@ fn (mut ws Client) handshake_handler(handshake_response, seckey string) {
}
if ws.flags.len < 3 {
ws.close(1002, 'invalid websocket HTTP headers')
l.e('invalid websocket HTTP headers')
ws.log.error('invalid websocket HTTP headers')
}
l.i('handshake successful!')
ws.log.info('handshake successful!')
unsafe {
handshake_response.free()
lines.free()

View File

@ -3,11 +3,8 @@ module websocket
fn (mut ws Client) write_to_server(buf voidptr, len int) int {
mut bytes_written := 0
ws.write_lock.m_lock()
bytes_written = if ws.is_ssl {
C.SSL_write(ws.ssl, buf, len)
} else {
C.write(ws.socket.sockfd, buf, len)
}
bytes_written = if ws.is_ssl { C.SSL_write(ws.ssl, buf, len) } else { C.write(ws.socket.sockfd,
buf, len) }
ws.write_lock.unlock()
return bytes_written
}

View File

@ -1,56 +0,0 @@
module logger
const (
colors = {
"success": "\e[32",
"debug": "\e[36",
"error": "\e[91",
"warn": "\e[33",
"critical": "\e[31",
"fatal": "\e[31",
"info": "\e[37"
}
)
struct Logger {
mod string
}
pub fn new(mod string) &Logger {
return &Logger{mod: mod}
}
pub fn (l &Logger) d(message string){
$if debug {
l.print("debug", message)
}
}
pub fn (l &Logger) i(message string){
l.print('info', message)
}
pub fn (l &Logger) e(message string){
l.print('error', message)
}
pub fn (l &Logger) c(message string){
l.print('critical', message)
}
pub fn (l &Logger) f(message string){
l.print('fatal', message)
exit(-1)
}
pub fn (l &Logger) w(message string){
l.print('warn', message)
}
pub fn (l &Logger) s(message string) {
l.print('success', message)
}
fn (l &Logger) print(mod, message string) {
println('${colors[mod]};7m[${mod}]\e[0m \e[1m${l.mod}\e[0m: ${message}')
}

View File

@ -7,20 +7,20 @@ const (
)
fn (mut ws Client) connect_ssl() {
l.i('Using secure SSL connection')
ws.log.info('Using secure SSL connection')
C.SSL_load_error_strings()
ws.sslctx = C.SSL_CTX_new(C.SSLv23_client_method())
if ws.sslctx == 0 {
l.f("Couldn't get ssl context")
ws.log.fatal("Couldn't get ssl context")
}
ws.ssl = C.SSL_new(ws.sslctx)
if ws.ssl == 0 {
l.f("Couldn't create OpenSSL instance.")
ws.log.fatal("Couldn't create OpenSSL instance.")
}
if C.SSL_set_fd(ws.ssl, ws.socket.sockfd) != 1 {
l.f("Couldn't assign ssl to socket.")
ws.log.fatal("Couldn't assign ssl to socket.")
}
if C.SSL_connect(ws.ssl) != 1 {
l.f("Couldn't connect using SSL.")
ws.log.fatal("Couldn't connect using SSL.")
}
}

View File

@ -28,8 +28,7 @@ pub fn utf8_validate(data byteptr, len int) bool {
}
fn (mut s Utf8State) seq(r0, r1, is_tail bool) bool {
if s.subindex == 0 || (s.index > 1 && s.subindex == 1) || (s.index >= 6 && s.subindex ==
2) {
if s.subindex == 0 || (s.index > 1 && s.subindex == 1) || (s.index >= 6 && s.subindex == 2) {
if (s.subindex == 0 && r0) || (s.subindex == 1 && r1) || (s.subindex == 2 && is_tail) {
s.subindex++
return true

View File

@ -20,7 +20,9 @@ fn htonl64(payload_len u64) byteptr {
fn create_masking_key() []byte {
mask_bit := byte(rand.intn(255))
buf := [`0`].repeat(4)
unsafe { C.memcpy(buf.data, &mask_bit, 4) }
unsafe {
C.memcpy(buf.data, &mask_bit, 4)
}
return buf
}

View File

@ -5,20 +5,16 @@ import net.urllib
import encoding.base64
import eventbus
import sync
import net.websocket.logger
const (
l = logger.new('ws')
)
import log
pub struct Client {
retry int
eb &eventbus.EventBus
is_ssl bool
mut:
// subprotocol_len int
// cwebsocket_subprotocol *subprotocol;
// cwebsocket_subprotocol *subprotocols[];
mut:
mtx &sync.Mutex = sync.new_mutex()
write_lock &sync.Mutex = sync.new_mutex()
state State
@ -28,6 +24,9 @@ mut:
ssl &C.SSL
fragments []Fragment
pub mut:
log log.Log = log.Log{
output_label: 'ws'
}
uri string
subscriber &eventbus.Subscriber
nonce_size int = 18 // you can try 16 too
@ -120,13 +119,13 @@ fn (ws &Client) parse_uri() &Uri {
pub fn (mut ws Client) connect() int {
match ws.state {
.connected {
l.f('connect: websocket already connected')
ws.log.fatal('connect: websocket already connected')
}
.connecting {
l.f('connect: websocket already connecting')
ws.log.fatal('connect: websocket already connecting')
}
.open {
l.f('connect: websocket already open')
ws.log.fatal('connect: websocket already open')
}
else {
// do nothing
@ -140,21 +139,21 @@ pub fn (mut ws Client) connect() int {
seckey := base64.encode(nonce)
ai_family := C.AF_INET
ai_socktype := C.SOCK_STREAM
l.d('handshake header:')
handshake := 'GET ${uri.resource}${uri.querystring} HTTP/1.1\r\nHost: ${uri.hostname}:${uri.port}\r\nUpgrade: websocket\r\nConnection: Upgrade\r\nSec-WebSocket-Key: ${seckey}\r\nSec-WebSocket-Version: 13\r\n\r\n'
l.d(handshake)
ws.log.debug('handshake header:')
handshake := 'GET $uri.resource$uri.querystring HTTP/1.1\r\nHost: $uri.hostname:$uri.port\r\nUpgrade: websocket\r\nConnection: Upgrade\r\nSec-WebSocket-Key: $seckey\r\nSec-WebSocket-Version: 13\r\n\r\n'
ws.log.debug(handshake)
socket := net.new_socket(ai_family, ai_socktype, 0) or {
l.f(err)
ws.log.fatal(err)
return -1
}
ws.socket = socket
ws.socket.connect(uri.hostname, uri.port.int()) or {
l.f(err)
ws.log.fatal(err)
return -1
}
optval := 1
ws.socket.setsockopt(C.SOL_SOCKET, C.SO_KEEPALIVE, &optval) or {
l.f(err)
ws.log.fatal(err)
return -1
}
if ws.is_ssl {
@ -165,7 +164,7 @@ pub fn (mut ws Client) connect() int {
ws.mtx.unlock()
res := ws.write_to_server(handshake.str, handshake.len)
if res <= 0 {
l.f('Handshake failed.')
ws.log.fatal('Handshake failed.')
}
ws.read_handshake(seckey)
ws.mtx.m_lock()
@ -208,7 +207,7 @@ pub fn (mut ws Client) close(code int, message string) {
}
} else {
if C.shutdown(ws.socket.sockfd, C.SHUT_WR) == -1 {
l.e('Unabled to shutdown websocket.')
ws.log.error('Unabled to shutdown websocket.')
}
mut buf := [`0`]
for ws.read_from_server(buf.data, 1) > 0 {
@ -226,8 +225,6 @@ pub fn (mut ws Client) close(code int, message string) {
ws.mtx.m_lock()
ws.state = .closed
ws.mtx.unlock()
unsafe {
}
// TODO impl autoreconnect
}
}
@ -244,7 +241,7 @@ pub fn (mut ws Client) write(payload byteptr, payload_len int, code OPCode) int
header_len := 6 + if payload_len > 125 { 2 } else { 0 } + if payload_len > 0xffff { 6 } else { 0 }
frame_len := header_len + payload_len
mut frame_buf := [`0`].repeat(frame_len)
fbdata := byteptr( frame_buf.data )
fbdata := byteptr(frame_buf.data)
masking_key := create_masking_key()
mut header := [`0`].repeat(header_len)
header[0] = byte(code) | 0x80
@ -275,13 +272,12 @@ pub fn (mut ws Client) write(payload byteptr, payload_len int, code OPCode) int
header[12] = masking_key[2]
header[13] = masking_key[3]
} else {
l.c('write: frame too large')
ws.log.fatal('write: frame too large')
ws.close(1009, 'frame too large')
goto free_data
return -1
}
unsafe
{
unsafe {
C.memcpy(fbdata, header.data, header_len)
C.memcpy(fbdata + header_len, payload, payload_len)
}
@ -291,12 +287,12 @@ pub fn (mut ws Client) write(payload byteptr, payload_len int, code OPCode) int
bytes_written = ws.write_to_server(fbdata, frame_len)
if bytes_written == -1 {
err := string(byteptr(C.strerror(C.errno)))
l.e('write: there was an error writing data: ${err}')
ws.log.error('write: there was an error writing data: $err')
ws.send_error_event('Error writing data')
goto free_data
return -1
}
l.d('write: ${bytes_written} bytes written.')
ws.log.debug('write: $bytes_written bytes written.')
free_data:
unsafe {
free(payload)
@ -308,11 +304,11 @@ pub fn (mut ws Client) write(payload byteptr, payload_len int, code OPCode) int
}
pub fn (mut ws Client) listen() {
l.i('Starting listener...')
ws.log.info('Starting listener...')
for ws.state == .open {
ws.read()
}
l.i('Listener stopped as websocket was closed.')
ws.log.info('Listener stopped as websocket was closed.')
}
pub fn (mut ws Client) read() int {
@ -334,7 +330,7 @@ pub fn (mut ws Client) read() int {
match byt {
0 {
error := 'server closed the connection.'
l.e('read: ${error}')
ws.log.error('read: $error')
ws.send_error_event(error)
ws.close(1006, error)
goto free_data
@ -342,7 +338,7 @@ pub fn (mut ws Client) read() int {
}
-1 {
err := string(byteptr(C.strerror(C.errno)))
l.e('read: error reading frame. ${err}')
ws.log.error('read: error reading frame. $err')
ws.send_error_event('error reading frame')
goto free_data
return -1
@ -384,7 +380,7 @@ pub fn (mut ws Client) read() int {
payload_len = u64(extended_payload_len)
frame_size = u64(header_len) + payload_len
if frame_size > initial_buffer {
l.d('reallocating: ${frame_size}')
ws.log.debug('reallocating: $frame_size')
data = v_realloc(data, u32(frame_size))
}
} else if frame.payload_len == u64(127) && bytes_read == u64(extended_payload64_end_byte) {
@ -408,7 +404,7 @@ pub fn (mut ws Client) read() int {
payload_len = extended_payload_len
frame_size = u64(header_len) + payload_len
if frame_size > initial_buffer {
l.d('reallocating: ${frame_size}')
ws.log.debug('reallocating: $frame_size')
data = v_realloc(data, u32(frame_size)) // TODO u64 => u32
}
}
@ -425,12 +421,14 @@ pub fn (mut ws Client) read() int {
return -1
} else if frame.opcode in [.text_frame, .binary_frame] {
data_node:
l.d('read: recieved text_frame or binary_frame')
ws.log.debug('read: recieved text_frame or binary_frame')
mut payload := malloc(int(sizeof(byte) * u32(payload_len) + 1))
if payload == 0 {
l.f('out of memory')
ws.log.fatal('out of memory')
}
unsafe {
C.memcpy(payload, &data[header_len], payload_len)
}
unsafe { C.memcpy(payload, &data[header_len], payload_len) }
if frame.fin {
if ws.fragments.len > 0 {
// join fragments
@ -448,7 +446,7 @@ pub fn (mut ws Client) read() int {
}
mut pl := malloc(int(sizeof(byte) * u32(size)))
if pl == 0 {
l.f('out of memory')
ws.log.fatal('out of memory')
}
mut by := 0
for f in frags {
@ -472,7 +470,7 @@ pub fn (mut ws Client) read() int {
payload[payload_len] = `\0`
if frame.opcode == .text_frame && payload_len > 0 {
if !utf8_validate(payload, int(payload_len)) {
l.e('malformed utf8 payload')
ws.log.error('malformed utf8 payload')
ws.send_error_event('Recieved malformed utf8.')
ws.close(1007, 'malformed utf8 payload')
goto free_data
@ -498,9 +496,9 @@ pub fn (mut ws Client) read() int {
}
return int(bytes_read)
} else if frame.opcode == .continuation {
l.d('read: continuation')
ws.log.debug('read: continuation')
if ws.fragments.len <= 0 {
l.e('Nothing to continue.')
ws.log.error('Nothing to continue.')
ws.close(1002, 'nothing to continue')
goto free_data
return -1
@ -508,7 +506,7 @@ pub fn (mut ws Client) read() int {
goto data_node
return 0
} else if frame.opcode == .ping {
l.d('read: ping')
ws.log.debug('read: ping')
if !frame.fin {
ws.close(1002, 'control message must not be fragmented')
goto free_data
@ -522,7 +520,9 @@ pub fn (mut ws Client) read() int {
mut payload := []byte{}
if payload_len > 0 {
payload = [`0`].repeat(int(payload_len))
unsafe { C.memcpy(payload.data, &data[header_len], payload_len) }
unsafe {
C.memcpy(payload.data, &data[header_len], payload_len)
}
}
unsafe {
free(data)
@ -540,7 +540,7 @@ pub fn (mut ws Client) read() int {
// got pong
return 0
} else if frame.opcode == .close {
l.d('read: close')
ws.log.debug('read: close')
if frame.payload_len > 125 {
ws.close(1002, 'control frames must not exceed 125 bytes')
goto free_data
@ -553,9 +553,9 @@ pub fn (mut ws Client) read() int {
header_len += 2
payload_len -= 2
reason = string(&data[header_len])
l.i('Closing with reason: ${reason} & code: ${code}')
ws.log.info('Closing with reason: $reason & code: $code')
if reason.len > 1 && !utf8_validate(reason.str, reason.len) {
l.e('malformed utf8 payload')
ws.log.error('malformed utf8 payload')
ws.send_error_event('Recieved malformed utf8.')
ws.close(1007, 'malformed utf8 payload')
goto free_data
@ -568,8 +568,8 @@ pub fn (mut ws Client) read() int {
ws.close(code, reason)
return 0
}
l.e('read: Recieved unsupported opcode: ${frame.opcode} fin: ${frame.fin} uri: ${ws.uri}')
ws.send_error_event('Recieved unsupported opcode: ${frame.opcode}')
ws.log.error('read: Recieved unsupported opcode: $frame.opcode fin: $frame.fin uri: $ws.uri')
ws.send_error_event('Recieved unsupported opcode: $frame.opcode')
ws.close(1002, 'Unsupported opcode')
free_data:
unsafe {
@ -581,11 +581,11 @@ pub fn (mut ws Client) read() int {
fn (mut ws Client) send_control_frame(code OPCode, frame_typ string, payload []byte) int {
mut bytes_written := -1
if ws.socket.sockfd <= 0 {
l.e('No socket opened.')
ws.log.error('No socket opened.')
unsafe {
payload.free()
}
l.c('send_control_frame: error sending ${frame_typ} control frame.')
ws.log.fatal('send_control_frame: error sending $frame_typ control frame.')
return -1
}
header_len := 6
@ -601,7 +601,9 @@ fn (mut ws Client) send_control_frame(code OPCode, frame_typ string, payload []b
if code == .close {
if payload.len > 2 {
mut parsed_payload := [`0`].repeat(payload.len + 1)
unsafe { C.memcpy(parsed_payload.data, &payload[0], payload.len) }
unsafe {
C.memcpy(parsed_payload.data, &payload[0], payload.len)
}
parsed_payload[payload.len] = `\0`
for i in 0 .. payload.len {
control_frame[6 + i] = (parsed_payload[i] ^ masking_key[i % 4]) & 0xff
@ -624,15 +626,15 @@ fn (mut ws Client) send_control_frame(code OPCode, frame_typ string, payload []b
}
match bytes_written {
0 {
l.d('send_control_frame: remote host closed the connection.')
ws.log.debug('send_control_frame: remote host closed the connection.')
return 0
}
-1 {
l.c('send_control_frame: error sending ${frame_typ} control frame.')
ws.log.error('send_control_frame: error sending $frame_typ control frame.')
return -1
}
else {
l.d('send_control_frame: wrote ${bytes_written} byte ${frame_typ} frame.')
ws.log.debug('send_control_frame: wrote $bytes_written byte $frame_typ frame.')
return bytes_written
}
}