Skip to content
Snippets Groups Projects
Commit 7b07fb0d authored by rswindell's avatar rswindell
Browse files

Added support for lprintf() with log level.

parent 7bc62c28
No related branches found
No related tags found
No related merge requests found
...@@ -132,7 +132,7 @@ BOOL dir_op(scfg_t* cfg, user_t* user, uint dirnum) ...@@ -132,7 +132,7 @@ BOOL dir_op(scfg_t* cfg, user_t* user, uint dirnum)
|| (cfg->dir[dirnum]->op_ar[0] && chk_ar(cfg,cfg->dir[dirnum]->op_ar,user))); || (cfg->dir[dirnum]->op_ar[0] && chk_ar(cfg,cfg->dir[dirnum]->op_ar,user)));
} }
static int lprintf(char *fmt, ...) static int lprintf(int level, char *fmt, ...)
{ {
int result; int result;
va_list argptr; va_list argptr;
...@@ -141,18 +141,11 @@ static int lprintf(char *fmt, ...) ...@@ -141,18 +141,11 @@ static int lprintf(char *fmt, ...)
if(startup==NULL || startup->lputs==NULL) if(startup==NULL || startup->lputs==NULL)
return(0); return(0);
#if 0 && defined(_WIN32) && defined(_DEBUG)
if(IsBadCodePtr((FARPROC)startup->lputs)) {
DebugBreak();
return(0);
}
#endif
va_start(argptr,fmt); va_start(argptr,fmt);
vsnprintf(sbuf,sizeof(sbuf),fmt,argptr); vsnprintf(sbuf,sizeof(sbuf),fmt,argptr);
sbuf[sizeof(sbuf)-1]=0; sbuf[sizeof(sbuf)-1]=0;
va_end(argptr); va_end(argptr);
result=startup->lputs(startup->cbdata,LOG_INFO,sbuf); result=startup->lputs(startup->cbdata,level,sbuf);
return(result); return(result);
} }
...@@ -167,12 +160,12 @@ static BOOL winsock_startup(void) ...@@ -167,12 +160,12 @@ static BOOL winsock_startup(void)
int status; /* Status Code */ int status; /* Status Code */
if((status = WSAStartup(MAKEWORD(1,1), &WSAData))==0) { if((status = WSAStartup(MAKEWORD(1,1), &WSAData))==0) {
lprintf("%s %s",WSAData.szDescription, WSAData.szSystemStatus); lprintf(LOG_INFO,"%s %s",WSAData.szDescription, WSAData.szSystemStatus);
WSAInitialized=TRUE; WSAInitialized=TRUE;
return (TRUE); return (TRUE);
} }
lprintf("!WinSock startup ERROR %d", status); lprintf(LOG_ERR,"!WinSock startup ERROR %d", status);
return (FALSE); return (FALSE);
} }
...@@ -231,10 +224,10 @@ static SOCKET ftp_open_socket(int type) ...@@ -231,10 +224,10 @@ static SOCKET ftp_open_socket(int type)
startup->socket_open(startup->cbdata,TRUE); startup->socket_open(startup->cbdata,TRUE);
if(sock!=INVALID_SOCKET) { if(sock!=INVALID_SOCKET) {
if(set_socket_options(&scfg, sock, error)) if(set_socket_options(&scfg, sock, error))
lprintf("%04d !ERROR %s",sock, error); lprintf(LOG_ERR,"%04d !ERROR %s",sock, error);
sockets++; sockets++;
#ifdef _DEBUG #ifdef _DEBUG
lprintf("%04d Socket opened (%u sockets in use)",sock,sockets); lprintf(LOG_DEBUG,"%04d Socket opened (%u sockets in use)",sock,sockets);
#endif #endif
} }
return(sock); return(sock);
...@@ -248,7 +241,7 @@ static int ftp_close_socket(SOCKET* sock, int line) ...@@ -248,7 +241,7 @@ static int ftp_close_socket(SOCKET* sock, int line)
int result; int result;
if((*sock)==INVALID_SOCKET) { if((*sock)==INVALID_SOCKET) {
lprintf("0000 !INVALID_SOCKET in close_socket from line %u",line); lprintf(LOG_WARNING,"0000 !INVALID_SOCKET in close_socket from line %u",line);
return(-1); return(-1);
} }
...@@ -262,12 +255,12 @@ static int ftp_close_socket(SOCKET* sock, int line) ...@@ -262,12 +255,12 @@ static int ftp_close_socket(SOCKET* sock, int line)
if(result!=0) { if(result!=0) {
if(ERROR_VALUE!=ENOTSOCK) if(ERROR_VALUE!=ENOTSOCK)
lprintf("%04d !ERROR %d closing socket from line %u",*sock,ERROR_VALUE,line); lprintf(LOG_WARNING,"%04d !ERROR %d closing socket from line %u",*sock,ERROR_VALUE,line);
} else if(sock==&server_socket || *sock==server_socket) } else if(sock==&server_socket || *sock==server_socket)
lprintf("%04d Server socket closed (%u sockets in use) from line %u",*sock,sockets,line); lprintf(LOG_DEBUG,"%04d Server socket closed (%u sockets in use) from line %u",*sock,sockets,line);
#ifdef _DEBUG #ifdef _DEBUG
else else
lprintf("%04d Socket closed (%u sockets in use) from line %u",*sock,sockets,line); lprintf(LOG_DEBUG,"%04d Socket closed (%u sockets in use) from line %u",*sock,sockets,line);
#endif #endif
*sock=INVALID_SOCKET; *sock=INVALID_SOCKET;
...@@ -287,13 +280,13 @@ static int sockprintf(SOCKET sock, char *fmt, ...) ...@@ -287,13 +280,13 @@ static int sockprintf(SOCKET sock, char *fmt, ...)
len=vsnprintf(sbuf,sizeof(sbuf),fmt,argptr); len=vsnprintf(sbuf,sizeof(sbuf),fmt,argptr);
sbuf[sizeof(sbuf)-1]=0; sbuf[sizeof(sbuf)-1]=0;
if(startup!=NULL && startup->options&FTP_OPT_DEBUG_TX) if(startup!=NULL && startup->options&FTP_OPT_DEBUG_TX)
lprintf("%04d TX: %s", sock, sbuf); lprintf(LOG_DEBUG,"%04d TX: %s", sock, sbuf);
strcat(sbuf,"\r\n"); strcat(sbuf,"\r\n");
len+=2; len+=2;
va_end(argptr); va_end(argptr);
if(sock==INVALID_SOCKET) { if(sock==INVALID_SOCKET) {
lprintf("!INVALID SOCKET in call to sockprintf"); lprintf(LOG_WARNING,"!INVALID SOCKET in call to sockprintf");
return(0); return(0);
} }
...@@ -306,10 +299,10 @@ static int sockprintf(SOCKET sock, char *fmt, ...) ...@@ -306,10 +299,10 @@ static int sockprintf(SOCKET sock, char *fmt, ...)
if((result=select(sock+1,NULL,&socket_set,NULL,&tv))<1) { if((result=select(sock+1,NULL,&socket_set,NULL,&tv))<1) {
if(result==0) if(result==0)
lprintf("%04d !TIMEOUT selecting socket for send" lprintf(LOG_WARNING,"%04d !TIMEOUT selecting socket for send"
,sock); ,sock);
else else
lprintf("%04d !ERROR %d selecting socket for send" lprintf(LOG_WARNING,"%04d !ERROR %d selecting socket for send"
,sock, ERROR_VALUE); ,sock, ERROR_VALUE);
return(0); return(0);
} }
...@@ -320,14 +313,14 @@ static int sockprintf(SOCKET sock, char *fmt, ...) ...@@ -320,14 +313,14 @@ static int sockprintf(SOCKET sock, char *fmt, ...)
continue; continue;
} }
if(ERROR_VALUE==ECONNRESET) if(ERROR_VALUE==ECONNRESET)
lprintf("%04d Connection reset by peer on send",sock); lprintf(LOG_WARNING,"%04d Connection reset by peer on send",sock);
else if(ERROR_VALUE==ECONNABORTED) else if(ERROR_VALUE==ECONNABORTED)
lprintf("%04d Connection aborted by peer on send",sock); lprintf(LOG_WARNING,"%04d Connection aborted by peer on send",sock);
else else
lprintf("%04d !ERROR %d sending",sock,ERROR_VALUE); lprintf(LOG_WARNING,"%04d !ERROR %d sending",sock,ERROR_VALUE);
return(0); return(0);
} }
lprintf("%04d !ERROR: short send: %u instead of %u",sock,result,len); lprintf(LOG_WARNING,"%04d !ERROR: short send: %u instead of %u",sock,result,len);
} }
return(len); return(len);
} }
...@@ -440,7 +433,7 @@ js_ErrorReporter(JSContext *cx, const char *message, JSErrorReport *report) ...@@ -440,7 +433,7 @@ js_ErrorReporter(JSContext *cx, const char *message, JSErrorReport *report)
fp=(FILE*)JS_GetContextPrivate(cx); fp=(FILE*)JS_GetContextPrivate(cx);
if(report==NULL) { if(report==NULL) {
lprintf("!JavaScript: %s", message); lprintf(LOG_ERR,"!JavaScript: %s", message);
if(fp!=NULL) if(fp!=NULL)
fprintf(fp,"!JavaScript: %s", message); fprintf(fp,"!JavaScript: %s", message);
return; return;
...@@ -464,7 +457,7 @@ js_ErrorReporter(JSContext *cx, const char *message, JSErrorReport *report) ...@@ -464,7 +457,7 @@ js_ErrorReporter(JSContext *cx, const char *message, JSErrorReport *report)
} else } else
warning=""; warning="";
lprintf("!JavaScript %s%s%s: %s",warning,file,line,message); lprintf(LOG_ERR,"!JavaScript %s%s%s: %s",warning,file,line,message);
if(fp!=NULL) if(fp!=NULL)
fprintf(fp,"!JavaScript %s%s%s: %s",warning,file,line,message); fprintf(fp,"!JavaScript %s%s%s: %s",warning,file,line,message);
} }
...@@ -480,26 +473,26 @@ js_initcx(JSRuntime* runtime, SOCKET sock, JSObject** glob, JSObject** ftp) ...@@ -480,26 +473,26 @@ js_initcx(JSRuntime* runtime, SOCKET sock, JSObject** glob, JSObject** ftp)
jsval val; jsval val;
BOOL success=FALSE; BOOL success=FALSE;
lprintf("%04d JavaScript: Initializing context (stack: %lu bytes)" lprintf(LOG_DEBUG,"%04d JavaScript: Initializing context (stack: %lu bytes)"
,sock,startup->js_cx_stack); ,sock,startup->js_cx_stack);
if((js_cx = JS_NewContext(runtime, startup->js_cx_stack))==NULL) if((js_cx = JS_NewContext(runtime, startup->js_cx_stack))==NULL)
return(NULL); return(NULL);
lprintf("%04d JavaScript: Context created",sock); lprintf(LOG_DEBUG,"%04d JavaScript: Context created",sock);
JS_SetErrorReporter(js_cx, js_ErrorReporter); JS_SetErrorReporter(js_cx, js_ErrorReporter);
do { do {
lprintf("%04d JavaScript: Initializing Global object",sock); lprintf(LOG_DEBUG,"%04d JavaScript: Initializing Global object",sock);
if((js_glob=js_CreateGlobalObject(js_cx, &scfg, NULL))==NULL) if((js_glob=js_CreateGlobalObject(js_cx, &scfg, NULL))==NULL)
break; break;
if (!JS_DefineFunctions(js_cx, js_glob, js_global_functions)) if (!JS_DefineFunctions(js_cx, js_glob, js_global_functions))
break; break;
lprintf("%04d JavaScript: Initializing System object",sock); lprintf(LOG_DEBUG,"%04d JavaScript: Initializing System object",sock);
if(js_CreateSystemObject(js_cx, js_glob, &scfg, uptime, startup->host_name)==NULL) if(js_CreateSystemObject(js_cx, js_glob, &scfg, uptime, startup->host_name)==NULL)
break; break;
...@@ -653,26 +646,26 @@ BOOL js_generate_index(JSContext* js_cx, JSObject* parent, ...@@ -653,26 +646,26 @@ BOOL js_generate_index(JSContext* js_cx, JSObject* parent,
do { /* pseudo try/catch */ do { /* pseudo try/catch */
if((file_array=JS_NewArrayObject(js_cx, 0, NULL))==NULL) { if((file_array=JS_NewArrayObject(js_cx, 0, NULL))==NULL) {
lprintf("%04d !JavaScript FAILED to create file_array",sock); lprintf(LOG_ERR,"%04d !JavaScript FAILED to create file_array",sock);
break; break;
} }
/* file[] */ /* file[] */
val=OBJECT_TO_JSVAL(file_array); val=OBJECT_TO_JSVAL(file_array);
if(!JS_SetProperty(js_cx, parent, "file_list", &val)) { if(!JS_SetProperty(js_cx, parent, "file_list", &val)) {
lprintf("%04d !JavaScript FAILED to set file property",sock); lprintf(LOG_ERR,"%04d !JavaScript FAILED to set file property",sock);
break; break;
} }
if((dir_array=JS_NewArrayObject(js_cx, 0, NULL))==NULL) { if((dir_array=JS_NewArrayObject(js_cx, 0, NULL))==NULL) {
lprintf("%04d !JavaScript FAILED to create dir_array",sock); lprintf(LOG_ERR,"%04d !JavaScript FAILED to create dir_array",sock);
break; break;
} }
/* dir[] */ /* dir[] */
val=OBJECT_TO_JSVAL(dir_array); val=OBJECT_TO_JSVAL(dir_array);
if(!JS_SetProperty(js_cx, parent, "dir_list", &val)) { if(!JS_SetProperty(js_cx, parent, "dir_list", &val)) {
lprintf("%04d !JavaScript FAILED to set dir property",sock); lprintf(LOG_ERR,"%04d !JavaScript FAILED to set dir property",sock);
break; break;
} }
...@@ -687,7 +680,7 @@ BOOL js_generate_index(JSContext* js_cx, JSObject* parent, ...@@ -687,7 +680,7 @@ BOOL js_generate_index(JSContext* js_cx, JSObject* parent,
strcat(spath,".js"); strcat(spath,".js");
if(!fexist(spath)) { if(!fexist(spath)) {
lprintf("%04d !HTML JavaScript (%s) doesn't exist",sock,spath); lprintf(LOG_ERR,"%04d !HTML JavaScript (%s) doesn't exist",sock,spath);
break; break;
} }
...@@ -695,31 +688,31 @@ BOOL js_generate_index(JSContext* js_cx, JSObject* parent, ...@@ -695,31 +688,31 @@ BOOL js_generate_index(JSContext* js_cx, JSObject* parent,
break; break;
val=STRING_TO_JSVAL(js_str); val=STRING_TO_JSVAL(js_str);
if(!JS_SetProperty(js_cx, parent, "html_index_file", &val)) { if(!JS_SetProperty(js_cx, parent, "html_index_file", &val)) {
lprintf("%04d !JavaScript FAILED to set html_index_file property",sock); lprintf(LOG_ERR,"%04d !JavaScript FAILED to set html_index_file property",sock);
break; break;
} }
/* curlib */ /* curlib */
if((lib_obj=JS_NewObject(js_cx, NULL, 0, NULL))==NULL) { if((lib_obj=JS_NewObject(js_cx, NULL, 0, NULL))==NULL) {
lprintf("%04d !JavaScript FAILED to create lib_obj",sock); lprintf(LOG_ERR,"%04d !JavaScript FAILED to create lib_obj",sock);
break; break;
} }
val=OBJECT_TO_JSVAL(lib_obj); val=OBJECT_TO_JSVAL(lib_obj);
if(!JS_SetProperty(js_cx, parent, "curlib", &val)) { if(!JS_SetProperty(js_cx, parent, "curlib", &val)) {
lprintf("%04d !JavaScript FAILED to set curlib property",sock); lprintf(LOG_ERR,"%04d !JavaScript FAILED to set curlib property",sock);
break; break;
} }
/* curdir */ /* curdir */
if((dir_obj=JS_NewObject(js_cx, NULL, 0, NULL))==NULL) { if((dir_obj=JS_NewObject(js_cx, NULL, 0, NULL))==NULL) {
lprintf("%04d !JavaScript FAILED to create dir_obj",sock); lprintf(LOG_ERR,"%04d !JavaScript FAILED to create dir_obj",sock);
break; break;
} }
val=OBJECT_TO_JSVAL(dir_obj); val=OBJECT_TO_JSVAL(dir_obj);
if(!JS_SetProperty(js_cx, parent, "curdir", &val)) { if(!JS_SetProperty(js_cx, parent, "curdir", &val)) {
lprintf("%04d !JavaScript FAILED to set curdir property",sock); lprintf(LOG_ERR,"%04d !JavaScript FAILED to set curdir property",sock);
break; break;
} }
...@@ -734,7 +727,7 @@ BOOL js_generate_index(JSContext* js_cx, JSObject* parent, ...@@ -734,7 +727,7 @@ BOOL js_generate_index(JSContext* js_cx, JSObject* parent,
break; break;
val=STRING_TO_JSVAL(js_str); val=STRING_TO_JSVAL(js_str);
if(!JS_SetProperty(js_cx, lib_obj, "name", &val)) { if(!JS_SetProperty(js_cx, lib_obj, "name", &val)) {
lprintf("%04d !JavaScript FAILED to set curlib.name property",sock); lprintf(LOG_ERR,"%04d !JavaScript FAILED to set curlib.name property",sock);
break; break;
} }
...@@ -742,7 +735,7 @@ BOOL js_generate_index(JSContext* js_cx, JSObject* parent, ...@@ -742,7 +735,7 @@ BOOL js_generate_index(JSContext* js_cx, JSObject* parent,
break; break;
val=STRING_TO_JSVAL(js_str); val=STRING_TO_JSVAL(js_str);
if(!JS_SetProperty(js_cx, lib_obj, "description", &val)) { if(!JS_SetProperty(js_cx, lib_obj, "description", &val)) {
lprintf("%04d !JavaScript FAILED to set curlib.desc property",sock); lprintf(LOG_ERR,"%04d !JavaScript FAILED to set curlib.desc property",sock);
break; break;
} }
} }
...@@ -755,7 +748,7 @@ BOOL js_generate_index(JSContext* js_cx, JSObject* parent, ...@@ -755,7 +748,7 @@ BOOL js_generate_index(JSContext* js_cx, JSObject* parent,
break; break;
val=STRING_TO_JSVAL(js_str); val=STRING_TO_JSVAL(js_str);
if(!JS_SetProperty(js_cx, dir_obj, "code", &val)) { if(!JS_SetProperty(js_cx, dir_obj, "code", &val)) {
lprintf("%04d !JavaScript FAILED to set curdir.code property",sock); lprintf(LOG_ERR,"%04d !JavaScript FAILED to set curdir.code property",sock);
break; break;
} }
...@@ -763,7 +756,7 @@ BOOL js_generate_index(JSContext* js_cx, JSObject* parent, ...@@ -763,7 +756,7 @@ BOOL js_generate_index(JSContext* js_cx, JSObject* parent,
break; break;
val=STRING_TO_JSVAL(js_str); val=STRING_TO_JSVAL(js_str);
if(!JS_SetProperty(js_cx, dir_obj, "name", &val)) { if(!JS_SetProperty(js_cx, dir_obj, "name", &val)) {
lprintf("%04d !JavaScript FAILED to set curdir.name property",sock); lprintf(LOG_ERR,"%04d !JavaScript FAILED to set curdir.name property",sock);
break; break;
} }
...@@ -771,13 +764,13 @@ BOOL js_generate_index(JSContext* js_cx, JSObject* parent, ...@@ -771,13 +764,13 @@ BOOL js_generate_index(JSContext* js_cx, JSObject* parent,
break; break;
val=STRING_TO_JSVAL(js_str); val=STRING_TO_JSVAL(js_str);
if(!JS_SetProperty(js_cx, dir_obj, "description", &val)) { if(!JS_SetProperty(js_cx, dir_obj, "description", &val)) {
lprintf("%04d !JavaScript FAILED to set curdir.desc property",sock); lprintf(LOG_ERR,"%04d !JavaScript FAILED to set curdir.desc property",sock);
break; break;
} }
val=INT_TO_JSVAL(scfg.dir[dir]->misc); val=INT_TO_JSVAL(scfg.dir[dir]->misc);
if(!JS_SetProperty(js_cx, dir_obj, "settings", &val)) { if(!JS_SetProperty(js_cx, dir_obj, "settings", &val)) {
lprintf("%04d !JavaScript FAILED to set curdir.misc property",sock); lprintf(LOG_ERR,"%04d !JavaScript FAILED to set curdir.misc property",sock);
break; break;
} }
} }
...@@ -786,7 +779,7 @@ BOOL js_generate_index(JSContext* js_cx, JSObject* parent, ...@@ -786,7 +779,7 @@ BOOL js_generate_index(JSContext* js_cx, JSObject* parent,
break; break;
val=STRING_TO_JSVAL(js_str); val=STRING_TO_JSVAL(js_str);
if(!JS_SetProperty(js_cx, parent, "path", &val)) { if(!JS_SetProperty(js_cx, parent, "path", &val)) {
lprintf("%04d !JavaScript FAILED to set curdir property",sock); lprintf(LOG_ERR,"%04d !JavaScript FAILED to set curdir property",sock);
break; break;
} }
...@@ -980,12 +973,12 @@ BOOL js_generate_index(JSContext* js_cx, JSObject* parent, ...@@ -980,12 +973,12 @@ BOOL js_generate_index(JSContext* js_cx, JSObject* parent,
JS_ClearPendingException(js_cx); JS_ClearPendingException(js_cx);
if((js_script=JS_CompileFile(js_cx, parent, spath))==NULL) { if((js_script=JS_CompileFile(js_cx, parent, spath))==NULL) {
lprintf("%04d !JavaScript FAILED to compile script (%s)",sock,spath); lprintf(LOG_ERR,"%04d !JavaScript FAILED to compile script (%s)",sock,spath);
break; break;
} }
if((success=JS_ExecuteScript(js_cx, parent, js_script, &rval))!=TRUE) { if((success=JS_ExecuteScript(js_cx, parent, js_script, &rval))!=TRUE) {
lprintf("%04d !JavaScript FAILED to execute script (%s)",sock,spath); lprintf(LOG_ERR,"%04d !JavaScript FAILED to execute script (%s)",sock,spath);
break; break;
} }
...@@ -1098,20 +1091,20 @@ BOOL download_stats(ulong bytes) ...@@ -1098,20 +1091,20 @@ BOOL download_stats(ulong bytes)
void recverror(SOCKET socket, int rd, int line) void recverror(SOCKET socket, int rd, int line)
{ {
if(rd==0) if(rd==0)
lprintf("%04d Socket closed by peer on receive (line %u)" lprintf(LOG_WARNING,"%04d Socket closed by peer on receive (line %u)"
,socket, line); ,socket, line);
else if(rd==SOCKET_ERROR) { else if(rd==SOCKET_ERROR) {
if(ERROR_VALUE==ECONNRESET) if(ERROR_VALUE==ECONNRESET)
lprintf("%04d Connection reset by peer on receive (line %u)" lprintf(LOG_WARNING,"%04d Connection reset by peer on receive (line %u)"
,socket, line); ,socket, line);
else if(ERROR_VALUE==ECONNABORTED) else if(ERROR_VALUE==ECONNABORTED)
lprintf("%04d Connection aborted by peer on receive (line %u)" lprintf(LOG_WARNING,"%04d Connection aborted by peer on receive (line %u)"
,socket, line); ,socket, line);
else else
lprintf("%04d !ERROR %d receiving on socket (line %u)" lprintf(LOG_WARNING,"%04d !ERROR %d receiving on socket (line %u)"
,socket, ERROR_VALUE, line); ,socket, ERROR_VALUE, line);
} else } else
lprintf("%04d !ERROR: recv on socket returned unexpected value: %d (line %u)" lprintf(LOG_ERR,"%04d !ERROR: recv on socket returned unexpected value: %d (line %u)"
,socket, rd, line); ,socket, rd, line);
} }
...@@ -1125,7 +1118,7 @@ int sockreadline(SOCKET socket, char* buf, int len, time_t* lastactive) ...@@ -1125,7 +1118,7 @@ int sockreadline(SOCKET socket, char* buf, int len, time_t* lastactive)
buf[0]=0; buf[0]=0;
if(socket==INVALID_SOCKET) { if(socket==INVALID_SOCKET) {
lprintf("INVALID SOCKET in call to sockreadline"); lprintf(LOG_WARNING,"INVALID SOCKET in call to sockreadline");
return(0); return(0);
} }
...@@ -1141,13 +1134,13 @@ int sockreadline(SOCKET socket, char* buf, int len, time_t* lastactive) ...@@ -1141,13 +1134,13 @@ int sockreadline(SOCKET socket, char* buf, int len, time_t* lastactive)
if(server_socket==INVALID_SOCKET) { if(server_socket==INVALID_SOCKET) {
sockprintf(socket,"421 Server downed, aborting."); sockprintf(socket,"421 Server downed, aborting.");
lprintf("%04d Server downed, aborting",socket); lprintf(LOG_WARNING,"%04d Server downed, aborting",socket);
return(0); return(0);
} }
if(i<1) { if(i<1) {
if(i==0) { if(i==0) {
if((time(NULL)-(*lastactive))>startup->max_inactivity) { if((time(NULL)-(*lastactive))>startup->max_inactivity) {
lprintf("%04d Disconnecting due to to inactivity",socket); lprintf(LOG_WARNING,"%04d Disconnecting due to to inactivity",socket);
sockprintf(socket,"421 Disconnecting due to inactivity (%u seconds)." sockprintf(socket,"421 Disconnecting due to inactivity (%u seconds)."
,startup->max_inactivity); ,startup->max_inactivity);
return(0); return(0);
...@@ -1314,7 +1307,7 @@ void DLLCALL ftp_terminate(void) ...@@ -1314,7 +1307,7 @@ void DLLCALL ftp_terminate(void)
{ {
recycle_server=FALSE; recycle_server=FALSE;
if(server_socket!=INVALID_SOCKET) { if(server_socket!=INVALID_SOCKET) {
lprintf("%04d FTP Terminate: closing socket",server_socket); lprintf(LOG_DEBUG,"%04d FTP Terminate: closing socket",server_socket);
ftp_close_socket(&server_socket,__LINE__); ftp_close_socket(&server_socket,__LINE__);
} }
} }
...@@ -1375,7 +1368,7 @@ static void send_thread(void* arg) ...@@ -1375,7 +1368,7 @@ static void send_thread(void* arg)
length=flength(xfer.filename); length=flength(xfer.filename);
if((fp=fopen(xfer.filename,"rb"))==NULL) { if((fp=fopen(xfer.filename,"rb"))==NULL) {
lprintf("%04d !DATA ERROR %d opening %s",xfer.ctrl_sock,errno,xfer.filename); lprintf(LOG_ERR,"%04d !DATA ERROR %d opening %s",xfer.ctrl_sock,errno,xfer.filename);
sockprintf(xfer.ctrl_sock,"450 ERROR %d opening %s.",errno,xfer.filename); sockprintf(xfer.ctrl_sock,"450 ERROR %d opening %s.",errno,xfer.filename);
if(xfer.tmpfile && !(startup->options&FTP_OPT_KEEP_TEMP_FILES)) if(xfer.tmpfile && !(startup->options&FTP_OPT_KEEP_TEMP_FILES))
remove(xfer.filename); remove(xfer.filename);
...@@ -1391,7 +1384,7 @@ static void send_thread(void* arg) ...@@ -1391,7 +1384,7 @@ static void send_thread(void* arg)
*xfer.aborted=FALSE; *xfer.aborted=FALSE;
if(startup->options&FTP_OPT_DEBUG_DATA || xfer.filepos) if(startup->options&FTP_OPT_DEBUG_DATA || xfer.filepos)
lprintf("%04d DATA socket %d sending %s from offset %lu" lprintf(LOG_DEBUG,"%04d DATA socket %d sending %s from offset %lu"
,xfer.ctrl_sock,*xfer.data_sock,xfer.filename,xfer.filepos); ,xfer.ctrl_sock,*xfer.data_sock,xfer.filename,xfer.filepos);
fseek(fp,xfer.filepos,SEEK_SET); fseek(fp,xfer.filepos,SEEK_SET);
...@@ -1406,7 +1399,7 @@ static void send_thread(void* arg) ...@@ -1406,7 +1399,7 @@ static void send_thread(void* arg)
sprintf(str," from offset %lu",xfer.filepos); sprintf(str," from offset %lu",xfer.filepos);
else else
str[0]=0; str[0]=0;
lprintf("%04d Sent %lu bytes (%lu total) of %s (%lu cps)%s" lprintf(LOG_INFO,"%04d Sent %lu bytes (%lu total) of %s (%lu cps)%s"
,xfer.ctrl_sock,total,length,xfer.filename ,xfer.ctrl_sock,total,length,xfer.filename
,(total-last_total)/(now-last_report) ,(total-last_total)/(now-last_report)
,str); ,str);
...@@ -1415,13 +1408,13 @@ static void send_thread(void* arg) ...@@ -1415,13 +1408,13 @@ static void send_thread(void* arg)
} }
if(*xfer.aborted==TRUE) { if(*xfer.aborted==TRUE) {
lprintf("%04d !DATA Transfer aborted",xfer.ctrl_sock); lprintf(LOG_WARNING,"%04d !DATA Transfer aborted",xfer.ctrl_sock);
sockprintf(xfer.ctrl_sock,"426 Transfer aborted."); sockprintf(xfer.ctrl_sock,"426 Transfer aborted.");
error=TRUE; error=TRUE;
break; break;
} }
if(server_socket==INVALID_SOCKET) { if(server_socket==INVALID_SOCKET) {
lprintf("%04d !DATA Transfer locally aborted",xfer.ctrl_sock); lprintf(LOG_WARNING,"%04d !DATA Transfer locally aborted",xfer.ctrl_sock);
sockprintf(xfer.ctrl_sock,"426 Transfer locally aborted."); sockprintf(xfer.ctrl_sock,"426 Transfer locally aborted.");
error=TRUE; error=TRUE;
break; break;
...@@ -1436,7 +1429,7 @@ static void send_thread(void* arg) ...@@ -1436,7 +1429,7 @@ static void send_thread(void* arg)
i=select((*xfer.data_sock)+1,NULL,&socket_set,NULL,&tv); i=select((*xfer.data_sock)+1,NULL,&socket_set,NULL,&tv);
if(i==SOCKET_ERROR) { if(i==SOCKET_ERROR) {
lprintf("%04d !DATA ERROR %d selecting socket %d for send" lprintf(LOG_WARNING,"%04d !DATA ERROR %d selecting socket %d for send"
,xfer.ctrl_sock, ERROR_VALUE, *xfer.data_sock); ,xfer.ctrl_sock, ERROR_VALUE, *xfer.data_sock);
sockprintf(xfer.ctrl_sock,"426 Transfer error."); sockprintf(xfer.ctrl_sock,"426 Transfer error.");
error=TRUE; error=TRUE;
...@@ -1460,18 +1453,18 @@ static void send_thread(void* arg) ...@@ -1460,18 +1453,18 @@ static void send_thread(void* arg)
if(wr<1) { if(wr<1) {
if(wr==SOCKET_ERROR) { if(wr==SOCKET_ERROR) {
if(ERROR_VALUE==EWOULDBLOCK) { if(ERROR_VALUE==EWOULDBLOCK) {
/*lprintf("%04d DATA send would block, retrying",xfer.ctrl_sock);*/ /*lprintf(LOG_WARNING,"%04d DATA send would block, retrying",xfer.ctrl_sock);*/
YIELD(); YIELD();
continue; continue;
} }
else if(ERROR_VALUE==ECONNRESET) else if(ERROR_VALUE==ECONNRESET)
lprintf("%04d DATA Connection reset by peer, sending on socket %d" lprintf(LOG_WARNING,"%04d DATA Connection reset by peer, sending on socket %d"
,xfer.ctrl_sock,*xfer.data_sock); ,xfer.ctrl_sock,*xfer.data_sock);
else if(ERROR_VALUE==ECONNABORTED) else if(ERROR_VALUE==ECONNABORTED)
lprintf("%04d DATA Connection aborted by peer, sending on socket %d" lprintf(LOG_WARNING,"%04d DATA Connection aborted by peer, sending on socket %d"
,xfer.ctrl_sock,*xfer.data_sock); ,xfer.ctrl_sock,*xfer.data_sock);
else else
lprintf("%04d !DATA ERROR %d sending on data socket %d" lprintf(LOG_WARNING,"%04d !DATA ERROR %d sending on data socket %d"
,xfer.ctrl_sock,ERROR_VALUE,*xfer.data_sock); ,xfer.ctrl_sock,ERROR_VALUE,*xfer.data_sock);
/* Send NAK */ /* Send NAK */
sockprintf(xfer.ctrl_sock,"426 Error %d sending on DATA channel" sockprintf(xfer.ctrl_sock,"426 Error %d sending on DATA channel"
...@@ -1480,12 +1473,12 @@ static void send_thread(void* arg) ...@@ -1480,12 +1473,12 @@ static void send_thread(void* arg)
break; break;
} }
if(wr==0) { if(wr==0) {
lprintf("%04d !DATA socket %d disconnected",xfer.ctrl_sock, *xfer.data_sock); lprintf(LOG_WARNING,"%04d !DATA socket %d disconnected",xfer.ctrl_sock, *xfer.data_sock);
sockprintf(xfer.ctrl_sock,"426 DATA channel disconnected"); sockprintf(xfer.ctrl_sock,"426 DATA channel disconnected");
error=TRUE; error=TRUE;
break; break;
} }
lprintf("%04d !DATA SEND ERROR %d (%d) on socket %d" lprintf(LOG_ERR,"%04d !DATA SEND ERROR %d (%d) on socket %d"
,xfer.ctrl_sock, wr, ERROR_VALUE, *xfer.data_sock); ,xfer.ctrl_sock, wr, ERROR_VALUE, *xfer.data_sock);
sockprintf(xfer.ctrl_sock,"451 DATA send error"); sockprintf(xfer.ctrl_sock,"451 DATA send error");
error=TRUE; error=TRUE;
...@@ -1497,16 +1490,16 @@ static void send_thread(void* arg) ...@@ -1497,16 +1490,16 @@ static void send_thread(void* arg)
} }
if((i=ferror(fp))!=0) if((i=ferror(fp))!=0)
lprintf("%04d !FILE ERROR %d (%d)",xfer.ctrl_sock,i,errno); lprintf(LOG_ERR,"%04d !FILE ERROR %d (%d)",xfer.ctrl_sock,i,errno);
ftp_close_socket(xfer.data_sock,__LINE__); /* Signal end of file */ ftp_close_socket(xfer.data_sock,__LINE__); /* Signal end of file */
if(startup->options&FTP_OPT_DEBUG_DATA) if(startup->options&FTP_OPT_DEBUG_DATA)
lprintf("%04d DATA socket closed",xfer.ctrl_sock); lprintf(LOG_DEBUG,"%04d DATA socket closed",xfer.ctrl_sock);
if(!error) { if(!error) {
dur=time(NULL)-start; dur=time(NULL)-start;
cps=dur ? total/dur : total*2; cps=dur ? total/dur : total*2;
lprintf("%04d Transfer successful: %lu bytes sent in %lu seconds (%lu cps)" lprintf(LOG_INFO,"%04d Transfer successful: %lu bytes sent in %lu seconds (%lu cps)"
,xfer.ctrl_sock ,xfer.ctrl_sock
,total,dur,cps); ,total,dur,cps);
sockprintf(xfer.ctrl_sock,"226 Download complete (%lu cps).",cps); sockprintf(xfer.ctrl_sock,"226 Download complete (%lu cps).",cps);
...@@ -1524,7 +1517,7 @@ static void send_thread(void* arg) ...@@ -1524,7 +1517,7 @@ static void send_thread(void* arg)
if(getfileixb(&scfg,&f)==TRUE && getfiledat(&scfg,&f)==TRUE) { if(getfileixb(&scfg,&f)==TRUE && getfiledat(&scfg,&f)==TRUE) {
f.timesdled++; f.timesdled++;
putfiledat(&scfg,&f); putfiledat(&scfg,&f);
lprintf("%04d %s downloaded: %s (%lu times total)" lprintf(LOG_INFO,"%04d %s downloaded: %s (%lu times total)"
,xfer.ctrl_sock ,xfer.ctrl_sock
,xfer.user->alias ,xfer.user->alias
,xfer.filename ,xfer.filename
...@@ -1630,7 +1623,7 @@ static void receive_thread(void* arg) ...@@ -1630,7 +1623,7 @@ static void receive_thread(void* arg)
thread_up(TRUE /* setuid */); thread_up(TRUE /* setuid */);
if((fp=fopen(xfer.filename,xfer.append ? "ab" : "wb"))==NULL) { if((fp=fopen(xfer.filename,xfer.append ? "ab" : "wb"))==NULL) {
lprintf("%04d !DATA ERROR %d opening %s",xfer.ctrl_sock,errno,xfer.filename); lprintf(LOG_ERR,"%04d !DATA ERROR %d opening %s",xfer.ctrl_sock,errno,xfer.filename);
sockprintf(xfer.ctrl_sock,"450 ERROR %d opening %s.",errno,xfer.filename); sockprintf(xfer.ctrl_sock,"450 ERROR %d opening %s.",errno,xfer.filename);
ftp_close_socket(xfer.data_sock,__LINE__); ftp_close_socket(xfer.data_sock,__LINE__);
*xfer.inprogress=FALSE; *xfer.inprogress=FALSE;
...@@ -1643,7 +1636,7 @@ static void receive_thread(void* arg) ...@@ -1643,7 +1636,7 @@ static void receive_thread(void* arg)
*xfer.aborted=FALSE; *xfer.aborted=FALSE;
if(xfer.filepos || startup->options&FTP_OPT_DEBUG_DATA) if(xfer.filepos || startup->options&FTP_OPT_DEBUG_DATA)
lprintf("%04d DATA socket %d receiving %s from offset %lu" lprintf(LOG_DEBUG,"%04d DATA socket %d receiving %s from offset %lu"
,xfer.ctrl_sock,*xfer.data_sock,xfer.filename,xfer.filepos); ,xfer.ctrl_sock,*xfer.data_sock,xfer.filename,xfer.filepos);
fseek(fp,xfer.filepos,SEEK_SET); fseek(fp,xfer.filepos,SEEK_SET);
...@@ -1658,7 +1651,7 @@ static void receive_thread(void* arg) ...@@ -1658,7 +1651,7 @@ static void receive_thread(void* arg)
sprintf(str," from offset %lu",xfer.filepos); sprintf(str," from offset %lu",xfer.filepos);
else else
str[0]=0; str[0]=0;
lprintf("%04d Received %lu bytes of %s (%lu cps)%s" lprintf(LOG_INFO,"%04d Received %lu bytes of %s (%lu cps)%s"
,xfer.ctrl_sock,total,xfer.filename ,xfer.ctrl_sock,total,xfer.filename
,(total-last_total)/(now-last_report) ,(total-last_total)/(now-last_report)
,str); ,str);
...@@ -1666,14 +1659,14 @@ static void receive_thread(void* arg) ...@@ -1666,14 +1659,14 @@ static void receive_thread(void* arg)
last_report=now; last_report=now;
} }
if(*xfer.aborted==TRUE) { if(*xfer.aborted==TRUE) {
lprintf("%04d !DATA Transfer aborted",xfer.ctrl_sock); lprintf(LOG_WARNING,"%04d !DATA Transfer aborted",xfer.ctrl_sock);
/* Send NAK */ /* Send NAK */
sockprintf(xfer.ctrl_sock,"426 Transfer aborted."); sockprintf(xfer.ctrl_sock,"426 Transfer aborted.");
error=TRUE; error=TRUE;
break; break;
} }
if(server_socket==INVALID_SOCKET) { if(server_socket==INVALID_SOCKET) {
lprintf("%04d !DATA Transfer locally aborted",xfer.ctrl_sock); lprintf(LOG_WARNING,"%04d !DATA Transfer locally aborted",xfer.ctrl_sock);
/* Send NAK */ /* Send NAK */
sockprintf(xfer.ctrl_sock,"426 Transfer locally aborted."); sockprintf(xfer.ctrl_sock,"426 Transfer locally aborted.");
error=TRUE; error=TRUE;
...@@ -1689,7 +1682,7 @@ static void receive_thread(void* arg) ...@@ -1689,7 +1682,7 @@ static void receive_thread(void* arg)
i=select((*xfer.data_sock)+1,&socket_set,NULL,NULL,&tv); i=select((*xfer.data_sock)+1,&socket_set,NULL,NULL,&tv);
if(i==SOCKET_ERROR) { if(i==SOCKET_ERROR) {
lprintf("%04d !DATA ERROR %d selecting socket %d for receive" lprintf(LOG_WARNING,"%04d !DATA ERROR %d selecting socket %d for receive"
,xfer.ctrl_sock, ERROR_VALUE, *xfer.data_sock); ,xfer.ctrl_sock, ERROR_VALUE, *xfer.data_sock);
sockprintf(xfer.ctrl_sock,"426 Transfer error."); sockprintf(xfer.ctrl_sock,"426 Transfer error.");
error=TRUE; error=TRUE;
...@@ -1708,24 +1701,24 @@ static void receive_thread(void* arg) ...@@ -1708,24 +1701,24 @@ static void receive_thread(void* arg)
if(rd<1) { if(rd<1) {
if(rd==0) { /* Socket closed */ if(rd==0) { /* Socket closed */
if(startup->options&FTP_OPT_DEBUG_DATA) if(startup->options&FTP_OPT_DEBUG_DATA)
lprintf("%04d DATA socket %d closed by client" lprintf(LOG_DEBUG,"%04d DATA socket %d closed by client"
,xfer.ctrl_sock,*xfer.data_sock); ,xfer.ctrl_sock,*xfer.data_sock);
break; break;
} }
if(rd==SOCKET_ERROR) { if(rd==SOCKET_ERROR) {
if(ERROR_VALUE==EWOULDBLOCK) { if(ERROR_VALUE==EWOULDBLOCK) {
/*lprintf("%04d DATA recv would block, retrying",xfer.ctrl_sock);*/ /*lprintf(LOG_WARNING,"%04d DATA recv would block, retrying",xfer.ctrl_sock);*/
YIELD(); YIELD();
continue; continue;
} }
else if(ERROR_VALUE==ECONNRESET) else if(ERROR_VALUE==ECONNRESET)
lprintf("%04d DATA Connection reset by peer, receiving on socket %d" lprintf(LOG_WARNING,"%04d DATA Connection reset by peer, receiving on socket %d"
,xfer.ctrl_sock,*xfer.data_sock); ,xfer.ctrl_sock,*xfer.data_sock);
else if(ERROR_VALUE==ECONNABORTED) else if(ERROR_VALUE==ECONNABORTED)
lprintf("%04d DATA Connection aborted by peer, receiving on socket %d" lprintf(LOG_WARNING,"%04d DATA Connection aborted by peer, receiving on socket %d"
,xfer.ctrl_sock,*xfer.data_sock); ,xfer.ctrl_sock,*xfer.data_sock);
else else
lprintf("%04d !DATA ERROR %d receiving on data socket %d" lprintf(LOG_WARNING,"%04d !DATA ERROR %d receiving on data socket %d"
,xfer.ctrl_sock,ERROR_VALUE,*xfer.data_sock); ,xfer.ctrl_sock,ERROR_VALUE,*xfer.data_sock);
/* Send NAK */ /* Send NAK */
sockprintf(xfer.ctrl_sock,"426 Error %d receiving on DATA channel" sockprintf(xfer.ctrl_sock,"426 Error %d receiving on DATA channel"
...@@ -1733,7 +1726,7 @@ static void receive_thread(void* arg) ...@@ -1733,7 +1726,7 @@ static void receive_thread(void* arg)
error=TRUE; error=TRUE;
break; break;
} }
lprintf("%04d !DATA ERROR recv returned %d on socket %d" lprintf(LOG_ERR,"%04d !DATA ERROR recv returned %d on socket %d"
,xfer.ctrl_sock,rd,*xfer.data_sock); ,xfer.ctrl_sock,rd,*xfer.data_sock);
/* Send NAK */ /* Send NAK */
sockprintf(xfer.ctrl_sock,"451 Unexpected socket error: %d",rd); sockprintf(xfer.ctrl_sock,"451 Unexpected socket error: %d",rd);
...@@ -1752,12 +1745,12 @@ static void receive_thread(void* arg) ...@@ -1752,12 +1745,12 @@ static void receive_thread(void* arg)
ftp_close_socket(xfer.data_sock,__LINE__); ftp_close_socket(xfer.data_sock,__LINE__);
if(error && startup->options&FTP_OPT_DEBUG_DATA) if(error && startup->options&FTP_OPT_DEBUG_DATA)
lprintf("%04d DATA socket %d closed",xfer.ctrl_sock,*xfer.data_sock); lprintf(LOG_DEBUG,"%04d DATA socket %d closed",xfer.ctrl_sock,*xfer.data_sock);
if(!error) { if(!error) {
dur=time(NULL)-start; dur=time(NULL)-start;
cps=dur ? total/dur : total*2; cps=dur ? total/dur : total*2;
lprintf("%04d Transfer successful: %lu bytes received in %lu seconds (%lu cps)" lprintf(LOG_INFO,"%04d Transfer successful: %lu bytes received in %lu seconds (%lu cps)"
,xfer.ctrl_sock ,xfer.ctrl_sock
,total,dur,cps); ,total,dur,cps);
...@@ -1828,11 +1821,11 @@ static void receive_thread(void* arg) ...@@ -1828,11 +1821,11 @@ static void receive_thread(void* arg)
SAFECOPY(f.uler,xfer.user->alias); /* exception here, Aug-27-2002 */ SAFECOPY(f.uler,xfer.user->alias); /* exception here, Aug-27-2002 */
if(filedat) { if(filedat) {
if(!putfiledat(&scfg,&f)) if(!putfiledat(&scfg,&f))
lprintf("%04d !ERROR updating file (%s) in database",xfer.ctrl_sock,f.name); lprintf(LOG_ERR,"%04d !ERROR updating file (%s) in database",xfer.ctrl_sock,f.name);
/* need to update the index here */ /* need to update the index here */
} else { } else {
if(!addfiledat(&scfg,&f)) if(!addfiledat(&scfg,&f))
lprintf("%04d !ERROR adding file (%s) to database",xfer.ctrl_sock,f.name); lprintf(LOG_ERR,"%04d !ERROR adding file (%s) to database",xfer.ctrl_sock,f.name);
} }
if(f.misc&FM_EXTDESC) if(f.misc&FM_EXTDESC)
...@@ -1887,7 +1880,7 @@ static void filexfer(SOCKADDR_IN* addr, SOCKET ctrl_sock, SOCKET pasv_sock, SOCK ...@@ -1887,7 +1880,7 @@ static void filexfer(SOCKADDR_IN* addr, SOCKET ctrl_sock, SOCKET pasv_sock, SOCK
fd_set socket_set; fd_set socket_set;
if((*inprogress)==TRUE) { if((*inprogress)==TRUE) {
lprintf("%04d !TRANSFER already in progress",ctrl_sock); lprintf(LOG_WARNING,"%04d !TRANSFER already in progress",ctrl_sock);
sockprintf(ctrl_sock,"425 Transfer already in progress."); sockprintf(ctrl_sock,"425 Transfer already in progress.");
return; return;
} }
...@@ -1899,7 +1892,7 @@ static void filexfer(SOCKADDR_IN* addr, SOCKET ctrl_sock, SOCKET pasv_sock, SOCK ...@@ -1899,7 +1892,7 @@ static void filexfer(SOCKADDR_IN* addr, SOCKET ctrl_sock, SOCKET pasv_sock, SOCK
if(pasv_sock==INVALID_SOCKET) { /* !PASV */ if(pasv_sock==INVALID_SOCKET) { /* !PASV */
if((*data_sock=socket(AF_INET, SOCK_STREAM, IPPROTO_IP)) == INVALID_SOCKET) { if((*data_sock=socket(AF_INET, SOCK_STREAM, IPPROTO_IP)) == INVALID_SOCKET) {
lprintf("%04d !DATA ERROR %d opening socket", ctrl_sock, ERROR_VALUE); lprintf(LOG_ERR,"%04d !DATA ERROR %d opening socket", ctrl_sock, ERROR_VALUE);
sockprintf(ctrl_sock,"425 Error %d opening socket",ERROR_VALUE); sockprintf(ctrl_sock,"425 Error %d opening socket",ERROR_VALUE);
if(tmpfile) if(tmpfile)
remove(filename); remove(filename);
...@@ -1910,7 +1903,7 @@ static void filexfer(SOCKADDR_IN* addr, SOCKET ctrl_sock, SOCKET pasv_sock, SOCK ...@@ -1910,7 +1903,7 @@ static void filexfer(SOCKADDR_IN* addr, SOCKET ctrl_sock, SOCKET pasv_sock, SOCK
startup->socket_open(startup->cbdata,TRUE); startup->socket_open(startup->cbdata,TRUE);
sockets++; sockets++;
if(startup->options&FTP_OPT_DEBUG_DATA) if(startup->options&FTP_OPT_DEBUG_DATA)
lprintf("%04d DATA socket %d opened",ctrl_sock,*data_sock); lprintf(LOG_DEBUG,"%04d DATA socket %d opened",ctrl_sock,*data_sock);
/* Use port-1 for all data connections */ /* Use port-1 for all data connections */
reuseaddr=TRUE; reuseaddr=TRUE;
...@@ -1928,7 +1921,7 @@ static void filexfer(SOCKADDR_IN* addr, SOCKET ctrl_sock, SOCKET pasv_sock, SOCK ...@@ -1928,7 +1921,7 @@ static void filexfer(SOCKADDR_IN* addr, SOCKET ctrl_sock, SOCKET pasv_sock, SOCK
result=bind(*data_sock, (struct sockaddr *) &server_addr,sizeof(server_addr)); result=bind(*data_sock, (struct sockaddr *) &server_addr,sizeof(server_addr));
} }
if(result!=0) { if(result!=0) {
lprintf ("%04d !DATA ERROR %d (%d) binding socket %d" lprintf(LOG_ERR,"%04d !DATA ERROR %d (%d) binding socket %d"
,ctrl_sock, result, ERROR_VALUE, *data_sock); ,ctrl_sock, result, ERROR_VALUE, *data_sock);
sockprintf(ctrl_sock,"425 Error %d binding socket",ERROR_VALUE); sockprintf(ctrl_sock,"425 Error %d binding socket",ERROR_VALUE);
if(tmpfile) if(tmpfile)
...@@ -1940,7 +1933,7 @@ static void filexfer(SOCKADDR_IN* addr, SOCKET ctrl_sock, SOCKET pasv_sock, SOCK ...@@ -1940,7 +1933,7 @@ static void filexfer(SOCKADDR_IN* addr, SOCKET ctrl_sock, SOCKET pasv_sock, SOCK
result=connect(*data_sock, (struct sockaddr *)addr,sizeof(struct sockaddr)); result=connect(*data_sock, (struct sockaddr *)addr,sizeof(struct sockaddr));
if(result!=0) { if(result!=0) {
lprintf("%04d !DATA ERROR %d (%d) connecting to client %s port %u on socket %d" lprintf(LOG_WARNING,"%04d !DATA ERROR %d (%d) connecting to client %s port %u on socket %d"
,ctrl_sock,result,ERROR_VALUE ,ctrl_sock,result,ERROR_VALUE
,inet_ntoa(addr->sin_addr),ntohs(addr->sin_port),*data_sock); ,inet_ntoa(addr->sin_addr),ntohs(addr->sin_port),*data_sock);
sockprintf(ctrl_sock,"425 Error %d connecting to socket",ERROR_VALUE); sockprintf(ctrl_sock,"425 Error %d connecting to socket",ERROR_VALUE);
...@@ -1951,13 +1944,13 @@ static void filexfer(SOCKADDR_IN* addr, SOCKET ctrl_sock, SOCKET pasv_sock, SOCK ...@@ -1951,13 +1944,13 @@ static void filexfer(SOCKADDR_IN* addr, SOCKET ctrl_sock, SOCKET pasv_sock, SOCK
return; return;
} }
if(startup->options&FTP_OPT_DEBUG_DATA) if(startup->options&FTP_OPT_DEBUG_DATA)
lprintf("%04d DATA socket %d connected to %s port %u" lprintf(LOG_DEBUG,"%04d DATA socket %d connected to %s port %u"
,ctrl_sock,*data_sock,inet_ntoa(addr->sin_addr),ntohs(addr->sin_port)); ,ctrl_sock,*data_sock,inet_ntoa(addr->sin_addr),ntohs(addr->sin_port));
} else { /* PASV */ } else { /* PASV */
if(startup->options&FTP_OPT_DEBUG_DATA) if(startup->options&FTP_OPT_DEBUG_DATA)
lprintf("%04d PASV DATA socket %d listening on %s port %u" lprintf(LOG_DEBUG,"%04d PASV DATA socket %d listening on %s port %u"
,ctrl_sock,pasv_sock,inet_ntoa(addr->sin_addr),ntohs(addr->sin_port)); ,ctrl_sock,pasv_sock,inet_ntoa(addr->sin_addr),ntohs(addr->sin_port));
/* Setup for select() */ /* Setup for select() */
...@@ -1975,7 +1968,7 @@ static void filexfer(SOCKADDR_IN* addr, SOCKET ctrl_sock, SOCKET pasv_sock, SOCK ...@@ -1975,7 +1968,7 @@ static void filexfer(SOCKADDR_IN* addr, SOCKET ctrl_sock, SOCKET pasv_sock, SOCK
socket_debug[ctrl_sock]&=~SOCKET_DEBUG_SELECT; socket_debug[ctrl_sock]&=~SOCKET_DEBUG_SELECT;
#endif #endif
if(result<1) { if(result<1) {
lprintf("%04d !PASV select returned %d (error: %d)",ctrl_sock,result,ERROR_VALUE); lprintf(LOG_WARNING,"%04d !PASV select returned %d (error: %d)",ctrl_sock,result,ERROR_VALUE);
sockprintf(ctrl_sock,"425 Error %d selecting socket for connection",ERROR_VALUE); sockprintf(ctrl_sock,"425 Error %d selecting socket for connection",ERROR_VALUE);
if(tmpfile) if(tmpfile)
remove(filename); remove(filename);
...@@ -1992,7 +1985,7 @@ static void filexfer(SOCKADDR_IN* addr, SOCKET ctrl_sock, SOCKET pasv_sock, SOCK ...@@ -1992,7 +1985,7 @@ static void filexfer(SOCKADDR_IN* addr, SOCKET ctrl_sock, SOCKET pasv_sock, SOCK
socket_debug[ctrl_sock]&=~SOCKET_DEBUG_ACCEPT; socket_debug[ctrl_sock]&=~SOCKET_DEBUG_ACCEPT;
#endif #endif
if(*data_sock==INVALID_SOCKET) { if(*data_sock==INVALID_SOCKET) {
lprintf("%04d !PASV DATA ERROR %d accepting connection on socket %d" lprintf(LOG_WARNING,"%04d !PASV DATA ERROR %d accepting connection on socket %d"
,ctrl_sock,ERROR_VALUE,pasv_sock); ,ctrl_sock,ERROR_VALUE,pasv_sock);
sockprintf(ctrl_sock,"425 Error %d accepting connection",ERROR_VALUE); sockprintf(ctrl_sock,"425 Error %d accepting connection",ERROR_VALUE);
if(tmpfile) if(tmpfile)
...@@ -2004,7 +1997,7 @@ static void filexfer(SOCKADDR_IN* addr, SOCKET ctrl_sock, SOCKET pasv_sock, SOCK ...@@ -2004,7 +1997,7 @@ static void filexfer(SOCKADDR_IN* addr, SOCKET ctrl_sock, SOCKET pasv_sock, SOCK
startup->socket_open(startup->cbdata,TRUE); startup->socket_open(startup->cbdata,TRUE);
sockets++; sockets++;
if(startup->options&FTP_OPT_DEBUG_DATA) if(startup->options&FTP_OPT_DEBUG_DATA)
lprintf("%04d PASV DATA socket %d connected to %s port %u" lprintf(LOG_DEBUG,"%04d PASV DATA socket %d connected to %s port %u"
,ctrl_sock,*data_sock,inet_ntoa(addr->sin_addr),ntohs(addr->sin_port)); ,ctrl_sock,*data_sock,inet_ntoa(addr->sin_addr),ntohs(addr->sin_port));
} }
...@@ -2013,7 +2006,7 @@ static void filexfer(SOCKADDR_IN* addr, SOCKET ctrl_sock, SOCKET pasv_sock, SOCK ...@@ -2013,7 +2006,7 @@ static void filexfer(SOCKADDR_IN* addr, SOCKET ctrl_sock, SOCKET pasv_sock, SOCK
l=1; l=1;
if(ioctlsocket(*data_sock, FIONBIO, &l)!=0) { if(ioctlsocket(*data_sock, FIONBIO, &l)!=0) {
lprintf("%04d !DATA ERROR %d disabling socket blocking" lprintf(LOG_ERR,"%04d !DATA ERROR %d disabling socket blocking"
,ctrl_sock, ERROR_VALUE); ,ctrl_sock, ERROR_VALUE);
sockprintf(ctrl_sock,"425 Error %d disabling socket blocking" sockprintf(ctrl_sock,"425 Error %d disabling socket blocking"
,ERROR_VALUE); ,ERROR_VALUE);
...@@ -2021,7 +2014,7 @@ static void filexfer(SOCKADDR_IN* addr, SOCKET ctrl_sock, SOCKET pasv_sock, SOCK ...@@ -2021,7 +2014,7 @@ static void filexfer(SOCKADDR_IN* addr, SOCKET ctrl_sock, SOCKET pasv_sock, SOCK
} }
if((xfer=malloc(sizeof(xfer_t)))==NULL) { if((xfer=malloc(sizeof(xfer_t)))==NULL) {
lprintf("%04d !MALLOC FAILURE LINE %d",ctrl_sock,__LINE__); lprintf(LOG_CRIT,"%04d !MALLOC FAILURE LINE %d",ctrl_sock,__LINE__);
sockprintf(ctrl_sock,"425 MALLOC FAILURE"); sockprintf(ctrl_sock,"425 MALLOC FAILURE");
break; break;
} }
...@@ -2210,7 +2203,7 @@ static BOOL ftpalias(char* fullalias, char* filename, user_t* user, int* curdir) ...@@ -2210,7 +2203,7 @@ static BOOL ftpalias(char* fullalias, char* filename, user_t* user, int* curdir)
if(!strnicmp(p,BBS_VIRTUAL_PATH,strlen(BBS_VIRTUAL_PATH))) { if(!strnicmp(p,BBS_VIRTUAL_PATH,strlen(BBS_VIRTUAL_PATH))) {
if((dir=getdir(p+strlen(BBS_VIRTUAL_PATH),user))<0) { if((dir=getdir(p+strlen(BBS_VIRTUAL_PATH),user))<0) {
lprintf("0000 !Invalid virtual path (%s) for %s",p,user->alias); lprintf(LOG_WARNING,"0000 !Invalid virtual path (%s) for %s",p,user->alias);
/* invalid or no access */ /* invalid or no access */
continue; continue;
} }
...@@ -2383,7 +2376,7 @@ static void ctrl_thread(void* arg) ...@@ -2383,7 +2376,7 @@ static void ctrl_thread(void* arg)
data_addr.sin_port=ntohs(data_addr.sin_port)-1; data_addr.sin_port=ntohs(data_addr.sin_port)-1;
data_addr.sin_port=htons(data_addr.sin_port); data_addr.sin_port=htons(data_addr.sin_port);
lprintf("%04d CTRL thread started", sock); lprintf(LOG_DEBUG,"%04d CTRL thread started", sock);
free(arg); /* unexplicable assertion here on July 26, 2001 */ free(arg); /* unexplicable assertion here on July 26, 2001 */
...@@ -2398,7 +2391,7 @@ static void ctrl_thread(void* arg) ...@@ -2398,7 +2391,7 @@ static void ctrl_thread(void* arg)
l=1; l=1;
if((i=ioctlsocket(sock, FIONBIO, &l))!=0) { if((i=ioctlsocket(sock, FIONBIO, &l))!=0) {
lprintf("%04d !ERROR %d (%d) disabling socket blocking" lprintf(LOG_ERR,"%04d !ERROR %d (%d) disabling socket blocking"
,sock, i, ERROR_VALUE); ,sock, i, ERROR_VALUE);
sockprintf(sock,"425 Error %d disabling socket blocking" sockprintf(sock,"425 Error %d disabling socket blocking"
,ERROR_VALUE); ,ERROR_VALUE);
...@@ -2411,7 +2404,7 @@ static void ctrl_thread(void* arg) ...@@ -2411,7 +2404,7 @@ static void ctrl_thread(void* arg)
SAFECOPY(host_ip,inet_ntoa(ftp.client_addr.sin_addr)); SAFECOPY(host_ip,inet_ntoa(ftp.client_addr.sin_addr));
lprintf ("%04d CTRL connection accepted from: %s port %u" lprintf(LOG_DEBUG,"%04d CTRL connection accepted from: %s port %u"
,sock, host_ip, ntohs(ftp.client_addr.sin_port)); ,sock, host_ip, ntohs(ftp.client_addr.sin_port));
if(startup->options&FTP_OPT_NO_HOST_LOOKUP) if(startup->options&FTP_OPT_NO_HOST_LOOKUP)
...@@ -2426,13 +2419,13 @@ static void ctrl_thread(void* arg) ...@@ -2426,13 +2419,13 @@ static void ctrl_thread(void* arg)
host_name="<no name>"; host_name="<no name>";
if(!(startup->options&FTP_OPT_NO_HOST_LOOKUP)) { if(!(startup->options&FTP_OPT_NO_HOST_LOOKUP)) {
lprintf("%04d Hostname: %s", sock, host_name); lprintf(LOG_INFO,"%04d Hostname: %s", sock, host_name);
for(i=0;host!=NULL && host->h_aliases!=NULL && host->h_aliases[i]!=NULL;i++) for(i=0;host!=NULL && host->h_aliases!=NULL && host->h_aliases[i]!=NULL;i++)
lprintf("%04d HostAlias: %s", sock, host->h_aliases[i]); lprintf(LOG_INFO,"%04d HostAlias: %s", sock, host->h_aliases[i]);
} }
if(trashcan(&scfg,host_ip,"ip")) { if(trashcan(&scfg,host_ip,"ip")) {
lprintf("%04d !CLIENT BLOCKED in ip.can: %s", sock, host_ip); lprintf(LOG_WARNING,"%04d !CLIENT BLOCKED in ip.can: %s", sock, host_ip);
sockprintf(sock,"550 Access denied."); sockprintf(sock,"550 Access denied.");
ftp_close_socket(&sock,__LINE__); ftp_close_socket(&sock,__LINE__);
thread_down(); thread_down();
...@@ -2440,7 +2433,7 @@ static void ctrl_thread(void* arg) ...@@ -2440,7 +2433,7 @@ static void ctrl_thread(void* arg)
} }
if(trashcan(&scfg,host_name,"host")) { if(trashcan(&scfg,host_name,"host")) {
lprintf("%04d !CLIENT BLOCKED in host.can: %s", sock, host_name); lprintf(LOG_WARNING,"%04d !CLIENT BLOCKED in host.can: %s", sock, host_name);
sockprintf(sock,"550 Access denied."); sockprintf(sock,"550 Access denied.");
ftp_close_socket(&sock,__LINE__); ftp_close_socket(&sock,__LINE__);
thread_down(); thread_down();
...@@ -2450,7 +2443,7 @@ static void ctrl_thread(void* arg) ...@@ -2450,7 +2443,7 @@ static void ctrl_thread(void* arg)
/* For PASV mode */ /* For PASV mode */
addr_len=sizeof(pasv_addr); addr_len=sizeof(pasv_addr);
if((result=getsockname(sock, (struct sockaddr *)&pasv_addr,&addr_len))!=0) { if((result=getsockname(sock, (struct sockaddr *)&pasv_addr,&addr_len))!=0) {
lprintf("%04d !ERROR %d (%d) getting address/port", sock, result, ERROR_VALUE); lprintf(LOG_ERR,"%04d !ERROR %d (%d) getting address/port", sock, result, ERROR_VALUE);
sockprintf(sock,"425 Error %d getting address/port",ERROR_VALUE); sockprintf(sock,"425 Error %d getting address/port",ERROR_VALUE);
ftp_close_socket(&sock,__LINE__); ftp_close_socket(&sock,__LINE__);
thread_down(); thread_down();
...@@ -2498,7 +2491,7 @@ static void ctrl_thread(void* arg) ...@@ -2498,7 +2491,7 @@ static void ctrl_thread(void* arg)
#endif #endif
if(rd<1) { if(rd<1) {
if(transfer_inprogress==TRUE) { if(transfer_inprogress==TRUE) {
lprintf("%04d Aborting transfer due to receive error",sock); lprintf(LOG_WARNING,"%04d Aborting transfer due to receive error",sock);
transfer_aborted=TRUE; transfer_aborted=TRUE;
} }
break; break;
...@@ -2508,17 +2501,17 @@ static void ctrl_thread(void* arg) ...@@ -2508,17 +2501,17 @@ static void ctrl_thread(void* arg)
cmd=buf; cmd=buf;
while(((BYTE)*cmd)==TELNET_IAC) { while(((BYTE)*cmd)==TELNET_IAC) {
cmd++; cmd++;
lprintf("%04d RX: Telnet cmd: %s",sock,telnet_cmd_desc(*cmd)); lprintf(LOG_DEBUG,"%04d RX: Telnet cmd: %s",sock,telnet_cmd_desc(*cmd));
cmd++; cmd++;
} }
while(*cmd && *cmd<' ') { while(*cmd && *cmd<' ') {
lprintf("%04d RX: %d (0x%02X)",sock,(BYTE)*cmd,(BYTE)*cmd); lprintf(LOG_DEBUG,"%04d RX: %d (0x%02X)",sock,(BYTE)*cmd,(BYTE)*cmd);
cmd++; cmd++;
} }
if(!(*cmd)) if(!(*cmd))
continue; continue;
if(startup->options&FTP_OPT_DEBUG_RX) if(startup->options&FTP_OPT_DEBUG_RX)
lprintf("%04d RX: %s", sock, cmd); lprintf(LOG_DEBUG,"%04d RX: %s", sock, cmd);
if(!stricmp(cmd, "NOOP")) { if(!stricmp(cmd, "NOOP")) {
sockprintf(sock,"200 NOOP command successful."); sockprintf(sock,"200 NOOP command successful.");
continue; continue;
...@@ -2603,22 +2596,22 @@ static void ctrl_thread(void* arg) ...@@ -2603,22 +2596,22 @@ static void ctrl_thread(void* arg)
user.number=matchuser(&scfg,user.alias,FALSE /*sysop_alias*/); user.number=matchuser(&scfg,user.alias,FALSE /*sysop_alias*/);
if(!user.number) { if(!user.number) {
if(scfg.sys_misc&SM_ECHO_PW) if(scfg.sys_misc&SM_ECHO_PW)
lprintf("%04d !UNKNOWN USER: %s, Password: %s",sock,user.alias,p); lprintf(LOG_WARNING,"%04d !UNKNOWN USER: %s, Password: %s",sock,user.alias,p);
else else
lprintf("%04d !UNKNOWN USER: %s",sock,user.alias); lprintf(LOG_WARNING,"%04d !UNKNOWN USER: %s",sock,user.alias);
if(badlogin(sock,&login_attempts)) if(badlogin(sock,&login_attempts))
break; break;
continue; continue;
} }
if((i=getuserdat(&scfg, &user))!=0) { if((i=getuserdat(&scfg, &user))!=0) {
lprintf("%04d !ERROR %d getting data for user #%d (%s)" lprintf(LOG_ERR,"%04d !ERROR %d getting data for user #%d (%s)"
,sock,i,user.number,user.alias); ,sock,i,user.number,user.alias);
sockprintf(sock,"530 Database error %d",i); sockprintf(sock,"530 Database error %d",i);
user.number=0; user.number=0;
continue; continue;
} }
if(user.misc&(DELETED|INACTIVE)) { if(user.misc&(DELETED|INACTIVE)) {
lprintf("%04d !DELETED or INACTIVE user #%d (%s)" lprintf(LOG_WARNING,"%04d !DELETED or INACTIVE user #%d (%s)"
,sock,user.number,user.alias); ,sock,user.number,user.alias);
user.number=0; user.number=0;
if(badlogin(sock,&login_attempts)) if(badlogin(sock,&login_attempts))
...@@ -2626,7 +2619,7 @@ static void ctrl_thread(void* arg) ...@@ -2626,7 +2619,7 @@ static void ctrl_thread(void* arg)
continue; continue;
} }
if(user.rest&FLAG('T')) { if(user.rest&FLAG('T')) {
lprintf("%04d !T RESTRICTED user #%d (%s)" lprintf(LOG_WARNING,"%04d !T RESTRICTED user #%d (%s)"
,sock,user.number,user.alias); ,sock,user.number,user.alias);
user.number=0; user.number=0;
if(badlogin(sock,&login_attempts)) if(badlogin(sock,&login_attempts))
...@@ -2635,14 +2628,14 @@ static void ctrl_thread(void* arg) ...@@ -2635,14 +2628,14 @@ static void ctrl_thread(void* arg)
} }
if(user.ltoday>scfg.level_callsperday[user.level] if(user.ltoday>scfg.level_callsperday[user.level]
&& !(user.exempt&FLAG('L'))) { && !(user.exempt&FLAG('L'))) {
lprintf("%04d !MAXIMUM LOGONS (%d) reached for %s" lprintf(LOG_WARNING,"%04d !MAXIMUM LOGONS (%d) reached for %s"
,sock,scfg.level_callsperday[user.level],user.alias); ,sock,scfg.level_callsperday[user.level],user.alias);
sockprintf(sock,"530 Maximum logons reached."); sockprintf(sock,"530 Maximum logons reached.");
user.number=0; user.number=0;
continue; continue;
} }
if(user.rest&FLAG('L') && user.ltoday>1) { if(user.rest&FLAG('L') && user.ltoday>1) {
lprintf("%04d !L RESTRICTED user #%d (%s) already on today" lprintf(LOG_WARNING,"%04d !L RESTRICTED user #%d (%s) already on today"
,sock,user.number,user.alias); ,sock,user.number,user.alias);
sockprintf(sock,"530 Maximum logons reached."); sockprintf(sock,"530 Maximum logons reached.");
user.number=0; user.number=0;
...@@ -2652,25 +2645,25 @@ static void ctrl_thread(void* arg) ...@@ -2652,25 +2645,25 @@ static void ctrl_thread(void* arg)
sprintf(sys_pass,"%s:%s",user.pass,scfg.sys_pass); sprintf(sys_pass,"%s:%s",user.pass,scfg.sys_pass);
if(!user.pass[0]) { /* Guest/Anonymous */ if(!user.pass[0]) { /* Guest/Anonymous */
if(trashcan(&scfg,password,"email")) { if(trashcan(&scfg,password,"email")) {
lprintf("%04d !BLOCKED e-mail address: %s",sock,password); lprintf(LOG_WARNING,"%04d !BLOCKED e-mail address: %s",sock,password);
user.number=0; user.number=0;
if(badlogin(sock,&login_attempts)) if(badlogin(sock,&login_attempts))
break; break;
continue; continue;
} }
lprintf("%04d %s: <%s>",sock,user.alias,password); lprintf(LOG_INFO,"%04d %s: <%s>",sock,user.alias,password);
putuserrec(&scfg,user.number,U_NETMAIL,LEN_NETMAIL,password); putuserrec(&scfg,user.number,U_NETMAIL,LEN_NETMAIL,password);
} }
else if(user.level>=SYSOP_LEVEL && !stricmp(password,sys_pass)) { else if(user.level>=SYSOP_LEVEL && !stricmp(password,sys_pass)) {
lprintf("%04d Sysop access granted to %s", sock, user.alias); lprintf(LOG_INFO,"%04d Sysop access granted to %s", sock, user.alias);
sysop=TRUE; sysop=TRUE;
} }
else if(stricmp(password,user.pass)) { else if(stricmp(password,user.pass)) {
if(scfg.sys_misc&SM_ECHO_PW) if(scfg.sys_misc&SM_ECHO_PW)
lprintf("%04d !FAILED Password attempt for user %s: '%s' expected '%s'" lprintf(LOG_WARNING,"%04d !FAILED Password attempt for user %s: '%s' expected '%s'"
,sock, user.alias, password, user.pass); ,sock, user.alias, password, user.pass);
else else
lprintf("%04d !FAILED Password attempt for user %s" lprintf(LOG_WARNING,"%04d !FAILED Password attempt for user %s"
,sock, user.alias); ,sock, user.alias);
user.number=0; user.number=0;
if(badlogin(sock,&login_attempts)) if(badlogin(sock,&login_attempts))
...@@ -2688,7 +2681,7 @@ static void ctrl_thread(void* arg) ...@@ -2688,7 +2681,7 @@ static void ctrl_thread(void* arg)
client_on(sock,&client,TRUE /* update */); client_on(sock,&client,TRUE /* update */);
lprintf("%04d %s logged in",sock,user.alias); lprintf(LOG_INFO,"%04d %s logged in",sock,user.alias);
logintime=time(NULL); logintime=time(NULL);
timeleft=gettimeleft(&scfg,&user,logintime); timeleft=gettimeleft(&scfg,&user,logintime);
sprintf(str,"%sftphello.txt",scfg.text_dir); sprintf(str,"%sftphello.txt",scfg.text_dir);
...@@ -2712,17 +2705,17 @@ static void ctrl_thread(void* arg) ...@@ -2712,17 +2705,17 @@ static void ctrl_thread(void* arg)
if(js_cx!=NULL) { if(js_cx!=NULL) {
if(js_CreateUserClass(js_cx, js_glob, &scfg)==NULL) if(js_CreateUserClass(js_cx, js_glob, &scfg)==NULL)
lprintf("%04d !JavaScript ERROR creating user class",sock); lprintf(LOG_ERR,"%04d !JavaScript ERROR creating user class",sock);
if(js_CreateUserObject(js_cx, js_glob, &scfg, "user", user.number)==NULL) if(js_CreateUserObject(js_cx, js_glob, &scfg, "user", user.number)==NULL)
lprintf("%04d !JavaScript ERROR creating user object",sock); lprintf(LOG_ERR,"%04d !JavaScript ERROR creating user object",sock);
if(js_CreateClientObject(js_cx, js_glob, "client", &client, sock)==NULL) if(js_CreateClientObject(js_cx, js_glob, "client", &client, sock)==NULL)
lprintf("%04d !JavaScript ERROR creating client object",sock); lprintf(LOG_ERR,"%04d !JavaScript ERROR creating client object",sock);
if(js_CreateFileAreaObject(js_cx, js_glob, &scfg, &user if(js_CreateFileAreaObject(js_cx, js_glob, &scfg, &user
,startup->html_index_file)==NULL) ,startup->html_index_file)==NULL)
lprintf("%04d !JavaScript ERROR creating file area object",sock); lprintf(LOG_ERR,"%04d !JavaScript ERROR creating file area object",sock);
} }
#endif #endif
...@@ -2758,7 +2751,7 @@ static void ctrl_thread(void* arg) ...@@ -2758,7 +2751,7 @@ static void ctrl_thread(void* arg)
if((timeleft=gettimeleft(&scfg,&user,logintime))<1L) { if((timeleft=gettimeleft(&scfg,&user,logintime))<1L) {
sockprintf(sock,"421 Sorry, you've run out of time."); sockprintf(sock,"421 Sorry, you've run out of time.");
lprintf("%04d Out of time, disconnecting",sock); lprintf(LOG_WARNING,"%04d Out of time, disconnecting",sock);
break; break;
} }
...@@ -2767,7 +2760,7 @@ static void ctrl_thread(void* arg) ...@@ -2767,7 +2760,7 @@ static void ctrl_thread(void* arg)
/********************************/ /********************************/
if(!stricmp(cmd, "REIN")) { if(!stricmp(cmd, "REIN")) {
lprintf("%04d %s reinitialized control session",sock,user.alias); lprintf(LOG_INFO,"%04d %s reinitialized control session",sock,user.alias);
user.number=0; user.number=0;
sysop=FALSE; sysop=FALSE;
filepos=0; filepos=0;
...@@ -2846,7 +2839,7 @@ static void ctrl_thread(void* arg) ...@@ -2846,7 +2839,7 @@ static void ctrl_thread(void* arg)
data_addr.sin_addr.s_addr=htonl((h1<<24)|(h2<<16)|(h3<<8)|h4); data_addr.sin_addr.s_addr=htonl((h1<<24)|(h2<<16)|(h3<<8)|h4);
data_addr.sin_port=(u_short)((p1<<8)|p2); data_addr.sin_port=(u_short)((p1<<8)|p2);
if(data_addr.sin_port<1024) { if(data_addr.sin_port<1024) {
lprintf("%04d !SUSPECTED BOUNCE ATTACK ATTEMPT by %s to %s port %u" lprintf(LOG_WARNING,"%04d !SUSPECTED BOUNCE ATTACK ATTEMPT by %s to %s port %u"
,sock,user.alias ,sock,user.alias
,inet_ntoa(data_addr.sin_addr),data_addr.sin_port); ,inet_ntoa(data_addr.sin_addr),data_addr.sin_port);
hacklog(&scfg, "FTP", user.alias, cmd, host_name, &ftp.client_addr); hacklog(&scfg, "FTP", user.alias, cmd, host_name, &ftp.client_addr);
...@@ -2868,19 +2861,19 @@ static void ctrl_thread(void* arg) ...@@ -2868,19 +2861,19 @@ static void ctrl_thread(void* arg)
ftp_close_socket(&pasv_sock,__LINE__); ftp_close_socket(&pasv_sock,__LINE__);
if((pasv_sock=ftp_open_socket(SOCK_STREAM))==INVALID_SOCKET) { if((pasv_sock=ftp_open_socket(SOCK_STREAM))==INVALID_SOCKET) {
lprintf("%04d !PASV ERROR %d opening socket", sock,ERROR_VALUE); lprintf(LOG_WARNING,"%04d !PASV ERROR %d opening socket", sock,ERROR_VALUE);
sockprintf(sock,"425 Error %d opening PASV data socket", ERROR_VALUE); sockprintf(sock,"425 Error %d opening PASV data socket", ERROR_VALUE);
continue; continue;
} }
if(startup->options&FTP_OPT_DEBUG_DATA) if(startup->options&FTP_OPT_DEBUG_DATA)
lprintf("%04d PASV DATA socket %d opened",sock,pasv_sock); lprintf(LOG_DEBUG,"%04d PASV DATA socket %d opened",sock,pasv_sock);
pasv_addr.sin_port = 0; pasv_addr.sin_port = 0;
result=bind(pasv_sock, (struct sockaddr *) &pasv_addr,sizeof(pasv_addr)); result=bind(pasv_sock, (struct sockaddr *) &pasv_addr,sizeof(pasv_addr));
if(result!= 0) { if(result!= 0) {
lprintf("%04d !PASV ERROR %d (%d) binding socket", sock, result, ERROR_VALUE); lprintf(LOG_ERR,"%04d !PASV ERROR %d (%d) binding socket", sock, result, ERROR_VALUE);
sockprintf(sock,"425 Error %d binding data socket",ERROR_VALUE); sockprintf(sock,"425 Error %d binding data socket",ERROR_VALUE);
ftp_close_socket(&pasv_sock,__LINE__); ftp_close_socket(&pasv_sock,__LINE__);
continue; continue;
...@@ -2888,14 +2881,14 @@ static void ctrl_thread(void* arg) ...@@ -2888,14 +2881,14 @@ static void ctrl_thread(void* arg)
addr_len=sizeof(addr); addr_len=sizeof(addr);
if((result=getsockname(pasv_sock, (struct sockaddr *)&addr,&addr_len))!=0) { if((result=getsockname(pasv_sock, (struct sockaddr *)&addr,&addr_len))!=0) {
lprintf("%04d !PASV ERROR %d (%d) getting address/port", sock, result, ERROR_VALUE); lprintf(LOG_ERR,"%04d !PASV ERROR %d (%d) getting address/port", sock, result, ERROR_VALUE);
sockprintf(sock,"425 Error %d getting address/port",ERROR_VALUE); sockprintf(sock,"425 Error %d getting address/port",ERROR_VALUE);
ftp_close_socket(&pasv_sock,__LINE__); ftp_close_socket(&pasv_sock,__LINE__);
continue; continue;
} }
if((result=listen(pasv_sock, 1))!= 0) { if((result=listen(pasv_sock, 1))!= 0) {
lprintf("%04d !PASV ERROR %d (%d) listening on socket", sock, result, ERROR_VALUE); lprintf(LOG_ERR,"%04d !PASV ERROR %d (%d) listening on socket", sock, result, ERROR_VALUE);
sockprintf(sock,"425 Error %d listening on data socket",ERROR_VALUE); sockprintf(sock,"425 Error %d listening on data socket",ERROR_VALUE);
ftp_close_socket(&pasv_sock,__LINE__); ftp_close_socket(&pasv_sock,__LINE__);
continue; continue;
...@@ -2978,7 +2971,7 @@ static void ctrl_thread(void* arg) ...@@ -2978,7 +2971,7 @@ static void ctrl_thread(void* arg)
if(!transfer_inprogress) if(!transfer_inprogress)
sockprintf(sock,"226 No tranfer in progress."); sockprintf(sock,"226 No tranfer in progress.");
else { else {
lprintf("%04d %s aborting transfer" lprintf(LOG_WARNING,"%04d %s aborting transfer"
,sock,user.alias); ,sock,user.alias);
transfer_aborted=TRUE; transfer_aborted=TRUE;
YIELD(); /* give send thread time to abort */ YIELD(); /* give send thread time to abort */
...@@ -2995,7 +2988,7 @@ static void ctrl_thread(void* arg) ...@@ -2995,7 +2988,7 @@ static void ctrl_thread(void* arg)
else { else {
if(!direxist(p)) { if(!direxist(p)) {
sockprintf(sock,"550 Directory does not exist."); sockprintf(sock,"550 Directory does not exist.");
lprintf("%04d !%s attempted to mount invalid directory: %s" lprintf(LOG_WARNING,"%04d !%s attempted to mount invalid directory: %s"
,sock, user.alias, p); ,sock, user.alias, p);
continue; continue;
} }
...@@ -3004,7 +2997,7 @@ static void ctrl_thread(void* arg) ...@@ -3004,7 +2997,7 @@ static void ctrl_thread(void* arg)
} }
sockprintf(sock,"250 %s file system mounted." sockprintf(sock,"250 %s file system mounted."
,local_fsys ? "Local" : "BBS"); ,local_fsys ? "Local" : "BBS");
lprintf("%04d %s mounted %s file system" lprintf(LOG_INFO,"%04d %s mounted %s file system"
,sock, user.alias, local_fsys ? "local" : "BBS"); ,sock, user.alias, local_fsys ? "local" : "BBS");
continue; continue;
} }
...@@ -3020,7 +3013,7 @@ static void ctrl_thread(void* arg) ...@@ -3020,7 +3013,7 @@ static void ctrl_thread(void* arg)
if(!strnicmp(cmd, "LIST", 4) || !strnicmp(cmd, "NLST", 4)) { if(!strnicmp(cmd, "LIST", 4) || !strnicmp(cmd, "NLST", 4)) {
if((fp=fopen(ftp_tmpfname(fname,sock),"w+b"))==NULL) { if((fp=fopen(ftp_tmpfname(fname,sock),"w+b"))==NULL) {
lprintf("%04d !ERROR %d opening %s",sock,errno,fname); lprintf(LOG_ERR,"%04d !ERROR %d opening %s",sock,errno,fname);
sockprintf(sock, "451 Insufficient system storage"); sockprintf(sock, "451 Insufficient system storage");
continue; continue;
} }
...@@ -3032,7 +3025,7 @@ static void ctrl_thread(void* arg) ...@@ -3032,7 +3025,7 @@ static void ctrl_thread(void* arg)
p=cmd+4; p=cmd+4;
while(*p && *p<=' ') p++; while(*p && *p<=' ') p++;
sprintf(path,"%s%s",local_dir, *p ? p : "*"); sprintf(path,"%s%s",local_dir, *p ? p : "*");
lprintf("%04d %s listing: %s", sock, user.alias, path); lprintf(LOG_INFO,"%04d %s listing: %s", sock, user.alias, path);
sockprintf(sock, "150 Directory of %s%s", local_dir, p); sockprintf(sock, "150 Directory of %s%s", local_dir, p);
now=time(NULL); now=time(NULL);
...@@ -3084,7 +3077,7 @@ static void ctrl_thread(void* arg) ...@@ -3084,7 +3077,7 @@ static void ctrl_thread(void* arg)
if(!strnicmp(tp,BBS_FSYS_DIR,strlen(BBS_FSYS_DIR))) { if(!strnicmp(tp,BBS_FSYS_DIR,strlen(BBS_FSYS_DIR))) {
local_fsys=FALSE; local_fsys=FALSE;
sockprintf(sock,"250 CWD command successful (BBS file system mounted)."); sockprintf(sock,"250 CWD command successful (BBS file system mounted).");
lprintf("%04d %s mounted BBS file system", sock, user.alias); lprintf(LOG_INFO,"%04d %s mounted BBS file system", sock, user.alias);
continue; continue;
} }
if(!strnicmp(tp,LOCAL_FSYS_DIR,strlen(LOCAL_FSYS_DIR))) { if(!strnicmp(tp,LOCAL_FSYS_DIR,strlen(LOCAL_FSYS_DIR))) {
...@@ -3103,7 +3096,7 @@ static void ctrl_thread(void* arg) ...@@ -3103,7 +3096,7 @@ static void ctrl_thread(void* arg)
if(!direxist(path)) { if(!direxist(path)) {
sockprintf(sock,"550 Directory does not exist (%s).",path); sockprintf(sock,"550 Directory does not exist (%s).",path);
lprintf("%04d !%s attempted to change to an invalid directory: %s" lprintf(LOG_WARNING,"%04d !%s attempted to change to an invalid directory: %s"
,sock, user.alias, path); ,sock, user.alias, path);
} else { } else {
SAFECOPY(local_dir,path); SAFECOPY(local_dir,path);
...@@ -3140,10 +3133,10 @@ static void ctrl_thread(void* arg) ...@@ -3140,10 +3133,10 @@ static void ctrl_thread(void* arg)
if((i=MKDIR(fname))==0) { if((i=MKDIR(fname))==0) {
sockprintf(sock,"257 \"%s\" directory created",fname); sockprintf(sock,"257 \"%s\" directory created",fname);
lprintf("%04d %s created directory: %s",sock,user.alias,fname); lprintf(LOG_NOTICE,"%04d %s created directory: %s",sock,user.alias,fname);
} else { } else {
sockprintf(sock,"521 Error %d creating directory: %s",i,fname); sockprintf(sock,"521 Error %d creating directory: %s",i,fname);
lprintf("%04d !%s attempted to create directory: %s (Error %d)" lprintf(LOG_WARNING,"%04d !%s attempted to create directory: %s (Error %d)"
,sock,user.alias,fname,i); ,sock,user.alias,fname,i);
} }
continue; continue;
...@@ -3159,10 +3152,10 @@ static void ctrl_thread(void* arg) ...@@ -3159,10 +3152,10 @@ static void ctrl_thread(void* arg)
if((i=rmdir(fname))==0) { if((i=rmdir(fname))==0) {
sockprintf(sock,"250 \"%s\" directory removed",fname); sockprintf(sock,"250 \"%s\" directory removed",fname);
lprintf("%04d %s removed directory: %s",sock,user.alias,fname); lprintf(LOG_NOTICE,"%04d %s removed directory: %s",sock,user.alias,fname);
} else { } else {
sockprintf(sock,"450 Error %d removing directory: %s",i,fname); sockprintf(sock,"450 Error %d removing directory: %s",i,fname);
lprintf("%04d !%s attempted to remove directory: %s (Error %d)" lprintf(LOG_WARNING,"%04d !%s attempted to remove directory: %s (Error %d)"
,sock,user.alias,fname,i); ,sock,user.alias,fname,i);
} }
continue; continue;
...@@ -3177,7 +3170,7 @@ static void ctrl_thread(void* arg) ...@@ -3177,7 +3170,7 @@ static void ctrl_thread(void* arg)
sprintf(ren_from,"%s%s",local_dir,p); sprintf(ren_from,"%s%s",local_dir,p);
if(!fexist(ren_from)) { if(!fexist(ren_from)) {
sockprintf(sock,"550 File not found: %s",ren_from); sockprintf(sock,"550 File not found: %s",ren_from);
lprintf("%04d !%s attempted to rename %s (not found)" lprintf(LOG_WARNING,"%04d !%s attempted to rename %s (not found)"
,sock,user.alias,ren_from); ,sock,user.alias,ren_from);
} else } else
sockprintf(sock,"350 File exists, ready for destination name"); sockprintf(sock,"350 File exists, ready for destination name");
...@@ -3194,10 +3187,10 @@ static void ctrl_thread(void* arg) ...@@ -3194,10 +3187,10 @@ static void ctrl_thread(void* arg)
if((i=rename(ren_from, fname))==0) { if((i=rename(ren_from, fname))==0) {
sockprintf(sock,"250 \"%s\" renamed to \"%s\"",ren_from,fname); sockprintf(sock,"250 \"%s\" renamed to \"%s\"",ren_from,fname);
lprintf("%04d %s renamed %s to %s",sock,user.alias,ren_from,fname); lprintf(LOG_NOTICE,"%04d %s renamed %s to %s",sock,user.alias,ren_from,fname);
} else { } else {
sockprintf(sock,"450 Error %d renaming file: %s",i,ren_from); sockprintf(sock,"450 Error %d renaming file: %s",i,ren_from);
lprintf("%04d !%s attempted to rename file: %s (Error %d)" lprintf(LOG_WARNING,"%04d !%s attempted to rename file: %s (Error %d)"
,sock,user.alias,ren_from,i); ,sock,user.alias,ren_from,i);
} }
continue; continue;
...@@ -3219,7 +3212,7 @@ static void ctrl_thread(void* arg) ...@@ -3219,7 +3212,7 @@ static void ctrl_thread(void* arg)
else /* relative */ else /* relative */
sprintf(fname,"%s%s",local_dir,p); sprintf(fname,"%s%s",local_dir,p);
if(!fexist(fname)) { if(!fexist(fname)) {
lprintf("%04d !%s file not found: %s",sock,user.alias,fname); lprintf(LOG_WARNING,"%04d !%s file not found: %s",sock,user.alias,fname);
sockprintf(sock,"550 File not found: %s",fname); sockprintf(sock,"550 File not found: %s",fname);
continue; continue;
} }
...@@ -3239,16 +3232,16 @@ static void ctrl_thread(void* arg) ...@@ -3239,16 +3232,16 @@ static void ctrl_thread(void* arg)
if(!strnicmp(cmd,"DELE ",5)) { if(!strnicmp(cmd,"DELE ",5)) {
if((i=remove(fname))==0) { if((i=remove(fname))==0) {
sockprintf(sock,"250 \"%s\" removed successfully.",fname); sockprintf(sock,"250 \"%s\" removed successfully.",fname);
lprintf("%04d %s deleted file: %s",sock,user.alias,fname); lprintf(LOG_NOTICE,"%04d %s deleted file: %s",sock,user.alias,fname);
} else { } else {
sockprintf(sock,"450 Error %d removing file: %s",i,fname); sockprintf(sock,"450 Error %d removing file: %s",i,fname);
lprintf("%04d !%s attempted to delete file: %s (Error %d)" lprintf(LOG_WARNING,"%04d !%s attempted to delete file: %s (Error %d)"
,sock,user.alias,fname,i); ,sock,user.alias,fname,i);
} }
continue; continue;
} }
/* RETR */ /* RETR */
lprintf("%04d %s downloading: %s (%lu bytes) in %s mode" lprintf(LOG_INFO,"%04d %s downloading: %s (%lu bytes) in %s mode"
,sock,user.alias,fname,flength(fname) ,sock,user.alias,fname,flength(fname)
,pasv_sock==INVALID_SOCKET ? "active":"passive"); ,pasv_sock==INVALID_SOCKET ? "active":"passive");
sockprintf(sock,"150 Opening BINARY mode data connection for file transfer."); sockprintf(sock,"150 Opening BINARY mode data connection for file transfer.");
...@@ -3272,7 +3265,7 @@ static void ctrl_thread(void* arg) ...@@ -3272,7 +3265,7 @@ static void ctrl_thread(void* arg)
else /* relative */ else /* relative */
sprintf(fname,"%s%s",local_dir,p); sprintf(fname,"%s%s",local_dir,p);
lprintf("%04d %s uploading: %s in %s mode", sock,user.alias,fname lprintf(LOG_INFO,"%04d %s uploading: %s in %s mode", sock,user.alias,fname
,pasv_sock==INVALID_SOCKET ? "active":"passive"); ,pasv_sock==INVALID_SOCKET ? "active":"passive");
sockprintf(sock,"150 Opening BINARY mode data connection for file transfer."); sockprintf(sock,"150 Opening BINARY mode data connection for file transfer.");
filexfer(&data_addr,sock,pasv_sock,&data_sock,fname,filepos filexfer(&data_addr,sock,pasv_sock,&data_sock,fname,filepos
...@@ -3295,7 +3288,7 @@ static void ctrl_thread(void* arg) ...@@ -3295,7 +3288,7 @@ static void ctrl_thread(void* arg)
lib=curlib; lib=curlib;
if(cmd[4]!=0) if(cmd[4]!=0)
lprintf("%04d LIST/NLST: %s",sock,cmd); lprintf(LOG_DEBUG,"%04d LIST/NLST: %s",sock,cmd);
/* path specified? */ /* path specified? */
p=cmd+4; p=cmd+4;
...@@ -3309,7 +3302,7 @@ static void ctrl_thread(void* arg) ...@@ -3309,7 +3302,7 @@ static void ctrl_thread(void* arg)
parsepath(&p,&user,&lib,&dir); parsepath(&p,&user,&lib,&dir);
if((fp=fopen(ftp_tmpfname(fname,sock),"w+b"))==NULL) { if((fp=fopen(ftp_tmpfname(fname,sock),"w+b"))==NULL) {
lprintf("%04d !ERROR %d opening %s",sock,errno,fname); lprintf(LOG_ERR,"%04d !ERROR %d opening %s",sock,errno,fname);
sockprintf(sock, "451 Insufficient system storage"); sockprintf(sock, "451 Insufficient system storage");
continue; continue;
} }
...@@ -3354,7 +3347,7 @@ static void ctrl_thread(void* arg) ...@@ -3354,7 +3347,7 @@ static void ctrl_thread(void* arg)
} }
if(lib<0) { /* Root dir */ if(lib<0) { /* Root dir */
lprintf("%04d %s listing: root",sock,user.alias); lprintf(LOG_INFO,"%04d %s listing: root",sock,user.alias);
/* QWK Packet */ /* QWK Packet */
if(startup->options&FTP_OPT_ALLOW_QWK/* && fexist(qwkfile)*/) { if(startup->options&FTP_OPT_ALLOW_QWK/* && fexist(qwkfile)*/) {
...@@ -3472,7 +3465,7 @@ static void ctrl_thread(void* arg) ...@@ -3472,7 +3465,7 @@ static void ctrl_thread(void* arg)
fprintf(fp,"%s\r\n",scfg.lib[i]->sname); fprintf(fp,"%s\r\n",scfg.lib[i]->sname);
} }
} else if(dir<0) { } else if(dir<0) {
lprintf("%04d %s listing: %s library",sock,user.alias,scfg.lib[lib]->sname); lprintf(LOG_INFO,"%04d %s listing: %s library",sock,user.alias,scfg.lib[lib]->sname);
for(i=0;i<scfg.total_dirs;i++) { for(i=0;i<scfg.total_dirs;i++) {
if(scfg.dir[i]->lib!=lib) if(scfg.dir[i]->lib!=lib)
continue; continue;
...@@ -3491,7 +3484,7 @@ static void ctrl_thread(void* arg) ...@@ -3491,7 +3484,7 @@ static void ctrl_thread(void* arg)
fprintf(fp,"%s\r\n",scfg.dir[i]->code_suffix); fprintf(fp,"%s\r\n",scfg.dir[i]->code_suffix);
} }
} else if(chk_ar(&scfg,scfg.dir[dir]->ar,&user)) { } else if(chk_ar(&scfg,scfg.dir[dir]->ar,&user)) {
lprintf("%04d %s listing: %s/%s directory" lprintf(LOG_INFO,"%04d %s listing: %s/%s directory"
,sock,user.alias,scfg.lib[lib]->sname,scfg.dir[dir]->code_suffix); ,sock,user.alias,scfg.lib[lib]->sname,scfg.dir[dir]->code_suffix);
sprintf(path,"%s%s",scfg.dir[dir]->path,*p ? p : "*"); sprintf(path,"%s%s",scfg.dir[dir]->path,*p ? p : "*");
...@@ -3541,7 +3534,7 @@ static void ctrl_thread(void* arg) ...@@ -3541,7 +3534,7 @@ static void ctrl_thread(void* arg)
} }
globfree(&g); globfree(&g);
} else } else
lprintf("%04d %s listing: %s/%s directory (empty - no access)" lprintf(LOG_INFO,"%04d %s listing: %s/%s directory (empty - no access)"
,sock,user.alias,scfg.lib[lib]->sname,scfg.dir[dir]->code_suffix); ,sock,user.alias,scfg.lib[lib]->sname,scfg.dir[dir]->code_suffix);
fclose(fp); fclose(fp);
...@@ -3597,7 +3590,7 @@ static void ctrl_thread(void* arg) ...@@ -3597,7 +3590,7 @@ static void ctrl_thread(void* arg)
credits=TRUE; /* include in d/l stats */ credits=TRUE; /* include in d/l stats */
tmpfile=FALSE; tmpfile=FALSE;
delfile=FALSE; delfile=FALSE;
lprintf("%04d %s %.4s by alias: %s" lprintf(LOG_INFO,"%04d %s %.4s by alias: %s"
,sock,user.alias,cmd,p); ,sock,user.alias,cmd,p);
p=getfname(fname); p=getfname(fname);
if(dir>=0) if(dir>=0)
...@@ -3636,10 +3629,10 @@ static void ctrl_thread(void* arg) ...@@ -3636,10 +3629,10 @@ static void ctrl_thread(void* arg)
sprintf(str,"%s.qwk",scfg.sys_id); sprintf(str,"%s.qwk",scfg.sys_id);
if(lib<0 && startup->options&FTP_OPT_ALLOW_QWK if(lib<0 && startup->options&FTP_OPT_ALLOW_QWK
&& !stricmp(p,str) && !delecmd) { && !stricmp(p,str) && !delecmd) {
lprintf("%04d %s creating/updating QWK packet...",sock,user.alias); lprintf(LOG_INFO,"%04d %s creating/updating QWK packet...",sock,user.alias);
sprintf(str,"%spack%04u.now",scfg.data_dir,user.number); sprintf(str,"%spack%04u.now",scfg.data_dir,user.number);
if((file=open(str,O_WRONLY|O_CREAT,S_IWRITE))==-1) { if((file=open(str,O_WRONLY|O_CREAT,S_IWRITE))==-1) {
lprintf("%04d !ERROR %d opening %s",sock, errno, str); lprintf(LOG_ERR,"%04d !ERROR %d opening %s",sock, errno, str);
sockprintf(sock, "451 !ERROR %d creating semaphore file",errno); sockprintf(sock, "451 !ERROR %d creating semaphore file",errno);
filepos=0; filepos=0;
continue; continue;
...@@ -3652,14 +3645,14 @@ static void ctrl_thread(void* arg) ...@@ -3652,14 +3645,14 @@ static void ctrl_thread(void* arg)
mswait(1000); mswait(1000);
} }
if(fexist(str)) { if(fexist(str)) {
lprintf("%04d !TIMEOUT waiting for QWK packet creation",sock); lprintf(LOG_WARNING,"%04d !TIMEOUT waiting for QWK packet creation",sock);
sockprintf(sock,"451 Time-out waiting for packet creation."); sockprintf(sock,"451 Time-out waiting for packet creation.");
remove(str); remove(str);
filepos=0; filepos=0;
continue; continue;
} }
if(!fexist(qwkfile)) { if(!fexist(qwkfile)) {
lprintf("%04d No QWK Packet created (no new messages)",sock); lprintf(LOG_INFO,"%04d No QWK Packet created (no new messages)",sock);
sockprintf(sock,"550 No QWK packet created (no new messages)"); sockprintf(sock,"550 No QWK packet created (no new messages)");
filepos=0; filepos=0;
continue; continue;
...@@ -3668,7 +3661,7 @@ static void ctrl_thread(void* arg) ...@@ -3668,7 +3661,7 @@ static void ctrl_thread(void* arg)
success=TRUE; success=TRUE;
delfile=TRUE; delfile=TRUE;
credits=FALSE; credits=FALSE;
lprintf("%04d %s downloading QWK packet (%lu bytes) in %s mode" lprintf(LOG_INFO,"%04d %s downloading QWK packet (%lu bytes) in %s mode"
,sock,user.alias,flength(fname) ,sock,user.alias,flength(fname)
,pasv_sock==INVALID_SOCKET ? "active":"passive"); ,pasv_sock==INVALID_SOCKET ? "active":"passive");
/* ASCII Index File */ /* ASCII Index File */
...@@ -3676,13 +3669,13 @@ static void ctrl_thread(void* arg) ...@@ -3676,13 +3669,13 @@ static void ctrl_thread(void* arg)
&& !stricmp(p,startup->index_file_name) && !stricmp(p,startup->index_file_name)
&& !delecmd) { && !delecmd) {
if((fp=fopen(ftp_tmpfname(fname,sock),"w+b"))==NULL) { if((fp=fopen(ftp_tmpfname(fname,sock),"w+b"))==NULL) {
lprintf("%04d !ERROR %d opening %s",sock,errno,fname); lprintf(LOG_ERR,"%04d !ERROR %d opening %s",sock,errno,fname);
sockprintf(sock, "451 Insufficient system storage"); sockprintf(sock, "451 Insufficient system storage");
filepos=0; filepos=0;
continue; continue;
} }
if(!getsize && !getdate) if(!getsize && !getdate)
lprintf("%04d %s downloading index for %s in %s mode" lprintf(LOG_INFO,"%04d %s downloading index for %s in %s mode"
,sock,user.alias,vpath(lib,dir,str) ,sock,user.alias,vpath(lib,dir,str)
,pasv_sock==INVALID_SOCKET ? "active":"passive"); ,pasv_sock==INVALID_SOCKET ? "active":"passive");
success=TRUE; success=TRUE;
...@@ -3784,17 +3777,17 @@ static void ctrl_thread(void* arg) ...@@ -3784,17 +3777,17 @@ static void ctrl_thread(void* arg)
&& !delecmd) { && !delecmd) {
#ifdef JAVASCRIPT #ifdef JAVASCRIPT
if(startup->options&FTP_OPT_NO_JAVASCRIPT) { if(startup->options&FTP_OPT_NO_JAVASCRIPT) {
lprintf("%04d !JavaScript disabled, cannot generate %s",sock,fname); lprintf(LOG_ERR,"%04d !JavaScript disabled, cannot generate %s",sock,fname);
sockprintf(sock, "451 JavaScript disabled"); sockprintf(sock, "451 JavaScript disabled");
filepos=0; filepos=0;
continue; continue;
} }
if(js_runtime == NULL) { if(js_runtime == NULL) {
lprintf("%04d JavaScript: Creating runtime: %lu bytes" lprintf(LOG_DEBUG,"%04d JavaScript: Creating runtime: %lu bytes"
,sock,startup->js_max_bytes); ,sock,startup->js_max_bytes);
if((js_runtime = JS_NewRuntime(startup->js_max_bytes))==NULL) { if((js_runtime = JS_NewRuntime(startup->js_max_bytes))==NULL) {
lprintf("%04d !ERROR creating JavaScript runtime",sock); lprintf(LOG_ERR,"%04d !ERROR creating JavaScript runtime",sock);
sockprintf(sock,"451 Error creating JavaScript runtime"); sockprintf(sock,"451 Error creating JavaScript runtime");
filepos=0; filepos=0;
continue; continue;
...@@ -3803,26 +3796,26 @@ static void ctrl_thread(void* arg) ...@@ -3803,26 +3796,26 @@ static void ctrl_thread(void* arg)
if(js_cx==NULL) { /* Context not yet created, create it now */ if(js_cx==NULL) { /* Context not yet created, create it now */
if(((js_cx=js_initcx(js_runtime, sock,&js_glob,&js_ftp))==NULL)) { if(((js_cx=js_initcx(js_runtime, sock,&js_glob,&js_ftp))==NULL)) {
lprintf("%04d !ERROR initializing JavaScript context",sock); lprintf(LOG_ERR,"%04d !ERROR initializing JavaScript context",sock);
sockprintf(sock,"451 Error initializing JavaScript context"); sockprintf(sock,"451 Error initializing JavaScript context");
filepos=0; filepos=0;
continue; continue;
} }
if(js_CreateUserClass(js_cx, js_glob, &scfg)==NULL) if(js_CreateUserClass(js_cx, js_glob, &scfg)==NULL)
lprintf("%04d !JavaScript ERROR creating user class",sock); lprintf(LOG_ERR,"%04d !JavaScript ERROR creating user class",sock);
if(js_CreateFileClass(js_cx, js_glob)==NULL) if(js_CreateFileClass(js_cx, js_glob)==NULL)
lprintf("%04d !JavaScript ERROR creating file class",sock); lprintf(LOG_ERR,"%04d !JavaScript ERROR creating file class",sock);
if(js_CreateUserObject(js_cx, js_glob, &scfg, "user", user.number)==NULL) if(js_CreateUserObject(js_cx, js_glob, &scfg, "user", user.number)==NULL)
lprintf("%04d !JavaScript ERROR creating user object",sock); lprintf(LOG_ERR,"%04d !JavaScript ERROR creating user object",sock);
if(js_CreateClientObject(js_cx, js_glob, "client", &client, sock)==NULL) if(js_CreateClientObject(js_cx, js_glob, "client", &client, sock)==NULL)
lprintf("%04d !JavaScript ERROR creating client object",sock); lprintf(LOG_ERR,"%04d !JavaScript ERROR creating client object",sock);
if(js_CreateFileAreaObject(js_cx, js_glob, &scfg, &user if(js_CreateFileAreaObject(js_cx, js_glob, &scfg, &user
,startup->html_index_file)==NULL) ,startup->html_index_file)==NULL)
lprintf("%04d !JavaScript ERROR creating file area object",sock); lprintf(LOG_ERR,"%04d !JavaScript ERROR creating file area object",sock);
} }
if((js_str=JS_NewStringCopyZ(js_cx, "name"))!=NULL) { if((js_str=JS_NewStringCopyZ(js_cx, "name"))!=NULL) {
...@@ -3865,13 +3858,13 @@ static void ctrl_thread(void* arg) ...@@ -3865,13 +3858,13 @@ static void ctrl_thread(void* arg)
} }
#endif #endif
if((fp=fopen(ftp_tmpfname(fname,sock),"w+b"))==NULL) { if((fp=fopen(ftp_tmpfname(fname,sock),"w+b"))==NULL) {
lprintf("%04d !ERROR %d opening %s",sock,errno,fname); lprintf(LOG_ERR,"%04d !ERROR %d opening %s",sock,errno,fname);
sockprintf(sock, "451 Insufficient system storage"); sockprintf(sock, "451 Insufficient system storage");
filepos=0; filepos=0;
continue; continue;
} }
if(!getsize && !getdate) if(!getsize && !getdate)
lprintf("%04d %s downloading HTML index for %s in %s mode" lprintf(LOG_INFO,"%04d %s downloading HTML index for %s in %s mode"
,sock,user.alias,vpath(lib,dir,str) ,sock,user.alias,vpath(lib,dir,str)
,pasv_sock==INVALID_SOCKET ? "active":"passive"); ,pasv_sock==INVALID_SOCKET ? "active":"passive");
success=TRUE; success=TRUE;
...@@ -3881,14 +3874,14 @@ static void ctrl_thread(void* arg) ...@@ -3881,14 +3874,14 @@ static void ctrl_thread(void* arg)
#ifdef JAVASCRIPT #ifdef JAVASCRIPT
js_val=INT_TO_JSVAL(timeleft); js_val=INT_TO_JSVAL(timeleft);
if(!JS_SetProperty(js_cx, js_ftp, "time_left", &js_val)) if(!JS_SetProperty(js_cx, js_ftp, "time_left", &js_val))
lprintf("%04d !JavaScript ERROR setting user.time_left",sock); lprintf(LOG_ERR,"%04d !JavaScript ERROR setting user.time_left",sock);
js_generate_index(js_cx, js_ftp, sock, fp, lib, dir, &user); js_generate_index(js_cx, js_ftp, sock, fp, lib, dir, &user);
#endif #endif
fclose(fp); fclose(fp);
} else if(dir>=0) { } else if(dir>=0) {
if(!chk_ar(&scfg,scfg.dir[dir]->ar,&user)) { if(!chk_ar(&scfg,scfg.dir[dir]->ar,&user)) {
lprintf("%04d !%s has insufficient access to /%s/%s" lprintf(LOG_WARNING,"%04d !%s has insufficient access to /%s/%s"
,sock,user.alias ,sock,user.alias
,scfg.lib[scfg.dir[dir]->lib]->sname ,scfg.lib[scfg.dir[dir]->lib]->sname
,scfg.dir[dir]->code_suffix); ,scfg.dir[dir]->code_suffix);
...@@ -3899,7 +3892,7 @@ static void ctrl_thread(void* arg) ...@@ -3899,7 +3892,7 @@ static void ctrl_thread(void* arg)
if(!getsize && !getdate && !delecmd if(!getsize && !getdate && !delecmd
&& !chk_ar(&scfg,scfg.dir[dir]->dl_ar,&user)) { && !chk_ar(&scfg,scfg.dir[dir]->dl_ar,&user)) {
lprintf("%04d !%s has insufficient access to download from /%s/%s" lprintf(LOG_WARNING,"%04d !%s has insufficient access to download from /%s/%s"
,sock,user.alias ,sock,user.alias
,scfg.lib[scfg.dir[dir]->lib]->sname ,scfg.lib[scfg.dir[dir]->lib]->sname
,scfg.dir[dir]->code_suffix); ,scfg.dir[dir]->code_suffix);
...@@ -3909,7 +3902,7 @@ static void ctrl_thread(void* arg) ...@@ -3909,7 +3902,7 @@ static void ctrl_thread(void* arg)
} }
if(delecmd && !dir_op(&scfg,&user,dir)) { if(delecmd && !dir_op(&scfg,&user,dir)) {
lprintf("%04d !%s has insufficient access to delete files in /%s/%s" lprintf(LOG_WARNING,"%04d !%s has insufficient access to delete files in /%s/%s"
,sock,user.alias ,sock,user.alias
,scfg.lib[scfg.dir[dir]->lib]->sname ,scfg.lib[scfg.dir[dir]->lib]->sname
,scfg.dir[dir]->code_suffix); ,scfg.dir[dir]->code_suffix);
...@@ -3930,7 +3923,7 @@ static void ctrl_thread(void* arg) ...@@ -3930,7 +3923,7 @@ static void ctrl_thread(void* arg)
filedat=getfileixb(&scfg,&f); filedat=getfileixb(&scfg,&f);
if(!filedat && !(startup->options&FTP_OPT_DIR_FILES)) { if(!filedat && !(startup->options&FTP_OPT_DIR_FILES)) {
sockprintf(sock,"550 File not found: %s",p); sockprintf(sock,"550 File not found: %s",p);
lprintf("%04d !%s file (%s%s) not in database for %.4s command" lprintf(LOG_WARNING,"%04d !%s file (%s%s) not in database for %.4s command"
,sock,user.alias,vpath(lib,dir,str),p,cmd); ,sock,user.alias,vpath(lib,dir,str),p,cmd);
filepos=0; filepos=0;
continue; continue;
...@@ -3944,7 +3937,7 @@ static void ctrl_thread(void* arg) ...@@ -3944,7 +3937,7 @@ static void ctrl_thread(void* arg)
else else
f.cdt=flength(fname); f.cdt=flength(fname);
if(f.cdt>(user.cdt+user.freecdt)) { if(f.cdt>(user.cdt+user.freecdt)) {
lprintf("%04d !%s has insufficient credit to download /%s/%s/%s (%lu credits)" lprintf(LOG_WARNING,"%04d !%s has insufficient credit to download /%s/%s/%s (%lu credits)"
,sock,user.alias,scfg.lib[scfg.dir[dir]->lib]->sname ,sock,user.alias,scfg.lib[scfg.dir[dir]->lib]->sname
,scfg.dir[dir]->code_suffix ,scfg.dir[dir]->code_suffix
,p ,p
...@@ -3957,7 +3950,7 @@ static void ctrl_thread(void* arg) ...@@ -3957,7 +3950,7 @@ static void ctrl_thread(void* arg)
if(strcspn(p,ILLEGAL_FILENAME_CHARS)!=strlen(p)) { if(strcspn(p,ILLEGAL_FILENAME_CHARS)!=strlen(p)) {
success=FALSE; success=FALSE;
lprintf("%04d !ILLEGAL FILENAME ATTEMPT by %s: %s" lprintf(LOG_WARNING,"%04d !ILLEGAL FILENAME ATTEMPT by %s: %s"
,sock,user.alias,p); ,sock,user.alias,p);
hacklog(&scfg, "FTP", user.alias, cmd, host_name, &ftp.client_addr); hacklog(&scfg, "FTP", user.alias, cmd, host_name, &ftp.client_addr);
#ifdef _WIN32 #ifdef _WIN32
...@@ -3968,7 +3961,7 @@ static void ctrl_thread(void* arg) ...@@ -3968,7 +3961,7 @@ static void ctrl_thread(void* arg)
if(fexist(fname)) { if(fexist(fname)) {
success=TRUE; success=TRUE;
if(!getsize && !getdate && !delecmd) if(!getsize && !getdate && !delecmd)
lprintf("%04d %s downloading: %s (%lu bytes) in %s mode" lprintf(LOG_INFO,"%04d %s downloading: %s (%lu bytes) in %s mode"
,sock,user.alias,fname,flength(fname) ,sock,user.alias,fname,flength(fname)
,pasv_sock==INVALID_SOCKET ? "active":"passive"); ,pasv_sock==INVALID_SOCKET ? "active":"passive");
} }
...@@ -3989,11 +3982,11 @@ static void ctrl_thread(void* arg) ...@@ -3989,11 +3982,11 @@ static void ctrl_thread(void* arg)
,tm.tm_hour,tm.tm_min,tm.tm_sec); ,tm.tm_hour,tm.tm_min,tm.tm_sec);
} else if(delecmd && success) { } else if(delecmd && success) {
if(remove(fname)!=0) { if(remove(fname)!=0) {
lprintf("%04d !ERROR %d deleting %s",sock,errno,fname); lprintf(LOG_ERR,"%04d !ERROR %d deleting %s",sock,errno,fname);
sockprintf(sock,"450 %s could not be deleted (error: %d)" sockprintf(sock,"450 %s could not be deleted (error: %d)"
,fname,errno); ,fname,errno);
} else { } else {
lprintf("%04d %s deleted %s",sock,user.alias,fname); lprintf(LOG_NOTICE,"%04d %s deleted %s",sock,user.alias,fname);
if(filedat) if(filedat)
removefiledat(&scfg,&f); removefiledat(&scfg,&f);
sockprintf(sock,"250 %s deleted.",fname); sockprintf(sock,"250 %s deleted.",fname);
...@@ -4006,7 +3999,7 @@ static void ctrl_thread(void* arg) ...@@ -4006,7 +3999,7 @@ static void ctrl_thread(void* arg)
} }
else { else {
sockprintf(sock,"550 File not found: %s",p); sockprintf(sock,"550 File not found: %s",p);
lprintf("%04d !%s file (%s%s) not found for %.4s command" lprintf(LOG_WARNING,"%04d !%s file (%s%s) not found for %.4s command"
,sock,user.alias,vpath(lib,dir,str),p,cmd); ,sock,user.alias,vpath(lib,dir,str),p,cmd);
} }
filepos=0; filepos=0;
...@@ -4043,7 +4036,7 @@ static void ctrl_thread(void* arg) ...@@ -4043,7 +4036,7 @@ static void ctrl_thread(void* arg)
} }
if(transfer_inprogress==TRUE) { if(transfer_inprogress==TRUE) {
lprintf("%04d !TRANSFER already in progress (%s)",sock,cmd); lprintf(LOG_WARNING,"%04d !TRANSFER already in progress (%s)",sock,cmd);
sockprintf(sock,"425 Transfer already in progress."); sockprintf(sock,"425 Transfer already in progress.");
continue; continue;
} }
...@@ -4097,13 +4090,13 @@ static void ctrl_thread(void* arg) ...@@ -4097,13 +4090,13 @@ static void ctrl_thread(void* arg)
sprintf(str,"%s.rep",scfg.sys_id); sprintf(str,"%s.rep",scfg.sys_id);
if(!(startup->options&FTP_OPT_ALLOW_QWK) if(!(startup->options&FTP_OPT_ALLOW_QWK)
|| stricmp(p,str)) { || stricmp(p,str)) {
lprintf("%04d !%s attempted to upload to invalid directory" lprintf(LOG_WARNING,"%04d !%s attempted to upload to invalid directory"
,sock,user.alias); ,sock,user.alias);
sockprintf(sock,"553 Invalid directory."); sockprintf(sock,"553 Invalid directory.");
continue; continue;
} }
sprintf(fname,"%sfile/%04d.rep",scfg.data_dir,user.number); sprintf(fname,"%sfile/%04d.rep",scfg.data_dir,user.number);
lprintf("%04d %s uploading: %s in %s mode" lprintf(LOG_INFO,"%04d %s uploading: %s in %s mode"
,sock,user.alias,fname ,sock,user.alias,fname
,pasv_sock==INVALID_SOCKET ? "active":"passive"); ,pasv_sock==INVALID_SOCKET ? "active":"passive");
} else { } else {
...@@ -4111,7 +4104,7 @@ static void ctrl_thread(void* arg) ...@@ -4111,7 +4104,7 @@ static void ctrl_thread(void* arg)
append=(strnicmp(cmd,"APPE",4)==0); append=(strnicmp(cmd,"APPE",4)==0);
if(!chk_ar(&scfg,scfg.dir[dir]->ul_ar,&user)) { if(!chk_ar(&scfg,scfg.dir[dir]->ul_ar,&user)) {
lprintf("%04d !%s has insufficient access to upload to /%s/%s" lprintf(LOG_WARNING,"%04d !%s has insufficient access to upload to /%s/%s"
,sock,user.alias ,sock,user.alias
,scfg.lib[scfg.dir[dir]->lib]->sname ,scfg.lib[scfg.dir[dir]->lib]->sname
,scfg.dir[dir]->code_suffix); ,scfg.dir[dir]->code_suffix);
...@@ -4120,7 +4113,7 @@ static void ctrl_thread(void* arg) ...@@ -4120,7 +4113,7 @@ static void ctrl_thread(void* arg)
} }
if(strcspn(p,ILLEGAL_FILENAME_CHARS)!=strlen(p) if(strcspn(p,ILLEGAL_FILENAME_CHARS)!=strlen(p)
|| trashcan(&scfg,p,"file")) { || trashcan(&scfg,p,"file")) {
lprintf("%04d !ILLEGAL FILENAME ATTEMPT by %s: %s" lprintf(LOG_WARNING,"%04d !ILLEGAL FILENAME ATTEMPT by %s: %s"
,sock,user.alias,p); ,sock,user.alias,p);
sockprintf(sock,"553 Illegal filename attempt"); sockprintf(sock,"553 Illegal filename attempt");
hacklog(&scfg, "FTP", user.alias, cmd, host_name, &ftp.client_addr); hacklog(&scfg, "FTP", user.alias, cmd, host_name, &ftp.client_addr);
...@@ -4137,7 +4130,7 @@ static void ctrl_thread(void* arg) ...@@ -4137,7 +4130,7 @@ static void ctrl_thread(void* arg)
|| (startup->options&FTP_OPT_HTML_INDEX_FILE || (startup->options&FTP_OPT_HTML_INDEX_FILE
&& !stricmp(p,startup->html_index_file)) && !stricmp(p,startup->html_index_file))
) { ) {
lprintf("%04d !%s attempted to overwrite existing file: %s" lprintf(LOG_WARNING,"%04d !%s attempted to overwrite existing file: %s"
,sock,user.alias,fname); ,sock,user.alias,fname);
sockprintf(sock,"553 File already exists."); sockprintf(sock,"553 File already exists.");
continue; continue;
...@@ -4154,7 +4147,7 @@ static void ctrl_thread(void* arg) ...@@ -4154,7 +4147,7 @@ static void ctrl_thread(void* arg)
f.size=-1; f.size=-1;
if(!getfileixb(&scfg,&f) || !getfiledat(&scfg,&f)) { if(!getfileixb(&scfg,&f) || !getfiledat(&scfg,&f)) {
if(filepos) { if(filepos) {
lprintf("%04d !%s file (%s) not in database for %.4s command" lprintf(LOG_WARNING,"%04d !%s file (%s) not in database for %.4s command"
,sock,user.alias,fname,cmd); ,sock,user.alias,fname,cmd);
sockprintf(sock,"550 File not found: %s",p); sockprintf(sock,"550 File not found: %s",p);
continue; continue;
...@@ -4163,13 +4156,13 @@ static void ctrl_thread(void* arg) ...@@ -4163,13 +4156,13 @@ static void ctrl_thread(void* arg)
} }
/* Verify user is original uploader */ /* Verify user is original uploader */
if((append || filepos) && stricmp(f.uler,user.alias)) { if((append || filepos) && stricmp(f.uler,user.alias)) {
lprintf("%04d !%s cannot resume upload of %s, uploaded by %s" lprintf(LOG_WARNING,"%04d !%s cannot resume upload of %s, uploaded by %s"
,sock,user.alias,fname,f.uler); ,sock,user.alias,fname,f.uler);
sockprintf(sock,"553 Insufficient access (can't resume upload from different user)."); sockprintf(sock,"553 Insufficient access (can't resume upload from different user).");
continue; continue;
} }
} }
lprintf("%04d %s uploading: %s to %s (%s) in %s mode" lprintf(LOG_INFO,"%04d %s uploading: %s to %s (%s) in %s mode"
,sock,user.alias ,sock,user.alias
,p /* filename */ ,p /* filename */
,vpath(lib,dir,str) /* virtual path */ ,vpath(lib,dir,str) /* virtual path */
...@@ -4218,14 +4211,14 @@ static void ctrl_thread(void* arg) ...@@ -4218,14 +4211,14 @@ static void ctrl_thread(void* arg)
p+=strlen(LOCAL_FSYS_DIR); p+=strlen(LOCAL_FSYS_DIR);
if(!direxist(p)) { if(!direxist(p)) {
sockprintf(sock,"550 Directory does not exist."); sockprintf(sock,"550 Directory does not exist.");
lprintf("%04d !%s attempted to mount invalid directory: %s" lprintf(LOG_WARNING,"%04d !%s attempted to mount invalid directory: %s"
,sock, user.alias, p); ,sock, user.alias, p);
continue; continue;
} }
SAFECOPY(local_dir,p); SAFECOPY(local_dir,p);
local_fsys=TRUE; local_fsys=TRUE;
sockprintf(sock,"250 CWD command successful (local file system mounted)."); sockprintf(sock,"250 CWD command successful (local file system mounted).");
lprintf("%04d %s mounted local file system", sock, user.alias); lprintf(LOG_INFO,"%04d %s mounted local file system", sock, user.alias);
continue; continue;
} }
success=FALSE; success=FALSE;
...@@ -4320,7 +4313,7 @@ static void ctrl_thread(void* arg) ...@@ -4320,7 +4313,7 @@ static void ctrl_thread(void* arg)
if(!strnicmp(cmd, "MKD", 3) || if(!strnicmp(cmd, "MKD", 3) ||
!strnicmp(cmd,"XMKD",4) || !strnicmp(cmd,"XMKD",4) ||
!strnicmp(cmd,"SITE EXEC",9)) { !strnicmp(cmd,"SITE EXEC",9)) {
lprintf("%04d !SUSPECTED HACK ATTEMPT by %s: '%s'" lprintf(LOG_WARNING,"%04d !SUSPECTED HACK ATTEMPT by %s: '%s'"
,sock,user.alias,cmd); ,sock,user.alias,cmd);
hacklog(&scfg, "FTP", user.alias, cmd, host_name, &ftp.client_addr); hacklog(&scfg, "FTP", user.alias, cmd, host_name, &ftp.client_addr);
#ifdef _WIN32 #ifdef _WIN32
...@@ -4329,7 +4322,7 @@ static void ctrl_thread(void* arg) ...@@ -4329,7 +4322,7 @@ static void ctrl_thread(void* arg)
#endif #endif
} }
sockprintf(sock,"500 Syntax error: '%s'",cmd); sockprintf(sock,"500 Syntax error: '%s'",cmd);
lprintf("%04d !UNSUPPORTED COMMAND from %s: '%s'" lprintf(LOG_WARNING,"%04d !UNSUPPORTED COMMAND from %s: '%s'"
,sock,user.alias,cmd); ,sock,user.alias,cmd);
} /* while(1) */ } /* while(1) */
...@@ -4338,7 +4331,7 @@ static void ctrl_thread(void* arg) ...@@ -4338,7 +4331,7 @@ static void ctrl_thread(void* arg)
#endif #endif
if(transfer_inprogress==TRUE) { if(transfer_inprogress==TRUE) {
lprintf("%04d Waiting for transfer to complete...",sock); lprintf(LOG_DEBUG,"%04d Waiting for transfer to complete...",sock);
count=0; count=0;
while(transfer_inprogress==TRUE) { while(transfer_inprogress==TRUE) {
if(server_socket==INVALID_SOCKET) { if(server_socket==INVALID_SOCKET) {
...@@ -4347,13 +4340,13 @@ static void ctrl_thread(void* arg) ...@@ -4347,13 +4340,13 @@ static void ctrl_thread(void* arg)
} }
if(!transfer_aborted) { if(!transfer_aborted) {
if(gettimeleft(&scfg,&user,logintime)<1) { if(gettimeleft(&scfg,&user,logintime)<1) {
lprintf("%04d Out of time, disconnecting",sock); lprintf(LOG_WARNING,"%04d Out of time, disconnecting",sock);
sockprintf(sock,"421 Sorry, you've run out of time."); sockprintf(sock,"421 Sorry, you've run out of time.");
ftp_close_socket(&data_sock,__LINE__); ftp_close_socket(&data_sock,__LINE__);
transfer_aborted=TRUE; transfer_aborted=TRUE;
} }
if((time(NULL)-lastactive)>startup->max_inactivity) { if((time(NULL)-lastactive)>startup->max_inactivity) {
lprintf("%04d Disconnecting due to to inactivity",sock); lprintf(LOG_WARNING,"%04d Disconnecting due to to inactivity",sock);
sockprintf(sock,"421 Disconnecting due to inactivity (%u seconds)." sockprintf(sock,"421 Disconnecting due to inactivity (%u seconds)."
,startup->max_inactivity); ,startup->max_inactivity);
ftp_close_socket(&data_sock,__LINE__); ftp_close_socket(&data_sock,__LINE__);
...@@ -4361,13 +4354,13 @@ static void ctrl_thread(void* arg) ...@@ -4361,13 +4354,13 @@ static void ctrl_thread(void* arg)
} }
} }
if(count && (count%60)==0) if(count && (count%60)==0)
lprintf("%04d Still waiting for transfer to complete " lprintf(LOG_WARNING,"%04d Still waiting for transfer to complete "
"(count=%lu, aborted=%d, lastactive=%lX) ..." "(count=%lu, aborted=%d, lastactive=%lX) ..."
,sock,count,transfer_aborted,lastactive); ,sock,count,transfer_aborted,lastactive);
count++; count++;
mswait(1000); mswait(1000);
} }
lprintf("%04d Done waiting for transfer to complete",sock); lprintf(LOG_DEBUG,"%04d Done waiting for transfer to complete",sock);
} }
/* Update User Statistics */ /* Update User Statistics */
...@@ -4375,7 +4368,7 @@ static void ctrl_thread(void* arg) ...@@ -4375,7 +4368,7 @@ static void ctrl_thread(void* arg)
logoutuserdat(&scfg, &user, time(NULL), logintime); logoutuserdat(&scfg, &user, time(NULL), logintime);
if(user.number) if(user.number)
lprintf("%04d %s logged off",sock,user.alias); lprintf(LOG_INFO,"%04d %s logged off",sock,user.alias);
#ifdef _WIN32 #ifdef _WIN32
if(startup->hangup_sound[0] && !(startup->options&FTP_OPT_MUTE)) if(startup->hangup_sound[0] && !(startup->options&FTP_OPT_MUTE))
...@@ -4384,12 +4377,12 @@ static void ctrl_thread(void* arg) ...@@ -4384,12 +4377,12 @@ static void ctrl_thread(void* arg)
#ifdef JAVASCRIPT #ifdef JAVASCRIPT
if(js_cx!=NULL) { if(js_cx!=NULL) {
lprintf("%04d JavaScript: Destroying context",sock); lprintf(LOG_DEBUG,"%04d JavaScript: Destroying context",sock);
JS_DestroyContext(js_cx); /* Free Context */ JS_DestroyContext(js_cx); /* Free Context */
} }
if(js_runtime!=NULL) { if(js_runtime!=NULL) {
lprintf("%04d JavaScript: Destroying runtime",sock); lprintf(LOG_DEBUG,"%04d JavaScript: Destroying runtime",sock);
JS_DestroyRuntime(js_runtime); JS_DestroyRuntime(js_runtime);
} }
...@@ -4419,14 +4412,14 @@ static void ctrl_thread(void* arg) ...@@ -4419,14 +4412,14 @@ static void ctrl_thread(void* arg)
active_clients--, update_clients(); active_clients--, update_clients();
thread_down(); thread_down();
lprintf("%04d CTRL thread terminated (%d clients, %u threads remain, %lu served)" lprintf(LOG_DEBUG,"%04d CTRL thread terminated (%d clients, %u threads remain, %lu served)"
,sock, active_clients, thread_count, served); ,sock, active_clients, thread_count, served);
} }
static void cleanup(int code, int line) static void cleanup(int code, int line)
{ {
#ifdef _DEBUG #ifdef _DEBUG
lprintf("0000 cleanup called from line %d",line); lprintf(LOG_INFO,"0000 cleanup called from line %d",line);
#endif #endif
free_cfg(&scfg); free_cfg(&scfg);
...@@ -4437,13 +4430,13 @@ static void cleanup(int code, int line) ...@@ -4437,13 +4430,13 @@ static void cleanup(int code, int line)
#ifdef _WINSOCKAPI_ #ifdef _WINSOCKAPI_
if(WSAInitialized && WSACleanup()!=0) if(WSAInitialized && WSACleanup()!=0)
lprintf("0000 !WSACleanup ERROR %d",ERROR_VALUE); lprintf(LOG_ERR,"0000 !WSACleanup ERROR %d",ERROR_VALUE);
#endif #endif
thread_down(); thread_down();
status("Down"); status("Down");
if(code) if(code)
lprintf("#### FTP Server thread terminated (%u threads remain, %lu clients served)" lprintf(LOG_INFO,"#### FTP Server thread terminated (%u threads remain, %lu clients served)"
,thread_count, served); ,thread_count, served);
if(startup!=NULL && startup->terminated!=NULL) if(startup!=NULL && startup->terminated!=NULL)
startup->terminated(startup->cbdata,code); startup->terminated(startup->cbdata,code);
...@@ -4545,7 +4538,7 @@ void DLLCALL ftp_server(void* arg) ...@@ -4545,7 +4538,7 @@ void DLLCALL ftp_server(void* arg)
memset(&scfg, 0, sizeof(scfg)); memset(&scfg, 0, sizeof(scfg));
lprintf("Synchronet FTP Server Revision %s%s" lprintf(LOG_INFO,"Synchronet FTP Server Revision %s%s"
,revision ,revision
#ifdef _DEBUG #ifdef _DEBUG
," Debug" ," Debug"
...@@ -4556,7 +4549,7 @@ void DLLCALL ftp_server(void* arg) ...@@ -4556,7 +4549,7 @@ void DLLCALL ftp_server(void* arg)
DESCRIBE_COMPILER(compiler); DESCRIBE_COMPILER(compiler);
lprintf("Compiled %s %s with %s", __DATE__, __TIME__, compiler); lprintf(LOG_INFO,"Compiled %s %s with %s", __DATE__, __TIME__, compiler);
srand(time(NULL)); /* Seed random number generator */ srand(time(NULL)); /* Seed random number generator */
sbbs_random(10); /* Throw away first number */ sbbs_random(10); /* Throw away first number */
...@@ -4567,17 +4560,17 @@ void DLLCALL ftp_server(void* arg) ...@@ -4567,17 +4560,17 @@ void DLLCALL ftp_server(void* arg)
} }
t=time(NULL); t=time(NULL);
lprintf("Initializing on %.24s with options: %lx" lprintf(LOG_INFO,"Initializing on %.24s with options: %lx"
,CTIME_R(&t,str),startup->options); ,CTIME_R(&t,str),startup->options);
/* Initial configuration and load from CNF files */ /* Initial configuration and load from CNF files */
SAFECOPY(scfg.ctrl_dir, startup->ctrl_dir); SAFECOPY(scfg.ctrl_dir, startup->ctrl_dir);
lprintf("Loading configuration files from %s", scfg.ctrl_dir); lprintf(LOG_INFO,"Loading configuration files from %s", scfg.ctrl_dir);
scfg.size=sizeof(scfg); scfg.size=sizeof(scfg);
SAFECOPY(error,UNKNOWN_LOAD_ERROR); SAFECOPY(error,UNKNOWN_LOAD_ERROR);
if(!load_cfg(&scfg, text, TRUE, error)) { if(!load_cfg(&scfg, text, TRUE, error)) {
lprintf("!ERROR %s",error); lprintf(LOG_ERR,"!ERROR %s",error);
lprintf("!Failed to load configuration files"); lprintf(LOG_ERR,"!Failed to load configuration files");
cleanup(1,__LINE__); cleanup(1,__LINE__);
return; return;
} }
...@@ -4587,11 +4580,11 @@ void DLLCALL ftp_server(void* arg) ...@@ -4587,11 +4580,11 @@ void DLLCALL ftp_server(void* arg)
if(!(scfg.sys_misc&SM_LOCAL_TZ) && !(startup->options&FTP_OPT_LOCAL_TIMEZONE)) { if(!(scfg.sys_misc&SM_LOCAL_TZ) && !(startup->options&FTP_OPT_LOCAL_TIMEZONE)) {
if(putenv("TZ=UTC0")) if(putenv("TZ=UTC0"))
lprintf("!putenv() FAILED"); lprintf(LOG_ERR,"!putenv() FAILED");
tzset(); tzset();
if((t=checktime())!=0) { /* Check binary time */ if((t=checktime())!=0) { /* Check binary time */
lprintf("!TIME PROBLEM (%ld)",t); lprintf(LOG_ERR,"!TIME PROBLEM (%ld)",t);
cleanup(1,__LINE__); cleanup(1,__LINE__);
return; return;
} }
...@@ -4611,9 +4604,9 @@ void DLLCALL ftp_server(void* arg) ...@@ -4611,9 +4604,9 @@ void DLLCALL ftp_server(void* arg)
if(startup->max_clients<10) if(startup->max_clients<10)
startup->max_clients=10; startup->max_clients=10;
} }
lprintf("Maximum clients: %d",startup->max_clients); lprintf(LOG_DEBUG,"Maximum clients: %d",startup->max_clients);
lprintf("Maximum inactivity: %d seconds",startup->max_inactivity); lprintf(LOG_DEBUG,"Maximum inactivity: %d seconds",startup->max_inactivity);
active_clients=0, update_clients(); active_clients=0, update_clients();
...@@ -4630,12 +4623,12 @@ void DLLCALL ftp_server(void* arg) ...@@ -4630,12 +4623,12 @@ void DLLCALL ftp_server(void* arg)
/* open a socket and wait for a client */ /* open a socket and wait for a client */
if((server_socket=ftp_open_socket(SOCK_STREAM))==INVALID_SOCKET) { if((server_socket=ftp_open_socket(SOCK_STREAM))==INVALID_SOCKET) {
lprintf("!ERROR %d opening socket", ERROR_VALUE); lprintf(LOG_ERR,"!ERROR %d opening socket", ERROR_VALUE);
cleanup(1,__LINE__); cleanup(1,__LINE__);
return; return;
} }
lprintf("%04d FTP socket opened",server_socket); lprintf(LOG_DEBUG,"%04d FTP socket opened",server_socket);
/*****************************/ /*****************************/
/* Listen for incoming calls */ /* Listen for incoming calls */
...@@ -4652,21 +4645,21 @@ void DLLCALL ftp_server(void* arg) ...@@ -4652,21 +4645,21 @@ void DLLCALL ftp_server(void* arg)
if(startup->seteuid!=NULL) if(startup->seteuid!=NULL)
startup->seteuid(TRUE); startup->seteuid(TRUE);
if(result!=0) { if(result!=0) {
lprintf("%04d !ERROR %d (%d) binding socket to port %u" lprintf(LOG_ERR,"%04d !ERROR %d (%d) binding socket to port %u"
,server_socket, result, ERROR_VALUE,startup->port); ,server_socket, result, ERROR_VALUE,startup->port);
lprintf("%04d %s", server_socket, BIND_FAILURE_HELP); lprintf(LOG_ERR,"%04d %s", server_socket, BIND_FAILURE_HELP);
cleanup(1,__LINE__); cleanup(1,__LINE__);
return; return;
} }
if((result=listen(server_socket, 1))!= 0) { if((result=listen(server_socket, 1))!= 0) {
lprintf("%04d !ERROR %d (%d) listening on socket" lprintf(LOG_ERR,"%04d !ERROR %d (%d) listening on socket"
,server_socket, result, ERROR_VALUE); ,server_socket, result, ERROR_VALUE);
cleanup(1,__LINE__); cleanup(1,__LINE__);
return; return;
} }
lprintf("%04d FTP Server thread started on port %d",server_socket,startup->port); lprintf(LOG_NOTICE,"%04d FTP Server thread started on port %d",server_socket,startup->port);
status(STATUS_WFC); status(STATUS_WFC);
if(initialized==0) { if(initialized==0) {
...@@ -4687,14 +4680,14 @@ void DLLCALL ftp_server(void* arg) ...@@ -4687,14 +4680,14 @@ void DLLCALL ftp_server(void* arg)
sprintf(path,"%sftpsrvr.rec",scfg.ctrl_dir); sprintf(path,"%sftpsrvr.rec",scfg.ctrl_dir);
t=fdate(path); t=fdate(path);
if(!active_clients && t!=-1 && t>initialized) { if(!active_clients && t!=-1 && t>initialized) {
lprintf("0000 Recycle semaphore file (%s) detected", path); lprintf(LOG_NOTICE,"0000 Recycle semaphore file (%s) detected", path);
initialized=t; initialized=t;
break; break;
} }
if(startup->recycle_sem!=NULL && sem_trywait(&startup->recycle_sem)==0) if(startup->recycle_sem!=NULL && sem_trywait(&startup->recycle_sem)==0)
startup->recycle_now=TRUE; startup->recycle_now=TRUE;
if(!active_clients && startup->recycle_now==TRUE) { if(!active_clients && startup->recycle_now==TRUE) {
lprintf("0000 Recycle semaphore signaled"); lprintf(LOG_NOTICE,"0000 Recycle semaphore signaled");
startup->recycle_now=FALSE; startup->recycle_now=FALSE;
break; break;
} }
...@@ -4711,11 +4704,11 @@ void DLLCALL ftp_server(void* arg) ...@@ -4711,11 +4704,11 @@ void DLLCALL ftp_server(void* arg)
if(i==0) if(i==0)
continue; continue;
if(ERROR_VALUE==EINTR) if(ERROR_VALUE==EINTR)
lprintf("0000 FTP Server listening interrupted"); lprintf(LOG_NOTICE,"0000 FTP Server listening interrupted");
else if(ERROR_VALUE == ENOTSOCK) else if(ERROR_VALUE == ENOTSOCK)
lprintf("0000 FTP Server sockets closed"); lprintf(LOG_NOTICE,"0000 FTP Server sockets closed");
else else
lprintf("0000 !ERROR %d selecting sockets",ERROR_VALUE); lprintf(LOG_WARNING,"0000 !ERROR %d selecting sockets",ERROR_VALUE);
break; break;
} }
...@@ -4729,9 +4722,9 @@ void DLLCALL ftp_server(void* arg) ...@@ -4729,9 +4722,9 @@ void DLLCALL ftp_server(void* arg)
if(client_socket == INVALID_SOCKET) if(client_socket == INVALID_SOCKET)
{ {
if(ERROR_VALUE == ENOTSOCK || ERROR_VALUE == EINTR || ERROR_VALUE == EINVAL) if(ERROR_VALUE == ENOTSOCK || ERROR_VALUE == EINTR || ERROR_VALUE == EINVAL)
lprintf("0000 FTP socket closed while listening"); lprintf(LOG_NOTICE,"0000 FTP socket closed while listening");
else else
lprintf("0000 !ERROR %d accepting connection", ERROR_VALUE); lprintf(LOG_WARNING,"0000 !ERROR %d accepting connection", ERROR_VALUE);
break; break;
} }
if(startup->socket_open!=NULL) if(startup->socket_open!=NULL)
...@@ -4744,7 +4737,7 @@ void DLLCALL ftp_server(void* arg) ...@@ -4744,7 +4737,7 @@ void DLLCALL ftp_server(void* arg)
} }
if(active_clients>=startup->max_clients) { if(active_clients>=startup->max_clients) {
lprintf("%04d !MAXMIMUM CLIENTS (%d) reached, access denied" lprintf(LOG_WARNING,"%04d !MAXMIMUM CLIENTS (%d) reached, access denied"
,client_socket, startup->max_clients); ,client_socket, startup->max_clients);
sockprintf(client_socket,"421 Maximum active clients reached, please try again later."); sockprintf(client_socket,"421 Maximum active clients reached, please try again later.");
mswait(3000); mswait(3000);
...@@ -4753,7 +4746,7 @@ void DLLCALL ftp_server(void* arg) ...@@ -4753,7 +4746,7 @@ void DLLCALL ftp_server(void* arg)
} }
if((ftp=malloc(sizeof(ftp_t)))==NULL) { if((ftp=malloc(sizeof(ftp_t)))==NULL) {
lprintf("%04d !ERROR allocating %d bytes of memory for ftp_t" lprintf(LOG_CRIT,"%04d !ERROR allocating %d bytes of memory for ftp_t"
,client_socket,sizeof(ftp_t)); ,client_socket,sizeof(ftp_t));
sockprintf(client_socket,"421 System error, please try again later."); sockprintf(client_socket,"421 System error, please try again later.");
mswait(3000); mswait(3000);
...@@ -4769,39 +4762,39 @@ void DLLCALL ftp_server(void* arg) ...@@ -4769,39 +4762,39 @@ void DLLCALL ftp_server(void* arg)
} }
if(active_clients) { if(active_clients) {
lprintf("0000 Waiting for %d active clients to disconnect...", active_clients); lprintf(LOG_DEBUG,"0000 Waiting for %d active clients to disconnect...", active_clients);
start=time(NULL); start=time(NULL);
while(active_clients) { while(active_clients) {
if(time(NULL)-start>TIMEOUT_THREAD_WAIT) { if(time(NULL)-start>TIMEOUT_THREAD_WAIT) {
lprintf("0000 !TIMEOUT waiting for %d active clients", active_clients); lprintf(LOG_WARNING,"0000 !TIMEOUT waiting for %d active clients", active_clients);
break; break;
} }
mswait(100); mswait(100);
} }
lprintf("0000 Done waiting"); lprintf(LOG_DEBUG,"0000 Done waiting");
} }
if(thread_count>1) { if(thread_count>1) {
lprintf("0000 Waiting for %d threads to terminate...", thread_count-1); lprintf(LOG_DEBUG,"0000 Waiting for %d threads to terminate...", thread_count-1);
start=time(NULL); start=time(NULL);
while(thread_count>1) { while(thread_count>1) {
if(time(NULL)-start>TIMEOUT_THREAD_WAIT) { if(time(NULL)-start>TIMEOUT_THREAD_WAIT) {
lprintf("0000 !TIMEOUT waiting for %d threads",thread_count-1); lprintf(LOG_WARNING,"0000 !TIMEOUT waiting for %d threads",thread_count-1);
break; break;
} }
mswait(100); mswait(100);
} }
lprintf("0000 Done waiting"); lprintf(LOG_DEBUG,"0000 Done waiting");
} }
cleanup(0,__LINE__); cleanup(0,__LINE__);
if(recycle_server) { if(recycle_server) {
lprintf("Recycling server..."); lprintf(LOG_INFO,"Recycling server...");
mswait(2000); mswait(2000);
} }
} while(recycle_server); } while(recycle_server);
lprintf("#### FTP Server thread terminated (%u threads remain, %lu clients served)", thread_count, served); lprintf(LOG_INFO,"#### FTP Server thread terminated (%u threads remain, %lu clients served)", thread_count, served);
} }
This diff is collapsed.
0% Loading or .
You are about to add 0 people to the discussion. Proceed with caution.
Please register or to comment