Add timestamped logging for non-debug messages

- Added log_message() function to prepend YYYY-MM-DD HH:MM:SS timestamps to log messages
- Updated all non-debug printf statements to use log_message() in wssshc.c and wssshd2/websocket.c
- Fixed variable redefinition issues in wssshc.c
- Adapted status logging to use correct tunnel_t fields for wssshd2
parent 0058a115
......@@ -32,6 +32,7 @@
#include <setjmp.h>
#include <openssl/ssl.h>
#include <openssl/err.h>
#include <stdarg.h>
#include "websocket.h"
#include "websocket_protocol.h"
#include "ssl.h"
......@@ -45,6 +46,17 @@ static const char *TUNNEL_REQUEST_MSG = "{\"type\":\"tunnel_request\",\"request_
static const char *TUNNEL_ACK_MSG = "{\"type\":\"tunnel_ack\",\"request_id\":\"%s\"}";
static const char *TUNNEL_ERROR_MSG = "{\"type\":\"tunnel_error\",\"request_id\":\"%s\",\"error\":\"%s\"}";
void log_message(const char *level, const char *format, ...) {
time_t now = time(NULL);
char time_str[20];
strftime(time_str, sizeof(time_str), "%Y-%m-%d %H:%M:%S", localtime(&now));
printf("[%s] [%s] ", time_str, level);
va_list args;
va_start(args, format);
vprintf(format, args);
va_end(args);
}
wssshd_state_t *websocket_init_state(bool debug, const char *server_password) {
wssshd_state_t *state = calloc(1, sizeof(wssshd_state_t));
if (!state) return NULL;
......@@ -503,7 +515,7 @@ int websocket_handle_message(wssshd_state_t *state, ws_connection_t *conn __attr
snprintf(response, sizeof(response), REGISTERED_MSG, client_id);
if (state->debug) printf("[DEBUG - wssshd -> wssshc] Sending registration success: %s\n", response);
ws_send_frame(conn, WS_OPCODE_TEXT, response, strlen(response));
if (!state->debug) printf("[EVENT] Client %s registered\n", client_id);
if (!state->debug) log_message("EVENT", "Client %s registered\n", client_id);
}
} else {
// Send registration error
......@@ -689,7 +701,7 @@ int websocket_handle_message(wssshd_state_t *state, ws_connection_t *conn __attr
ws_send_frame(conn, WS_OPCODE_TEXT, ack_msg, strlen(ack_msg));
if (state->debug) printf("[DEBUG - %s -> wssshd] Created tunnel %s for client %s\n", direction, request_id, client_id);
if (!state->debug) printf("[EVENT] New tunnel %s for client %s\n", request_id, client_id);
if (!state->debug) log_message("EVENT", "New tunnel %s for client %s\n", request_id, client_id);
}
} else {
// Send error to tool
......@@ -1074,7 +1086,7 @@ int websocket_handle_message(wssshd_state_t *state, ws_connection_t *conn __attr
// Remove the tunnel
websocket_remove_tunnel(state, request_id);
if (state->debug) printf("[DEBUG - %s -> wssshd] Closed tunnel %s\n", direction, request_id);
if (!state->debug) printf("[EVENT] Tunnel %s closed\n", request_id);
if (!state->debug) log_message("EVENT", "Tunnel %s closed\n", request_id);
}
if (request_id) free(request_id);
......@@ -1444,7 +1456,7 @@ static void *client_handler_thread(void *arg) {
if (state->clients[i].websocket == conn) {
// Remove this client
if (!state->debug) {
printf("[EVENT] Client %s disconnected\n", state->clients[i].client_id);
log_message("EVENT", "Client %s disconnected\n", state->clients[i].client_id);
}
memmove(&state->clients[i], &state->clients[i + 1],
(state->clients_count - i - 1) * sizeof(client_t));
......@@ -1478,9 +1490,33 @@ void *status_thread(void *arg) {
int seconds = uptime % 60;
pthread_mutex_lock(&state->tunnel_mutex);
int tunnel_count = state->tunnels_count;
pthread_mutex_unlock(&state->tunnel_mutex);
printf("[STATUS] Uptime: %02d:%02d:%02d | Active tunnels: %d\n",
log_message("STATUS", "Uptime: %02d:%02d:%02d | Active tunnels: %d\n",
hours, minutes, seconds, tunnel_count);
// List active tunnels with details
for (size_t i = 0; i < state->tunnels_count; i++) {
tunnel_t *tunnel = state->tunnels[i];
if (tunnel && tunnel->status == TUNNEL_STATUS_ACTIVE) {
time_t tunnel_uptime = current_time - tunnel->created_at;
unsigned long long total_data = tunnel->total_bytes_sent + tunnel->total_bytes_received;
double avg_rate = tunnel_uptime > 0 ? (double)total_data / tunnel_uptime : 0.0;
double last_rate = tunnel->bytes_last_period / 30.0;
log_message("STATUS", " Tunnel ID: %s | Client: %s | Service: %s | Uptime: %ld s | Data: %llu B (%llu sent, %llu recv) | Rate: %.2f B/s avg, %.2f B/s last\n",
tunnel->request_id,
strlen(tunnel->client_id) > 0 ? tunnel->client_id : "unknown",
strlen(tunnel->service) > 0 ? tunnel->service : "ssh",
tunnel_uptime,
total_data,
tunnel->total_bytes_sent,
tunnel->total_bytes_received,
avg_rate,
last_rate);
}
}
pthread_mutex_unlock(&state->tunnel_mutex);
}
}
return NULL;
......
......@@ -625,6 +625,9 @@ void handle_tunnel_request_with_service_and_enc(SSL *ssl, const char *request_id
new_tunnel->total_bytes_received = 0;
new_tunnel->bytes_last_period = 0;
new_tunnel->last_stats_reset = current_time;
new_tunnel->start_time = current_time;
strcpy(new_tunnel->service, service ? service->name : "ssh");
strcpy(new_tunnel->client_id, "local");
// Add the new tunnel to the array
if (!add_tunnel(new_tunnel)) {
......
......@@ -51,6 +51,9 @@ typedef struct {
unsigned long long total_bytes_received; // Total bytes received through tunnel
unsigned long long bytes_last_period; // Bytes transferred in last 30-second period
time_t last_stats_reset; // When we last reset the period stats
time_t start_time; // When the tunnel was created
char service[32]; // Service name (e.g., "ssh", "scp")
char client_id[64]; // Client identifier
int bin; // Binary mode flag - if true, transmit data as binary instead of hex
wsssh_encoding_t encoding; // Data encoding mode
......
......@@ -34,6 +34,7 @@
#include <dirent.h>
#include <sys/stat.h>
#include <sys/wait.h>
#include <stdarg.h>
#include "libwsssht/wssshlib.h"
#include "libwsssht/websocket.h"
......@@ -49,6 +50,17 @@ volatile sig_atomic_t sigint_count = 0;
volatile sig_atomic_t graceful_shutdown = 0;
volatile sig_atomic_t reload_config = 0;
void log_message(const char *level, const char *format, ...) {
time_t now = time(NULL);
char time_str[20];
strftime(time_str, sizeof(time_str), "%Y-%m-%d %H:%M:%S", localtime(&now));
printf("[%s] [%s] ", time_str, level);
va_list args;
va_start(args, format);
vprintf(format, args);
va_end(args);
}
void sigint_handler(int sig __attribute__((unused))) {
sigint_count++;
if (sigint_count == 1) {
......@@ -78,10 +90,33 @@ void print_status() {
// Protect access to active_tunnels_count with mutex
pthread_mutex_lock(&tunnel_mutex);
int tunnel_count = active_tunnels_count;
pthread_mutex_unlock(&tunnel_mutex);
printf("[STATUS] Uptime: %02d:%02d:%02d | Active tunnels: %d\n",
log_message("STATUS", "Uptime: %02d:%02d:%02d | Active tunnels: %d\n",
hours, minutes, seconds, tunnel_count);
// List active tunnels with details
for (int i = 0; i < active_tunnels_count; i++) {
tunnel_t *tunnel = active_tunnels[i];
if (tunnel && tunnel->active) {
time_t tunnel_uptime = current_time - tunnel->start_time;
unsigned long long total_data = tunnel->total_bytes_sent + tunnel->total_bytes_received;
double avg_rate = tunnel_uptime > 0 ? (double)total_data / tunnel_uptime : 0.0;
double last_rate = tunnel->bytes_last_period / 30.0;
log_message("STATUS", " Tunnel ID: %s | Client: %s | Service: %s | Uptime: %ld s | Data: %llu B (%llu sent, %llu recv) | Rate: %.2f B/s avg, %.2f B/s last\n",
tunnel->request_id,
strlen(tunnel->client_id) > 0 ? tunnel->client_id : "local",
strlen(tunnel->service) > 0 ? tunnel->service : "ssh",
tunnel_uptime,
total_data,
tunnel->total_bytes_sent,
tunnel->total_bytes_received,
avg_rate,
last_rate);
}
}
pthread_mutex_unlock(&tunnel_mutex);
}
......@@ -978,7 +1013,16 @@ int connect_to_server(const wssshc_config_t *config, service_config_t ***service
time_t last_tunnel_list_time = time(NULL);
const int tunnel_list_interval = 60; // Show tunnel list every 60 seconds
// Status printing variables
static time_t last_status_time = 0;
while (1) {
// Print status every 15 seconds
if (time(NULL) - last_status_time >= 15) {
print_status();
last_status_time = time(NULL);
}
// Check for graceful shutdown
if (graceful_shutdown) {
fprintf(stderr, "Attempting graceful shutdown of active tunnels...\n");
......@@ -1027,8 +1071,8 @@ int connect_to_server(const wssshc_config_t *config, service_config_t ***service
}
// Send keep-alive ping if needed
time_t current_time = time(NULL);
if (current_time - last_ping_time >= ping_interval) {
time_t ping_time = time(NULL);
if (ping_time - last_ping_time >= ping_interval) {
if (config->debug) {
printf("[DEBUG - WebSockets] Sending keep-alive ping\n");
fflush(stdout);
......@@ -1040,11 +1084,12 @@ int connect_to_server(const wssshc_config_t *config, service_config_t ***service
fflush(stdout);
}
} else {
last_ping_time = current_time;
last_ping_time = ping_time;
}
}
// Send tunnel keep-alive messages if needed
time_t current_time = time(NULL);
if (current_time - last_keepalive_time >= keepalive_interval) {
// Send keep-alive for all active tunnels
pthread_mutex_lock(&tunnel_mutex);
......@@ -1769,7 +1814,6 @@ int main(int argc, char *argv[]) {
printf(" Debug Mode: %s\n", config.debug ? "enabled" : "disabled");
printf("\n");
time_t last_status_time = 0;
while (1) {
// Check for graceful shutdown before attempting to reconnect
if (graceful_shutdown) {
......@@ -1788,20 +1832,13 @@ int main(int argc, char *argv[]) {
reload_configuration(&config, &services, &num_services);
}
// Print status every 15 seconds
time_t current_time = time(NULL);
if (current_time - last_status_time >= 15) {
print_status();
last_status_time = current_time;
}
int result = connect_to_server(&config, &services, &num_services);
if (result == 1) {
// Error condition - use short retry interval for immediate reconnection
if (config.debug) {
printf("Connection lost, retrying in 1 seconds...\n");
} else {
printf("[EVENT] Connection lost, retrying...\n");
log_message("EVENT", "Connection lost, retrying...\n");
}
sleep(1);
} else if (result == 0) {
......@@ -1810,7 +1847,7 @@ int main(int argc, char *argv[]) {
printf("[DEBUG - WebSockets] Server initiated disconnect, reconnecting in 1 seconds...\n");
fflush(stdout);
} else {
printf("[EVENT] Server initiated disconnect, reconnecting...\n");
log_message("EVENT", "Server initiated disconnect, reconnecting...\n");
}
sleep(1);
}
......
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment