Skip to content
Snippets Groups Projects
Commit b6cdc473 authored by Rob Swindell's avatar Rob Swindell :speech_balloon:
Browse files

Log message improvements: include protocol (HTTP vs HTTPS) and IP address

parent e672b5c9
No related branches found
No related tags found
1 merge request!463MRC mods by Codefenix (2024-10-20)
Pipeline #3206 passed
Stage: build
Hide whitespace changes
Inline Side-by-side
Showing
with 40 additions and 32 deletions
src/sbbs3/websrvr.c
+ 40
− 32
View file @ b6cdc473
......@@ -1239,8 +1239,8 @@ static BOOL send_headers(http_session_t *session, const char *status, int chunke
session->req.sent_headers=TRUE;
return(FALSE);
}
lprintf(LOG_DEBUG,"%04d Request resolved to: %s"
,session->socket,session->req.physical_path);
lprintf(LOG_DEBUG,"%04d %s [%s] Request resolved to: %s"
,session->socket, session->client.protocol, session->host_ip, session->req.physical_path);
if(session->http_ver <= HTTP_0_9) {
session->req.sent_headers=TRUE;
if(session->req.ld != NULL)
......@@ -1312,7 +1312,7 @@ static BOOL send_headers(http_session_t *session, const char *status, int chunke
/* Status-Line */
safe_snprintf(header,sizeof(header),"%s %s",response_http_vers[session->http_ver > HTTP_0_9 ? HTTP_1_1 : HTTP_0_9],status_line);
lprintf(LOG_DEBUG,"%04d Result: %s",session->socket,header);
lprintf(LOG_DEBUG,"%04d %s [%s] Result: %s", session->socket, session->client.protocol, session->host_ip, header);
safecat(headers,header,MAX_HEADERS_SIZE);
......@@ -1447,7 +1447,7 @@ static off_t sock_sendfile(http_session_t *session,char *path, off_t start, off_
uint64_t remain;
if(startup->options&WEB_OPT_DEBUG_TX)
lprintf(LOG_DEBUG,"%04d Sending %s",session->socket,path);
lprintf(LOG_DEBUG,"%04d %s [%s] Sending %s",session->socket, session->client.protocol, session->host_ip, path);
if((file=open(path,O_RDONLY|O_BINARY))==-1)
lprintf(LOG_WARNING,"%04d !ERROR %d opening %s",session->socket,errno,path);
else {
......@@ -1491,7 +1491,8 @@ static void send_error(http_session_t * session, unsigned line, const char* mess
if(session->socket==INVALID_SOCKET)
return;
session->req.if_modified_since=0;
lprintf(LOG_INFO,"%04d [%s] !ERROR: %s (line %u)",session->socket,session->host_ip,message,line);
lprintf(LOG_INFO,"%04d %s [%s] !ERROR: %s (line %u) request: %s"
,session->socket, session->client.protocol, session->host_ip, message, line, session->req.request_line);
session->req.keep_alive=FALSE;
session->req.send_location=NO_LOCATION;
SAFECOPY(error_code,message);
......@@ -1587,7 +1588,8 @@ void http_logon(http_session_t * session, user_t *usr)
if(session->user.number==session->last_user_num)
return;
lprintf(LOG_DEBUG,"%04d HTTP Logon (user #%d)",session->socket,session->user.number);
lprintf(LOG_DEBUG,"%04d %s [%s] Logon (user #%d)"
,session->socket, session->client.protocol, session->host_ip, session->user.number);
if(session->subscan!=NULL)
getmsgptrs(&scfg,&session->user,session->subscan,NULL,NULL);
......@@ -1616,8 +1618,8 @@ void http_logoff(http_session_t* session, SOCKET socket, int line)
if(session->last_user_num<=0)
return;
lprintf(LOG_DEBUG,"%04d HTTP Logoff (user #%d) from line %d"
,socket,session->user.number, line);
lprintf(LOG_DEBUG,"%04d %s [%s] Logoff (user #%d) from line %d"
,socket, session->client.protocol, session->host_ip, session->user.number, line);
SAFECOPY(session->username,unknown);
if(!logoutuserdat(&scfg, &session->user, time(NULL), session->logon_time))
......@@ -2040,8 +2042,8 @@ static BOOL check_ars(http_session_t * session)
}
/* Should go to the hack log? */
lprintf(LOG_WARNING,"%04d !AUTHORIZATION FAILURE for user %s, ARS: %s"
,session->socket,session->req.auth.username,session->req.ars);
lprintf(LOG_WARNING,"%04d %s [%s] !AUTHORIZATION FAILURE for user %s, ARS: %s"
,session->socket, session->client.protocol, session->host_ip, session->req.auth.username, session->req.ars);
#ifdef _WIN32
if(startup->sound.hack[0] && !sound_muted(&scfg))
......@@ -2314,7 +2316,8 @@ static void js_add_queryval(http_session_t * session, char *key, char *value)
alen=len;
}
lprintf(LOG_DEBUG,"%04d Adding query value %s=%s at pos %d",session->socket,key,value,alen);
lprintf(LOG_DEBUG,"%04d %s [%s] Adding query value %s=%s at pos %d"
,session->socket, session->client.protocol, session->host_ip, key,value,alen);
val=STRING_TO_JSVAL(JS_NewStringCopyZ(session->js_cx,value));
JS_SetElement(session->js_cx, keyarray, alen, &val);
}
......@@ -2345,7 +2348,8 @@ static void js_add_cookieval(http_session_t * session, char *key, char *value)
alen=len;
}
lprintf(LOG_DEBUG,"%04d Adding cookie value %s=%s at pos %d",session->socket,key,value,alen);
lprintf(LOG_DEBUG,"%04d %s [%s] Adding cookie value %s=%s at pos %d"
,session->socket, session->client.protocol, session->host_ip, key,value,alen);
val=STRING_TO_JSVAL(JS_NewStringCopyZ(session->js_cx,value));
JS_SetElement(session->js_cx, keyarray, alen, &val);
}
......@@ -3267,13 +3271,13 @@ static BOOL get_req(http_session_t * session, char *request_line)
if(len<0)
return(FALSE);
if(req_line[0])
lprintf(LOG_INFO,"%04d Request: %s",session->socket,req_line);
lprintf(LOG_INFO,"%04d %s [%s] Request: %s",session->socket, session->client.protocol, session->host_ip, req_line);
if(session->req.ld!=NULL && session->req.ld->request==NULL)
/* FREE()d in http_logging_thread() */
session->req.ld->request=strdup(req_line);
}
else {
lprintf(LOG_DEBUG,"%04d Handling Internal Redirect to: %s",session->socket,request_line);
lprintf(LOG_DEBUG,"%04d %s [%s] Handling Internal Redirect to: %s",session->socket, session->client.protocol, session->host_ip, request_line);
session->req.extra_path_info[0]=0;
SAFECOPY(req_line,request_line);
is_redir=1;
......@@ -3493,7 +3497,7 @@ static BOOL exec_js_webctrl(http_session_t* session, char *name, char* script, c
session->js_callback.counter=0;
lprintf(LOG_DEBUG,"%04d JavaScript: Compiling %s", session->socket, name);
lprintf(LOG_DEBUG,"%04d %s [%s] JavaScript: Compiling %s", session->socket, session->client.protocol, session->host_ip, name);
if(!JS_EvaluateScript(session->js_cx, session->js_glob, script, strlen(script), name, 1, &rval)) {
lprintf(LOG_WARNING,"%04d !JavaScript FAILED to compile rewrite %s:%s"
,session->socket,name,script);
......@@ -3611,7 +3615,7 @@ static BOOL check_request(http_session_t * session)
SAFECOPY(path,session->req.physical_path);
if(startup->options&WEB_OPT_DEBUG_TX)
lprintf(LOG_DEBUG,"%04d Path is: %s",session->socket,path);
lprintf(LOG_DEBUG,"%04d %s [%s] Path is: %s",session->socket, session->client.protocol, session->host_ip, path);
if(isdir(path)) {
last_ch=*lastchar(path);
if(!IS_PATH_DELIM(last_ch)) {
......@@ -3668,7 +3672,7 @@ static BOOL check_request(http_session_t * session)
session->req.keep_alive=FALSE;
send_error(session,__LINE__,"400 Bad Request");
SAFEPRINTF2(str, "Request for '%s' is outside of web root: %s", path, root_dir);
lprintf(LOG_NOTICE,"%04d !ERROR %s", session->socket, str);
lprintf(LOG_NOTICE,"%04d %s [%s] !ERROR %s", session->socket, session->client.protocol, session->host_ip, str);
hacklog(&scfg, session->client.protocol, session->username, str, session->client.host, &session->addr);
#ifdef _WIN32
if(startup->sound.hack[0] && !sound_muted(&scfg))
......@@ -4682,7 +4686,7 @@ static BOOL exec_fastcgi(http_session_t *session)
.arg = &cd
};
lprintf(LOG_INFO,"%04d Executing FastCGI: %s",session->socket,session->req.physical_path);
lprintf(LOG_INFO,"%04d %s [%s] Executing FastCGI: %s",session->socket, session->client.protocol, session->host_ip, session->req.physical_path);
if (session->req.fastcgi_socket == NULL) {
lprintf(LOG_ERR, "%04d No FastCGI socket configured!",session->socket);
return FALSE;
......@@ -4787,7 +4791,7 @@ static BOOL exec_cgi(http_session_t *session)
SAFECOPY(cmdline,session->req.physical_path);
lprintf(LOG_INFO,"%04d Executing CGI: %s",session->socket,cmdline);
lprintf(LOG_INFO,"%04d %s [%s] Executing CGI: %s",session->socket, session->client.protocol, session->host_ip, cmdline);
orig_keep=session->req.keep_alive;
session->req.keep_alive=FALSE;
......@@ -4936,8 +4940,8 @@ static BOOL exec_cgi(http_session_t *session)
done_wait = (waitpid(child,&status,WNOHANG)==child);
if(!done_wait) {
if(start)
lprintf(LOG_NOTICE,"%04d CGI Process %s still alive on client exit"
,session->socket,getfname(cmdline));
lprintf(LOG_NOTICE,"%04d %s [%s] CGI Process %s still alive on client exit"
,session->socket, session->client.protocol, session->host_ip, getfname(cmdline));
kill(child,SIGTERM);
mswait(1000);
done_wait = (waitpid(child,&status,WNOHANG)==child);
......@@ -4955,7 +4959,7 @@ static BOOL exec_cgi(http_session_t *session)
i=read(err_pipe[0],buf,sizeof(buf)-1);
if(i!=-1 && i!=0) {
buf[i]=0;
lprintf(LOG_ERR,"%04d CGI Error: %s",session->socket,buf);
lprintf(LOG_ERR,"%04d %s [%s] !CGI Error: %s",session->socket, session->client.protocol, session->host_ip, buf);
}
}
......@@ -6496,7 +6500,8 @@ void http_session_thread(void* arg)
thread_down();
return;
}
lprintf(LOG_DEBUG,"%04d Session thread started", session.socket);
session.client.protocol=session.is_tls ? "HTTPS":"HTTP";
lprintf(LOG_DEBUG,"%04d %s [%s] Session thread started", session.socket, session.client.protocol, session.host_ip);
if(startup->index_file_name==NULL || startup->cgi_ext==NULL)
lprintf(LOG_DEBUG,"%04d !!! DANGER WILL ROBINSON, DANGER !!!", session.socket);
......@@ -6568,7 +6573,8 @@ void http_session_thread(void* arg)
char host_name[128] = "";
if(!(startup->options&BBS_OPT_NO_HOST_LOOKUP)) {
getnameinfo(&session.addr.addr, session.addr_len, host_name, sizeof(host_name), NULL, 0, NI_NAMEREQD);
lprintf(LOG_INFO,"%04d Hostname: %s [%s]", session.socket, host_name[0] ? host_name : STR_NO_HOSTNAME, session.host_ip);
lprintf(LOG_INFO,"%04d %s [%s] Hostname: %s"
,session.socket, session.client.protocol, session.host_ip, host_name[0] ? host_name : STR_NO_HOSTNAME);
#if 0 /* gethostbyaddr() is apparently not (always) thread-safe
and getnameinfo() doesn't return alias information */
for(i=0;host!=NULL && host->h_aliases!=NULL
......@@ -6576,7 +6582,8 @@ void http_session_thread(void* arg)
lprintf(LOG_INFO,"%04d HostAlias: %s", session.socket, host->h_aliases[i]);
#endif
if(host_name[0] && trashcan(&scfg, host_name,"host")) {
lprintf(LOG_NOTICE,"%04d !CLIENT BLOCKED in host.can: %s", session.socket, host_name);
lprintf(LOG_NOTICE,"%04d %s [%s] !CLIENT BLOCKED in host.can: %s"
,session.socket, session.client.protocol, session.host_ip, host_name);
close_session_socket(&session);
sem_wait(&session.output_thread_terminated);
sem_destroy(&session.output_thread_terminated);
......@@ -6599,10 +6606,11 @@ void http_session_thread(void* arg)
if(banned || trashcan(&scfg,session.host_ip,"ip")) {
if(banned) {
char ban_duration[128];
lprintf(LOG_NOTICE, "%04d !TEMPORARY BAN of %s (%lu login attempts, last: %s) - remaining: %s"
,session.socket, session.host_ip, attempted.count-attempted.dupes, attempted.user, seconds_to_str(banned, ban_duration));
lprintf(LOG_NOTICE, "%04d %s !TEMPORARY BAN of %s (%lu login attempts, last: %s) - remaining: %s"
,session.socket, session.client.protocol
,session.host_ip, attempted.count-attempted.dupes, attempted.user, seconds_to_str(banned, ban_duration));
} else
lprintf(LOG_NOTICE, "%04d !CLIENT BLOCKED in ip.can: %s", session.socket, session.host_ip);
lprintf(LOG_NOTICE, "%04d %s !CLIENT BLOCKED in ip.can: %s", session.socket, session.client.protocol, session.host_ip);
close_session_socket(&session);
sem_wait(&session.output_thread_terminated);
sem_destroy(&session.output_thread_terminated);
......@@ -6619,7 +6627,6 @@ void http_session_thread(void* arg)
SAFECOPY(session.client.host, host_name);
session.client.port=inet_addrport(&session.addr);
session.client.time=time32(NULL);
session.client.protocol=session.is_tls ? "HTTPS":"HTTP";
session.client.user=session.username;
session.client.size=sizeof(session.client);
session.client.usernum = 0;
......@@ -6708,7 +6715,8 @@ void http_session_thread(void* arg)
safe_snprintf(session.redir_req,sizeof(session.redir_req),"%s %s%s%s",methods[session.req.method]
,session.req.virtual_path,session.http_ver<HTTP_1_0?"":" ",http_vers[session.http_ver]);
}
lprintf(LOG_DEBUG,"%04d Internal Redirect to: %s",socket,session.redir_req);
lprintf(LOG_DEBUG,"%04d %s [%s] Internal Redirect to: %s"
,socket, session.client.protocol, session.host_ip, session.redir_req);
redirp=session.redir_req;
}
}
......@@ -6759,8 +6767,8 @@ void http_session_thread(void* arg)
if(startup->index_file_name==NULL || startup->cgi_ext==NULL)
lprintf(LOG_DEBUG,"%04d !!! ALL YOUR BASE ARE BELONG TO US !!!", socket);
lprintf(LOG_INFO,"%04d Session thread terminated (%u clients, %u threads remain, %lu served)"
,socket, clients_remain, protected_uint32_value(thread_count), served);
lprintf(LOG_INFO,"%04d %s [%s] Session thread terminated (%u clients, %u threads remain, %lu served)"
,socket, session.client.protocol, session.host_ip, clients_remain, protected_uint32_value(thread_count), served);
}
......
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