GUAC-911: Expand logging within SSH and telnet.

This commit is contained in:
Michael Jumper 2014-11-28 17:20:02 -08:00
parent ea64fd51ff
commit 4b53f9f3a6
6 changed files with 64 additions and 21 deletions

View File

@ -74,6 +74,11 @@ int guac_sftp_file_handler(guac_client* client, guac_stream* stream,
/* Ensure filename is a valid filename and not a path */ /* Ensure filename is a valid filename and not a path */
if (!__ssh_guac_valid_filename(filename)) { if (!__ssh_guac_valid_filename(filename)) {
guac_client_log(client, GUAC_LOG_DEBUG,
"Filename \"%s\" is invalid",
filename);
guac_protocol_send_ack(client->socket, stream, "SFTP: Illegal filename", guac_protocol_send_ack(client->socket, stream, "SFTP: Illegal filename",
GUAC_PROTOCOL_STATUS_CLIENT_BAD_REQUEST); GUAC_PROTOCOL_STATUS_CLIENT_BAD_REQUEST);
guac_socket_flush(client->socket); guac_socket_flush(client->socket);
@ -102,6 +107,11 @@ int guac_sftp_file_handler(guac_client* client, guac_stream* stream,
/* If path + filename exceeds max length, abort */ /* If path + filename exceeds max length, abort */
if (i == GUAC_SFTP_MAX_PATH) { if (i == GUAC_SFTP_MAX_PATH) {
guac_client_log(client, GUAC_LOG_DEBUG,
"Filename exceeds maximum of %i characters",
GUAC_SFTP_MAX_PATH);
guac_protocol_send_ack(client->socket, stream, "SFTP: Name too long", GUAC_PROTOCOL_STATUS_CLIENT_OVERRUN); guac_protocol_send_ack(client->socket, stream, "SFTP: Name too long", GUAC_PROTOCOL_STATUS_CLIENT_OVERRUN);
guac_socket_flush(client->socket); guac_socket_flush(client->socket);
return 0; return 0;
@ -117,11 +127,16 @@ int guac_sftp_file_handler(guac_client* client, guac_stream* stream,
/* Inform of status */ /* Inform of status */
if (file != NULL) { if (file != NULL) {
guac_client_log(client, GUAC_LOG_DEBUG,
"File \"%s\" opened",
fullpath);
guac_protocol_send_ack(client->socket, stream, "SFTP: File opened", GUAC_PROTOCOL_STATUS_SUCCESS); guac_protocol_send_ack(client->socket, stream, "SFTP: File opened", GUAC_PROTOCOL_STATUS_SUCCESS);
guac_socket_flush(client->socket); guac_socket_flush(client->socket);
} }
else { else {
guac_client_log(client, GUAC_LOG_ERROR, "Unable to open file \"%s\": %s", guac_client_log(client, GUAC_LOG_INFO, "Unable to open file \"%s\": %s",
fullpath, libssh2_sftp_last_error(client_data->sftp_session)); fullpath, libssh2_sftp_last_error(client_data->sftp_session));
guac_protocol_send_ack(client->socket, stream, "SFTP: Open failed", GUAC_PROTOCOL_STATUS_RESOURCE_NOT_FOUND); guac_protocol_send_ack(client->socket, stream, "SFTP: Open failed", GUAC_PROTOCOL_STATUS_RESOURCE_NOT_FOUND);
guac_socket_flush(client->socket); guac_socket_flush(client->socket);
@ -146,13 +161,14 @@ int guac_sftp_blob_handler(guac_client* client, guac_stream* stream,
/* Attempt write */ /* Attempt write */
if (libssh2_sftp_write(file, data, length) == length) { if (libssh2_sftp_write(file, data, length) == length) {
guac_client_log(client, GUAC_LOG_DEBUG, "%i bytes written", length);
guac_protocol_send_ack(client->socket, stream, "SFTP: OK", GUAC_PROTOCOL_STATUS_SUCCESS); guac_protocol_send_ack(client->socket, stream, "SFTP: OK", GUAC_PROTOCOL_STATUS_SUCCESS);
guac_socket_flush(client->socket); guac_socket_flush(client->socket);
} }
/* Inform of any errors */ /* Inform of any errors */
else { else {
guac_client_log(client, GUAC_LOG_ERROR, "Unable to write to file: %s", guac_client_log(client, GUAC_LOG_INFO, "Unable to write to file: %s",
libssh2_sftp_last_error(client_data->sftp_session)); libssh2_sftp_last_error(client_data->sftp_session));
guac_protocol_send_ack(client->socket, stream, "SFTP: Write failed", GUAC_PROTOCOL_STATUS_SERVER_ERROR); guac_protocol_send_ack(client->socket, stream, "SFTP: Write failed", GUAC_PROTOCOL_STATUS_SERVER_ERROR);
guac_socket_flush(client->socket); guac_socket_flush(client->socket);
@ -169,11 +185,12 @@ int guac_sftp_end_handler(guac_client* client, guac_stream* stream) {
/* Attempt to close file */ /* Attempt to close file */
if (libssh2_sftp_close(file) == 0) { if (libssh2_sftp_close(file) == 0) {
guac_client_log(client, GUAC_LOG_DEBUG, "File closed");
guac_protocol_send_ack(client->socket, stream, "SFTP: OK", GUAC_PROTOCOL_STATUS_SUCCESS); guac_protocol_send_ack(client->socket, stream, "SFTP: OK", GUAC_PROTOCOL_STATUS_SUCCESS);
guac_socket_flush(client->socket); guac_socket_flush(client->socket);
} }
else { else {
guac_client_log(client, GUAC_LOG_ERROR, "Unable to close file"); guac_client_log(client, GUAC_LOG_INFO, "Unable to close file");
guac_protocol_send_ack(client->socket, stream, "SFTP: Close failed", GUAC_PROTOCOL_STATUS_SERVER_ERROR); guac_protocol_send_ack(client->socket, stream, "SFTP: Close failed", GUAC_PROTOCOL_STATUS_SERVER_ERROR);
guac_socket_flush(client->socket); guac_socket_flush(client->socket);
} }
@ -196,19 +213,25 @@ int guac_sftp_ack_handler(guac_client* client, guac_stream* stream,
int bytes_read = libssh2_sftp_read(file, buffer, sizeof(buffer)); int bytes_read = libssh2_sftp_read(file, buffer, sizeof(buffer));
/* If bytes read, send as blob */ /* If bytes read, send as blob */
if (bytes_read > 0) if (bytes_read > 0) {
guac_protocol_send_blob(client->socket, stream, guac_protocol_send_blob(client->socket, stream,
buffer, bytes_read); buffer, bytes_read);
guac_client_log(client, GUAC_LOG_DEBUG, "%i bytes sent to client",
bytes_read);
}
/* If EOF, send end */ /* If EOF, send end */
else if (bytes_read == 0) { else if (bytes_read == 0) {
guac_client_log(client, GUAC_LOG_DEBUG, "File sent");
guac_protocol_send_end(client->socket, stream); guac_protocol_send_end(client->socket, stream);
guac_client_free_stream(client, stream); guac_client_free_stream(client, stream);
} }
/* Otherwise, fail stream */ /* Otherwise, fail stream */
else { else {
guac_client_log(client, GUAC_LOG_ERROR, "Error reading file: %s", guac_client_log(client, GUAC_LOG_INFO, "Error reading file: %s",
libssh2_sftp_last_error(client_data->sftp_session)); libssh2_sftp_last_error(client_data->sftp_session));
guac_protocol_send_end(client->socket, stream); guac_protocol_send_end(client->socket, stream);
guac_client_free_stream(client, stream); guac_client_free_stream(client, stream);
@ -236,7 +259,7 @@ guac_stream* guac_sftp_download_file(guac_client* client,
file = libssh2_sftp_open(client_data->sftp_session, filename, file = libssh2_sftp_open(client_data->sftp_session, filename,
LIBSSH2_FXF_READ, 0); LIBSSH2_FXF_READ, 0);
if (file == NULL) { if (file == NULL) {
guac_client_log(client, GUAC_LOG_ERROR, "Unable to read file \"%s\": %s", guac_client_log(client, GUAC_LOG_INFO, "Unable to read file \"%s\": %s",
filename, filename,
libssh2_sftp_last_error(client_data->sftp_session)); libssh2_sftp_last_error(client_data->sftp_session));
return NULL; return NULL;
@ -253,6 +276,7 @@ guac_stream* guac_sftp_download_file(guac_client* client,
"application/octet-stream", filename); "application/octet-stream", filename);
guac_socket_flush(client->socket); guac_socket_flush(client->socket);
guac_client_log(client, GUAC_LOG_DEBUG, "Sending file \"%s\"", filename);
return stream; return stream;
} }
@ -272,6 +296,7 @@ void guac_sftp_set_upload_path(guac_client* client, char* path) {
/* Copy path */ /* Copy path */
memcpy(client_data->sftp_upload_path, path, length); memcpy(client_data->sftp_upload_path, path, length);
guac_client_log(client, GUAC_LOG_DEBUG, "Upload path set to \"%s\"", path);
} }

View File

@ -112,7 +112,9 @@ static void __kbd_callback(const char *name, int name_len,
responses[0].length = strlen(client_data->password); responses[0].length = strlen(client_data->password);
} }
else else
guac_client_log(client, GUAC_LOG_INFO, "Unsupported number of keyboard-interactive prompts: %i", num_prompts); guac_client_log(client, GUAC_LOG_WARNING,
"Unsupported number of keyboard-interactive prompts: %i",
num_prompts);
} }
@ -161,13 +163,13 @@ static LIBSSH2_SESSION* __guac_ssh_create_session(guac_client* client,
connected_address, sizeof(connected_address), connected_address, sizeof(connected_address),
connected_port, sizeof(connected_port), connected_port, sizeof(connected_port),
NI_NUMERICHOST | NI_NUMERICSERV))) NI_NUMERICHOST | NI_NUMERICSERV)))
guac_client_log(client, GUAC_LOG_INFO, "Unable to resolve host: %s", gai_strerror(retval)); guac_client_log(client, GUAC_LOG_DEBUG, "Unable to resolve host: %s", gai_strerror(retval));
/* Connect */ /* Connect */
if (connect(fd, current_address->ai_addr, if (connect(fd, current_address->ai_addr,
current_address->ai_addrlen) == 0) { current_address->ai_addrlen) == 0) {
guac_client_log(client, GUAC_LOG_INFO, "Successfully connected to " guac_client_log(client, GUAC_LOG_DEBUG, "Successfully connected to "
"host %s, port %s", connected_address, connected_port); "host %s, port %s", connected_address, connected_port);
/* Done if successful connect */ /* Done if successful connect */
@ -177,7 +179,7 @@ static LIBSSH2_SESSION* __guac_ssh_create_session(guac_client* client,
/* Otherwise log information regarding bind failure */ /* Otherwise log information regarding bind failure */
else else
guac_client_log(client, GUAC_LOG_INFO, "Unable to connect to " guac_client_log(client, GUAC_LOG_DEBUG, "Unable to connect to "
"host %s, port %s: %s", "host %s, port %s: %s",
connected_address, connected_port, strerror(errno)); connected_address, connected_port, strerror(errno));
@ -214,7 +216,7 @@ static LIBSSH2_SESSION* __guac_ssh_create_session(guac_client* client,
/* Get list of suported authentication methods */ /* Get list of suported authentication methods */
user_authlist = libssh2_userauth_list(session, client_data->username, strlen(client_data->username)); user_authlist = libssh2_userauth_list(session, client_data->username, strlen(client_data->username));
guac_client_log(client, GUAC_LOG_INFO, "Supported authentication methods: %s", user_authlist); guac_client_log(client, GUAC_LOG_DEBUG, "Supported authentication methods: %s", user_authlist);
/* Authenticate with key if available */ /* Authenticate with key if available */
if (client_data->key != NULL) { if (client_data->key != NULL) {
@ -242,11 +244,11 @@ static LIBSSH2_SESSION* __guac_ssh_create_session(guac_client* client,
/* Authenticate with password */ /* Authenticate with password */
if (strstr(user_authlist, "password") != NULL) { if (strstr(user_authlist, "password") != NULL) {
guac_client_log(client, GUAC_LOG_INFO, "Using password authentication method"); guac_client_log(client, GUAC_LOG_DEBUG, "Using password authentication method");
retval = libssh2_userauth_password(session, client_data->username, client_data->password); retval = libssh2_userauth_password(session, client_data->username, client_data->password);
} }
else if (strstr(user_authlist, "keyboard-interactive") != NULL) { else if (strstr(user_authlist, "keyboard-interactive") != NULL) {
guac_client_log(client, GUAC_LOG_INFO, "Using keyboard-interactive authentication method"); guac_client_log(client, GUAC_LOG_DEBUG, "Using keyboard-interactive authentication method");
retval = libssh2_userauth_keyboard_interactive(session, client_data->username, &__kbd_callback); retval = libssh2_userauth_keyboard_interactive(session, client_data->username, &__kbd_callback);
} }
else { else {
@ -442,7 +444,7 @@ void* ssh_client_thread(void* data) {
client_data->term->file_download_handler = guac_sftp_download_file; client_data->term->file_download_handler = guac_sftp_download_file;
/* Create SSH session specific for SFTP */ /* Create SSH session specific for SFTP */
guac_client_log(client, GUAC_LOG_INFO, "Reconnecting for SFTP..."); guac_client_log(client, GUAC_LOG_DEBUG, "Reconnecting for SFTP...");
client_data->sftp_ssh_session = __guac_ssh_create_session(client, NULL); client_data->sftp_ssh_session = __guac_ssh_create_session(client, NULL);
if (client_data->sftp_ssh_session == NULL) { if (client_data->sftp_ssh_session == NULL) {
/* Already aborted within __guac_ssh_create_session() */ /* Already aborted within __guac_ssh_create_session() */
@ -459,7 +461,7 @@ void* ssh_client_thread(void* data) {
/* Set file handler */ /* Set file handler */
client->file_handler = guac_sftp_file_handler; client->file_handler = guac_sftp_file_handler;
guac_client_log(client, GUAC_LOG_INFO, "SFTP session initialized"); guac_client_log(client, GUAC_LOG_DEBUG, "SFTP session initialized");
} }

View File

@ -63,7 +63,8 @@ int guac_telnet_client_key_handler(guac_client* client, int keysym, int pressed)
/* Stop searching for password */ /* Stop searching for password */
if (client_data->password_regex != NULL) { if (client_data->password_regex != NULL) {
guac_client_log(client, GUAC_LOG_INFO, "Stopping password prompt search due to user input."); guac_client_log(client, GUAC_LOG_DEBUG,
"Stopping password prompt search due to user input.");
regfree(client_data->password_regex); regfree(client_data->password_regex);
free(client_data->password_regex); free(client_data->password_regex);
@ -74,7 +75,8 @@ int guac_telnet_client_key_handler(guac_client* client, int keysym, int pressed)
/* Stop searching for username */ /* Stop searching for username */
if (client_data->username_regex != NULL) { if (client_data->username_regex != NULL) {
guac_client_log(client, GUAC_LOG_INFO, "Stopping username prompt search due to user input."); guac_client_log(client, GUAC_LOG_DEBUG,
"Stopping username prompt search due to user input.");
regfree(client_data->username_regex); regfree(client_data->username_regex);
free(client_data->username_regex); free(client_data->username_regex);

View File

@ -158,6 +158,7 @@ static void __guac_telnet_event_handler(telnet_t* telnet, telnet_event_t* event,
if (client_data->username_regex != NULL) { if (client_data->username_regex != NULL) {
if (__guac_telnet_regex_search(client, client_data->username_regex, client_data->username, if (__guac_telnet_regex_search(client, client_data->username_regex, client_data->username,
event->data.buffer, event->data.size)) { event->data.buffer, event->data.size)) {
guac_client_log(client, GUAC_LOG_DEBUG, "Username sent");
regfree(client_data->username_regex); regfree(client_data->username_regex);
free(client_data->username_regex); free(client_data->username_regex);
client_data->username_regex = NULL; client_data->username_regex = NULL;
@ -169,6 +170,8 @@ static void __guac_telnet_event_handler(telnet_t* telnet, telnet_event_t* event,
if (__guac_telnet_regex_search(client, client_data->password_regex, client_data->password, if (__guac_telnet_regex_search(client, client_data->password_regex, client_data->password,
event->data.buffer, event->data.size)) { event->data.buffer, event->data.size)) {
guac_client_log(client, GUAC_LOG_DEBUG, "Password sent");
/* Do not continue searching for username once password is sent */ /* Do not continue searching for username once password is sent */
if (client_data->username_regex != NULL) { if (client_data->username_regex != NULL) {
regfree(client_data->username_regex); regfree(client_data->username_regex);
@ -227,7 +230,7 @@ static void __guac_telnet_event_handler(telnet_t* telnet, telnet_event_t* event,
/* Connection warnings */ /* Connection warnings */
case TELNET_EV_WARNING: case TELNET_EV_WARNING:
guac_client_log(client, GUAC_LOG_INFO, "%s", event->error.msg); guac_client_log(client, GUAC_LOG_WARNING, "%s", event->error.msg);
break; break;
/* Connection errors */ /* Connection errors */
@ -322,13 +325,13 @@ static telnet_t* __guac_telnet_create_session(guac_client* client) {
connected_address, sizeof(connected_address), connected_address, sizeof(connected_address),
connected_port, sizeof(connected_port), connected_port, sizeof(connected_port),
NI_NUMERICHOST | NI_NUMERICSERV))) NI_NUMERICHOST | NI_NUMERICSERV)))
guac_client_log(client, GUAC_LOG_INFO, "Unable to resolve host: %s", gai_strerror(retval)); guac_client_log(client, GUAC_LOG_DEBUG, "Unable to resolve host: %s", gai_strerror(retval));
/* Connect */ /* Connect */
if (connect(fd, current_address->ai_addr, if (connect(fd, current_address->ai_addr,
current_address->ai_addrlen) == 0) { current_address->ai_addrlen) == 0) {
guac_client_log(client, GUAC_LOG_INFO, "Successfully connected to " guac_client_log(client, GUAC_LOG_DEBUG, "Successfully connected to "
"host %s, port %s", connected_address, connected_port); "host %s, port %s", connected_address, connected_port);
/* Done if successful connect */ /* Done if successful connect */
@ -338,7 +341,7 @@ static telnet_t* __guac_telnet_create_session(guac_client* client) {
/* Otherwise log information regarding bind failure */ /* Otherwise log information regarding bind failure */
else else
guac_client_log(client, GUAC_LOG_INFO, "Unable to connect to " guac_client_log(client, GUAC_LOG_DEBUG, "Unable to connect to "
"host %s, port %s: %s", "host %s, port %s: %s",
connected_address, connected_port, strerror(errno)); connected_address, connected_port, strerror(errno));

View File

@ -1124,6 +1124,9 @@ int guac_terminal_resize(guac_terminal* terminal, int width, int height) {
/* If size has changed */ /* If size has changed */
if (columns != terminal->term_width || rows != terminal->term_height) { if (columns != terminal->term_width || rows != terminal->term_height) {
guac_client_log(terminal->client, GUAC_LOG_DEBUG,
"Resizing terminal to %ix%i", rows, columns);
/* Resize terminal */ /* Resize terminal */
__guac_terminal_resize(terminal, columns, rows); __guac_terminal_resize(terminal, columns, rows);
@ -1298,6 +1301,8 @@ static int __guac_terminal_send_key(guac_terminal* term, int keysym, int pressed
if (keysym == 0xFFFF) return guac_terminal_send_string(term, "\x1B[3~"); /* Delete */ if (keysym == 0xFFFF) return guac_terminal_send_string(term, "\x1B[3~"); /* Delete */
/* Ignore unknown keys */ /* Ignore unknown keys */
guac_client_log(term->client, GUAC_LOG_DEBUG,
"Ignoring unknown keysym: 0x%X", keysym);
} }
} }

View File

@ -897,6 +897,9 @@ int guac_terminal_set_directory(guac_terminal* term, unsigned char c) {
term->char_handler = guac_terminal_echo; term->char_handler = guac_terminal_echo;
if (term->upload_path_handler) if (term->upload_path_handler)
term->upload_path_handler(term->client, filename); term->upload_path_handler(term->client, filename);
else
guac_client_log(term->client, GUAC_LOG_DEBUG,
"Cannot set upload path. File is transfer not enabled.");
length = 0; length = 0;
} }
@ -919,6 +922,9 @@ int guac_terminal_download(guac_terminal* term, unsigned char c) {
term->char_handler = guac_terminal_echo; term->char_handler = guac_terminal_echo;
if (term->file_download_handler) if (term->file_download_handler)
term->file_download_handler(term->client, filename); term->file_download_handler(term->client, filename);
else
guac_client_log(term->client, GUAC_LOG_DEBUG,
"Cannot send file. File is transfer not enabled.");
length = 0; length = 0;
} }