diff --git a/src/sbbs3/ftpsrvr.c b/src/sbbs3/ftpsrvr.c index c73c909c58c4dee907469dc0505f0cf76d94b3d4..03e5f533b1a3fe8589cad1c024e563e3e58e7677 100644 --- a/src/sbbs3/ftpsrvr.c +++ b/src/sbbs3/ftpsrvr.c @@ -728,34 +728,34 @@ BOOL js_generate_index(JSContext* js_cx, JSObject* parent, long double start=xp_timer(); jsrefcount rc; - lprintf(LOG_DEBUG,"%04d JavaScript: Generating HTML Index for %s" - ,sock, genvpath(lib,dir,str)); + lprintf(LOG_DEBUG,"%04d <%s> JavaScript: Generating HTML Index for %s" + ,sock, user->alias, genvpath(lib,dir,str)); JS_SetContextPrivate(js_cx, fp); do { /* pseudo try/catch */ if((file_array=JS_NewArrayObject(js_cx, 0, NULL))==NULL) { - lprintf(LOG_ERR,"%04d !JavaScript FAILED to create file_array",sock); + lprintf(LOG_ERR,"%04d <%s> !JavaScript FAILED to create file_array",sock, user->alias); break; } /* file[] */ val=OBJECT_TO_JSVAL(file_array); if(!JS_SetProperty(js_cx, parent, "file_list", &val)) { - lprintf(LOG_ERR,"%04d !JavaScript FAILED to set file property",sock); + lprintf(LOG_ERR,"%04d <%s> !JavaScript FAILED to set file property",sock, user->alias); break; } if((dir_array=JS_NewArrayObject(js_cx, 0, NULL))==NULL) { - lprintf(LOG_ERR,"%04d !JavaScript FAILED to create dir_array",sock); + lprintf(LOG_ERR,"%04d <%s> !JavaScript FAILED to create dir_array",sock, user->alias); break; } /* dir[] */ val=OBJECT_TO_JSVAL(dir_array); if(!JS_SetProperty(js_cx, parent, "dir_list", &val)) { - lprintf(LOG_ERR,"%04d !JavaScript FAILED to set dir property",sock); + lprintf(LOG_ERR,"%04d <%s> !JavaScript FAILED to set dir property",sock, user->alias); break; } @@ -772,7 +772,7 @@ BOOL js_generate_index(JSContext* js_cx, JSObject* parent, if(!fexist(spath)) { JS_RESUMEREQUEST(js_cx, rc); - lprintf(LOG_ERR,"%04d !HTML JavaScript (%s) doesn't exist",sock,spath); + lprintf(LOG_ERR,"%04d <%s> !HTML JavaScript (%s) doesn't exist",sock,user->alias, spath); break; } JS_RESUMEREQUEST(js_cx, rc); @@ -781,31 +781,31 @@ BOOL js_generate_index(JSContext* js_cx, JSObject* parent, break; val=STRING_TO_JSVAL(js_str); if(!JS_SetProperty(js_cx, parent, "html_index_file", &val)) { - lprintf(LOG_ERR,"%04d !JavaScript FAILED to set html_index_file property",sock); + lprintf(LOG_ERR,"%04d <%s> !JavaScript FAILED to set html_index_file property",sock, user->alias); break; } /* curlib */ if((lib_obj=JS_NewObject(js_cx, NULL, 0, NULL))==NULL) { - lprintf(LOG_ERR,"%04d !JavaScript FAILED to create lib_obj",sock); + lprintf(LOG_ERR,"%04d <%s> !JavaScript FAILED to create lib_obj",sock, user->alias); break; } val=OBJECT_TO_JSVAL(lib_obj); if(!JS_SetProperty(js_cx, parent, "curlib", &val)) { - lprintf(LOG_ERR,"%04d !JavaScript FAILED to set curlib property",sock); + lprintf(LOG_ERR,"%04d <%s> !JavaScript FAILED to set curlib property",sock, user->alias); break; } /* curdir */ if((dir_obj=JS_NewObject(js_cx, NULL, 0, NULL))==NULL) { - lprintf(LOG_ERR,"%04d !JavaScript FAILED to create dir_obj",sock); + lprintf(LOG_ERR,"%04d <%s> !JavaScript FAILED to create dir_obj",sock, user->alias); break; } val=OBJECT_TO_JSVAL(dir_obj); if(!JS_SetProperty(js_cx, parent, "curdir", &val)) { - lprintf(LOG_ERR,"%04d !JavaScript FAILED to set curdir property",sock); + lprintf(LOG_ERR,"%04d <%s> !JavaScript FAILED to set curdir property",sock, user->alias); break; } @@ -820,7 +820,7 @@ BOOL js_generate_index(JSContext* js_cx, JSObject* parent, break; val=STRING_TO_JSVAL(js_str); if(!JS_SetProperty(js_cx, lib_obj, "name", &val)) { - lprintf(LOG_ERR,"%04d !JavaScript FAILED to set curlib.name property",sock); + lprintf(LOG_ERR,"%04d <%s> !JavaScript FAILED to set curlib.name property",sock, user->alias); break; } @@ -828,7 +828,7 @@ BOOL js_generate_index(JSContext* js_cx, JSObject* parent, break; val=STRING_TO_JSVAL(js_str); if(!JS_SetProperty(js_cx, lib_obj, "description", &val)) { - lprintf(LOG_ERR,"%04d !JavaScript FAILED to set curlib.desc property",sock); + lprintf(LOG_ERR,"%04d <%s> !JavaScript FAILED to set curlib.desc property",sock, user->alias); break; } } @@ -841,7 +841,7 @@ BOOL js_generate_index(JSContext* js_cx, JSObject* parent, break; val=STRING_TO_JSVAL(js_str); if(!JS_SetProperty(js_cx, dir_obj, "code", &val)) { - lprintf(LOG_ERR,"%04d !JavaScript FAILED to set curdir.code property",sock); + lprintf(LOG_ERR,"%04d <%s> !JavaScript FAILED to set curdir.code property",sock, user->alias); break; } @@ -849,7 +849,7 @@ BOOL js_generate_index(JSContext* js_cx, JSObject* parent, break; val=STRING_TO_JSVAL(js_str); if(!JS_SetProperty(js_cx, dir_obj, "name", &val)) { - lprintf(LOG_ERR,"%04d !JavaScript FAILED to set curdir.name property",sock); + lprintf(LOG_ERR,"%04d <%s> !JavaScript FAILED to set curdir.name property",sock, user->alias); break; } @@ -857,13 +857,13 @@ BOOL js_generate_index(JSContext* js_cx, JSObject* parent, break; val=STRING_TO_JSVAL(js_str); if(!JS_SetProperty(js_cx, dir_obj, "description", &val)) { - lprintf(LOG_ERR,"%04d !JavaScript FAILED to set curdir.desc property",sock); + lprintf(LOG_ERR,"%04d <%s> !JavaScript FAILED to set curdir.desc property",sock, user->alias); break; } val=INT_TO_JSVAL(scfg.dir[dir]->misc); if(!JS_SetProperty(js_cx, dir_obj, "settings", &val)) { - lprintf(LOG_ERR,"%04d !JavaScript FAILED to set curdir.misc property",sock); + lprintf(LOG_ERR,"%04d <%s> !JavaScript FAILED to set curdir.misc property",sock, user->alias); break; } } @@ -872,7 +872,7 @@ BOOL js_generate_index(JSContext* js_cx, JSObject* parent, break; val=STRING_TO_JSVAL(js_str); if(!JS_SetProperty(js_cx, parent, "path", &val)) { - lprintf(LOG_ERR,"%04d !JavaScript FAILED to set curdir property",sock); + lprintf(LOG_ERR,"%04d <%s> !JavaScript FAILED to set curdir property",sock, user->alias); break; } @@ -1077,18 +1077,18 @@ BOOL js_generate_index(JSContext* js_cx, JSObject* parent, JS_ClearPendingException(js_cx); if((js_script=JS_CompileFile(js_cx, parent, spath))==NULL) { - lprintf(LOG_ERR,"%04d !JavaScript FAILED to compile script (%s)",sock,spath); + lprintf(LOG_ERR,"%04d <%s> !JavaScript FAILED to compile script (%s)",sock, user->alias, spath); break; } js_PrepareToExecute(js_cx, parent, spath, /* startup_dir: */NULL, parent); if((success=JS_ExecuteScript(js_cx, parent, js_script, &rval))!=TRUE) { - lprintf(LOG_ERR,"%04d !JavaScript FAILED to execute script (%s)",sock,spath); + lprintf(LOG_ERR,"%04d <%s> !JavaScript FAILED to execute script (%s)",sock, user->alias, spath); break; } - lprintf(LOG_DEBUG,"%04d JavaScript: Done executing script: %s (%.2Lf seconds)" - ,sock,spath,xp_timer()-start); + lprintf(LOG_DEBUG,"%04d <%s> JavaScript: Done executing script: %s (%.2Lf seconds)" + ,sock, user->alias, spath, xp_timer()-start); } while(0); @@ -1394,8 +1394,8 @@ static void send_thread(void* arg) if((fp=fnopen(NULL,xfer.filename,O_RDONLY|O_BINARY))==NULL /* non-shareable open failed */ && (fp=fopen(xfer.filename,"rb"))==NULL) { /* shareable open failed */ - lprintf(LOG_ERR,"%04d !DATA ERROR %d (%s) line %d opening %s (useron=%s)" - ,xfer.ctrl_sock, errno, strerror(errno), __LINE__, xfer.filename, xfer.user->alias); + lprintf(LOG_ERR,"%04d <%s> !DATA ERROR %d (%s) line %d opening %s" + ,xfer.ctrl_sock, xfer.user->alias, errno, strerror(errno), __LINE__, xfer.filename); sockprintf(xfer.ctrl_sock,xfer.ctrl_sess,"450 ERROR %d opening %s.",errno,xfer.filename); if(xfer.tmpfile && !(startup->options&FTP_OPT_KEEP_TEMP_FILES)) ftp_remove(xfer.ctrl_sock, __LINE__, xfer.filename); @@ -1411,8 +1411,8 @@ static void send_thread(void* arg) *xfer.aborted=FALSE; if(startup->options&FTP_OPT_DEBUG_DATA || xfer.filepos) - lprintf(LOG_DEBUG,"%04d DATA socket %d sending %s from offset %lu" - ,xfer.ctrl_sock,*xfer.data_sock,xfer.filename,xfer.filepos); + lprintf(LOG_DEBUG,"%04d <%s> DATA socket %d sending %s from offset %lu" + ,xfer.ctrl_sock, xfer.user->alias, *xfer.data_sock,xfer.filename,xfer.filepos); fseek(fp,xfer.filepos,SEEK_SET); last_report=start=time(NULL); @@ -1426,8 +1426,8 @@ static void send_thread(void* arg) sprintf(str," from offset %lu",xfer.filepos); else str[0]=0; - lprintf(LOG_INFO,"%04d Sent %lu bytes (%lu total) of %s (%lu cps)%s" - ,xfer.ctrl_sock,total,length,xfer.filename + lprintf(LOG_INFO,"%04d <%s> DATA Sent %lu bytes (%lu total) of %s (%lu cps)%s" + ,xfer.ctrl_sock, xfer.user->alias, total,length,xfer.filename ,(ulong)((total-last_total)/(now-last_report)) ,str); last_total=total; @@ -1435,13 +1435,13 @@ static void send_thread(void* arg) } if(*xfer.aborted==TRUE) { - lprintf(LOG_WARNING,"%04d !DATA Transfer aborted",xfer.ctrl_sock); + lprintf(LOG_WARNING,"%04d <%s> !DATA Transfer aborted",xfer.ctrl_sock, xfer.user->alias); sockprintf(xfer.ctrl_sock,xfer.ctrl_sess,"426 Transfer aborted."); error=TRUE; break; } if(ftp_set==NULL || terminate_server) { - lprintf(LOG_WARNING,"%04d !DATA Transfer locally aborted",xfer.ctrl_sock); + lprintf(LOG_WARNING,"%04d <%s> !DATA Transfer locally aborted",xfer.ctrl_sock, xfer.user->alias); sockprintf(xfer.ctrl_sock,xfer.ctrl_sess,"426 Transfer locally aborted."); error=TRUE; break; @@ -1456,8 +1456,8 @@ static void send_thread(void* arg) i=select((*xfer.data_sock)+1,NULL,&socket_set,NULL,&tv); if(i==SOCKET_ERROR) { - lprintf(LOG_WARNING,"%04d !DATA ERROR %d selecting socket %d for send" - ,xfer.ctrl_sock, ERROR_VALUE, *xfer.data_sock); + lprintf(LOG_WARNING,"%04d <%s> !DATA ERROR %d selecting socket %d for send" + ,xfer.ctrl_sock, xfer.user->alias, ERROR_VALUE, *xfer.data_sock); sockprintf(xfer.ctrl_sock,xfer.ctrl_sess,"426 Transfer error."); error=TRUE; break; @@ -1500,14 +1500,14 @@ static void send_thread(void* arg) continue; } else if(ERROR_VALUE==ECONNRESET) - lprintf(LOG_WARNING,"%04d DATA Connection reset by peer, sending on socket %d" - ,xfer.ctrl_sock,*xfer.data_sock); + lprintf(LOG_WARNING,"%04d <%s> DATA Connection reset by peer, sending on socket %d" + ,xfer.ctrl_sock, xfer.user->alias,*xfer.data_sock); else if(ERROR_VALUE==ECONNABORTED) - lprintf(LOG_WARNING,"%04d DATA Connection aborted by peer, sending on socket %d" - ,xfer.ctrl_sock,*xfer.data_sock); + lprintf(LOG_WARNING,"%04d <%s> DATA Connection aborted by peer, sending on socket %d" + ,xfer.ctrl_sock, xfer.user->alias,*xfer.data_sock); else - lprintf(LOG_WARNING,"%04d !DATA ERROR %d sending on data socket %d" - ,xfer.ctrl_sock,ERROR_VALUE,*xfer.data_sock); + lprintf(LOG_WARNING,"%04d <%s> !DATA ERROR %d sending on data socket %d" + ,xfer.ctrl_sock, xfer.user->alias,ERROR_VALUE,*xfer.data_sock); /* Send NAK */ sockprintf(xfer.ctrl_sock,xfer.ctrl_sess,"426 Error %d sending on DATA channel" ,ERROR_VALUE); @@ -1515,13 +1515,13 @@ static void send_thread(void* arg) break; } if(wr==0) { - lprintf(LOG_WARNING,"%04d !DATA socket %d disconnected",xfer.ctrl_sock, *xfer.data_sock); + lprintf(LOG_WARNING,"%04d <%s> !DATA socket %d disconnected",xfer.ctrl_sock, xfer.user->alias, *xfer.data_sock); sockprintf(xfer.ctrl_sock,xfer.ctrl_sess,"426 DATA channel disconnected"); error=TRUE; break; } - lprintf(LOG_ERR,"%04d !DATA SEND ERROR %d (%d) on socket %d" - ,xfer.ctrl_sock, wr, ERROR_VALUE, *xfer.data_sock); + lprintf(LOG_ERR,"%04d <%s> !DATA ERROR %d (%d) sending on socket %d" + ,xfer.ctrl_sock, xfer.user->alias, wr, ERROR_VALUE, *xfer.data_sock); sockprintf(xfer.ctrl_sock,xfer.ctrl_sess,"451 DATA send error"); error=TRUE; break; @@ -1532,17 +1532,19 @@ static void send_thread(void* arg) } if((i=ferror(fp))!=0) - lprintf(LOG_ERR,"%04d !FILE ERROR %d (%d)",xfer.ctrl_sock,i,errno); + lprintf(LOG_ERR,"%04d <%s> !DATA FILE ERROR %d (%d, %s)" + ,xfer.ctrl_sock, xfer.user->alias, i, errno, strerror(errno)); ftp_close_socket(xfer.data_sock,xfer.data_sess,__LINE__); /* Signal end of file */ if(startup->options&FTP_OPT_DEBUG_DATA) - lprintf(LOG_DEBUG,"%04d DATA socket closed",xfer.ctrl_sock); + lprintf(LOG_DEBUG,"%04d <%s> DATA socket closed",xfer.ctrl_sock, xfer.user->alias); if(!error) { dur=(long)(time(NULL)-start); cps=dur ? total/dur : total*2; - lprintf(LOG_INFO,"%04d Transfer successful: %lu bytes sent in %lu seconds (%lu cps)" + lprintf(LOG_INFO,"%04d <%s> DATA Transfer successful: %lu bytes sent in %lu seconds (%lu cps)" ,xfer.ctrl_sock + ,xfer.user->alias ,total,dur,cps); sockprintf(xfer.ctrl_sock,xfer.ctrl_sess,"226 Download complete (%lu cps).",cps); @@ -1562,7 +1564,7 @@ static void send_thread(void* arg) f.datedled=time32(NULL); putfileixb(&scfg,&f); - lprintf(LOG_INFO,"%04d %s downloaded: %s (%u times total)" + lprintf(LOG_INFO,"%04d <%s> DATA downloaded: %s (%u times total)" ,xfer.ctrl_sock ,xfer.user->alias ,xfer.filename @@ -1669,8 +1671,8 @@ static void receive_thread(void* arg) thread_up(TRUE /* setuid */); if((fp=fopen(xfer.filename,xfer.append ? "ab" : "wb"))==NULL) { - lprintf(LOG_ERR,"%04d !DATA ERROR %d (%s) line %d opening %s (useron=%s)" - ,xfer.ctrl_sock, errno, strerror(errno), __LINE__, xfer.filename, xfer.user->alias); + lprintf(LOG_ERR,"%04d <%s> !DATA ERROR %d (%s) line %d opening %s" + ,xfer.ctrl_sock, xfer.user->alias, errno, strerror(errno), __LINE__, xfer.filename); sockprintf(xfer.ctrl_sock,sess,"450 ERROR %d opening %s.",errno,xfer.filename); ftp_close_socket(xfer.data_sock,xfer.data_sess,__LINE__); *xfer.inprogress=FALSE; @@ -1683,8 +1685,8 @@ static void receive_thread(void* arg) *xfer.aborted=FALSE; if(xfer.filepos || startup->options&FTP_OPT_DEBUG_DATA) - lprintf(LOG_DEBUG,"%04d DATA socket %d receiving %s from offset %lu" - ,xfer.ctrl_sock,*xfer.data_sock,xfer.filename,xfer.filepos); + lprintf(LOG_DEBUG,"%04d <%s> DATA socket %d receiving %s from offset %lu" + ,xfer.ctrl_sock,xfer.user->alias, *xfer.data_sock,xfer.filename,xfer.filepos); fseek(fp,xfer.filepos,SEEK_SET); last_report=start=time(NULL); @@ -1698,29 +1700,31 @@ static void receive_thread(void* arg) sprintf(str," from offset %lu",xfer.filepos); else str[0]=0; - lprintf(LOG_INFO,"%04d Received %lu bytes of %s (%lu cps)%s" - ,xfer.ctrl_sock,total,xfer.filename + lprintf(LOG_INFO,"%04d <%s> DATA Received %lu bytes of %s (%lu cps)%s" + ,xfer.ctrl_sock + ,xfer.user->alias + ,total,xfer.filename ,(ulong)((total-last_total)/(now-last_report)) ,str); last_total=total; last_report=now; } if(startup->max_fsize && (xfer.filepos+total) > startup->max_fsize) { - lprintf(LOG_WARNING,"%04d !DATA received %lu bytes of %s exceeds maximum allowed (%lu bytes)" - ,xfer.ctrl_sock, xfer.filepos+total, xfer.filename, startup->max_fsize); + lprintf(LOG_WARNING,"%04d <%s> !DATA received %lu bytes of %s exceeds maximum allowed (%lu bytes)" + ,xfer.ctrl_sock, xfer.user->alias, xfer.filepos+total, xfer.filename, startup->max_fsize); sockprintf(xfer.ctrl_sock,sess,"552 File size exceeds maximum allowed (%lu bytes)", startup->max_fsize); error=TRUE; break; } if(*xfer.aborted==TRUE) { - lprintf(LOG_WARNING,"%04d !DATA Transfer aborted",xfer.ctrl_sock); + lprintf(LOG_WARNING,"%04d <%s> !DATA Transfer aborted",xfer.ctrl_sock, xfer.user->alias); /* Send NAK */ sockprintf(xfer.ctrl_sock,sess,"426 Transfer aborted."); error=TRUE; break; } if(ftp_set==NULL || terminate_server) { - lprintf(LOG_WARNING,"%04d !DATA Transfer locally aborted",xfer.ctrl_sock); + lprintf(LOG_WARNING,"%04d <%s> !DATA Transfer locally aborted",xfer.ctrl_sock, xfer.user->alias); /* Send NAK */ sockprintf(xfer.ctrl_sock,sess,"426 Transfer locally aborted."); error=TRUE; @@ -1736,8 +1740,8 @@ static void receive_thread(void* arg) i=select((*xfer.data_sock)+1,&socket_set,NULL,NULL,&tv); if(i==SOCKET_ERROR) { - lprintf(LOG_WARNING,"%04d !DATA ERROR %d selecting socket %d for receive" - ,xfer.ctrl_sock, ERROR_VALUE, *xfer.data_sock); + lprintf(LOG_WARNING,"%04d <%s> !DATA ERROR %d selecting socket %d for receive" + ,xfer.ctrl_sock, xfer.user->alias, ERROR_VALUE, *xfer.data_sock); sockprintf(xfer.ctrl_sock,sess,"426 Transfer error."); error=TRUE; break; @@ -1764,8 +1768,8 @@ static void receive_thread(void* arg) if(rd<1) { if(rd==0) { /* Socket closed */ if(startup->options&FTP_OPT_DEBUG_DATA) - lprintf(LOG_DEBUG,"%04d DATA socket %d closed by client" - ,xfer.ctrl_sock,*xfer.data_sock); + lprintf(LOG_DEBUG,"%04d <%s> DATA socket %d closed by client" + ,xfer.ctrl_sock, xfer.user->alias,*xfer.data_sock); break; } if(rd==SOCKET_ERROR) { @@ -1775,22 +1779,22 @@ static void receive_thread(void* arg) continue; } else if(ERROR_VALUE==ECONNRESET) - lprintf(LOG_WARNING,"%04d DATA Connection reset by peer, receiving on socket %d" - ,xfer.ctrl_sock,*xfer.data_sock); + lprintf(LOG_WARNING,"%04d <%s> DATA Connection reset by peer, receiving on socket %d" + ,xfer.ctrl_sock, xfer.user->alias,*xfer.data_sock); else if(ERROR_VALUE==ECONNABORTED) - lprintf(LOG_WARNING,"%04d DATA Connection aborted by peer, receiving on socket %d" - ,xfer.ctrl_sock,*xfer.data_sock); + lprintf(LOG_WARNING,"%04d <%s> DATA Connection aborted by peer, receiving on socket %d" + ,xfer.ctrl_sock, xfer.user->alias,*xfer.data_sock); else - lprintf(LOG_WARNING,"%04d !DATA ERROR %d receiving on data socket %d" - ,xfer.ctrl_sock,ERROR_VALUE,*xfer.data_sock); + lprintf(LOG_WARNING,"%04d <%s> !DATA ERROR %d receiving on data socket %d" + ,xfer.ctrl_sock, xfer.user->alias,ERROR_VALUE,*xfer.data_sock); /* Send NAK */ sockprintf(xfer.ctrl_sock,sess,"426 Error %d receiving on DATA channel" ,ERROR_VALUE); error=TRUE; break; } - lprintf(LOG_ERR,"%04d !DATA ERROR recv returned %d on socket %d" - ,xfer.ctrl_sock,rd,*xfer.data_sock); + lprintf(LOG_ERR,"%04d <%s> !DATA ERROR recv returned %d on socket %d" + ,xfer.ctrl_sock, xfer.user->alias,rd,*xfer.data_sock); /* Send NAK */ sockprintf(xfer.ctrl_sock,sess,"451 Unexpected socket error: %d",rd); error=TRUE; @@ -1806,11 +1810,11 @@ static void receive_thread(void* arg) ftp_close_socket(xfer.data_sock,xfer.data_sess,__LINE__); if(error && startup->options&FTP_OPT_DEBUG_DATA) - lprintf(LOG_DEBUG,"%04d DATA socket %d closed",xfer.ctrl_sock,*xfer.data_sock); + lprintf(LOG_DEBUG,"%04d <%s> DATA socket %d closed",xfer.ctrl_sock, xfer.user->alias,*xfer.data_sock); if(xfer.filepos+total < startup->min_fsize) { - lprintf(LOG_WARNING,"%04d DATA received %lu bytes for %s, less than minimum required (%lu bytes)" - ,xfer.ctrl_sock, xfer.filepos+total, xfer.filename, startup->min_fsize); + lprintf(LOG_WARNING,"%04d <%s> DATA received %lu bytes for %s, less than minimum required (%lu bytes)" + ,xfer.ctrl_sock, xfer.user->alias, xfer.filepos+total, xfer.filename, startup->min_fsize); sockprintf(xfer.ctrl_sock,sess,"550 File size less than minimum required (%lu bytes)" ,startup->min_fsize); error=TRUE; @@ -1821,8 +1825,9 @@ static void receive_thread(void* arg) } else { dur=(long)(time(NULL)-start); cps=dur ? total/dur : total*2; - lprintf(LOG_INFO,"%04d Transfer successful: %lu bytes received in %lu seconds (%lu cps)" + lprintf(LOG_INFO,"%04d <%s> DATA Transfer successful: %lu bytes received in %lu seconds (%lu cps)" ,xfer.ctrl_sock + ,xfer.user->alias ,total,dur,cps); if(xfer.dir>=0) { @@ -1859,19 +1864,19 @@ static void receive_thread(void* arg) if(fexistcase(tmp)) ftp_remove(xfer.ctrl_sock, __LINE__, tmp); cmdstr(&scfg,xfer.user,scfg.fextr[i]->cmd,fname,"FILE_ID.DIZ",cmd); - lprintf(LOG_DEBUG,"%04d Extracting DIZ: %s",xfer.ctrl_sock,cmd); + lprintf(LOG_DEBUG,"%04d <%s> DATA Extracting DIZ: %s",xfer.ctrl_sock, xfer.user->alias,cmd); system(cmd); if(!fexistcase(tmp)) { sprintf(tmp,"%sDESC.SDI",scfg.temp_dir); if(fexistcase(tmp)) ftp_remove(xfer.ctrl_sock, __LINE__, tmp); cmdstr(&scfg,xfer.user,scfg.fextr[i]->cmd,fname,"DESC.SDI",cmd); - lprintf(LOG_DEBUG,"%04d Extracting DIZ: %s",xfer.ctrl_sock,cmd); + lprintf(LOG_DEBUG,"%04d <%s> DATA Extracting DIZ: %s",xfer.ctrl_sock, xfer.user->alias,cmd); system(cmd); fexistcase(tmp); /* fixes filename case */ } if((file=nopen(tmp,O_RDONLY))!=-1) { - lprintf(LOG_DEBUG,"%04d Parsing DIZ: %s",xfer.ctrl_sock,tmp); + lprintf(LOG_DEBUG,"%04d <%s> DATA Parsing DIZ: %s",xfer.ctrl_sock, xfer.user->alias,tmp); memset(ext,0,sizeof(ext)); read(file,ext,sizeof(ext)-1); for(i=sizeof(ext)-1;i;i--) /* trim trailing spaces */ @@ -1891,7 +1896,7 @@ static void receive_thread(void* arg) ftp_remove(xfer.ctrl_sock, __LINE__, tmp); f.misc|=FM_EXTDESC; } else - lprintf(LOG_DEBUG,"%04d DIZ Does not exist: %s",xfer.ctrl_sock,tmp); + lprintf(LOG_DEBUG,"%04d <%s> DATA DIZ Does not exist: %s",xfer.ctrl_sock, xfer.user->alias,tmp); } } /* FILE_ID.DIZ support */ @@ -1901,11 +1906,13 @@ static void receive_thread(void* arg) SAFECOPY(f.uler,xfer.user->alias); /* exception here, Aug-27-2002 */ if(filedat) { if(!putfiledat(&scfg,&f)) - lprintf(LOG_ERR,"%04d !ERROR updating file (%s) in database",xfer.ctrl_sock,f.name); + lprintf(LOG_ERR,"%04d <%s> !DATA ERROR updating file (%s) in database" + ,xfer.ctrl_sock, xfer.user->alias,f.name); /* need to update the index here */ } else { if(!addfiledat(&scfg,&f)) - lprintf(LOG_ERR,"%04d !ERROR adding file (%s) to database",xfer.ctrl_sock,f.name); + lprintf(LOG_ERR,"%04d <%s> !DATA ERROR adding file (%s) to database" + ,xfer.ctrl_sock, xfer.user->alias,f.name); } if(f.misc&FM_EXTDESC) @@ -2027,7 +2034,7 @@ static void filexfer(union xp_sockaddr* addr, SOCKET ctrl_sock, CRYPT_SESSION ct char host_ip[INET6_ADDRSTRLEN]; if((*inprogress)==TRUE) { - lprintf(LOG_WARNING,"%04d !TRANSFER already in progress",ctrl_sock); + lprintf(LOG_WARNING,"%04d <%s> !DATA TRANSFER already in progress",ctrl_sock, user->alias); sockprintf(ctrl_sock,ctrl_sess,"425 Transfer already in progress."); if(tmpfile && !(startup->options&FTP_OPT_KEEP_TEMP_FILES)) ftp_remove(ctrl_sock, __LINE__, filename); @@ -2042,7 +2049,7 @@ static void filexfer(union xp_sockaddr* addr, SOCKET ctrl_sock, CRYPT_SESSION ct if(pasv_sock==INVALID_SOCKET) { /* !PASV */ if((*data_sock=socket(addr->addr.sa_family, SOCK_STREAM, IPPROTO_IP)) == INVALID_SOCKET) { - lprintf(LOG_ERR,"%04d !DATA ERROR %d opening socket", ctrl_sock, ERROR_VALUE); + lprintf(LOG_ERR,"%04d <%s> !DATA ERROR %d opening socket", ctrl_sock, user->alias, ERROR_VALUE); sockprintf(ctrl_sock,ctrl_sess,"425 Error %d opening socket",ERROR_VALUE); if(tmpfile && !(startup->options&FTP_OPT_KEEP_TEMP_FILES)) ftp_remove(ctrl_sock, __LINE__, filename); @@ -2052,7 +2059,7 @@ static void filexfer(union xp_sockaddr* addr, SOCKET ctrl_sock, CRYPT_SESSION ct if(startup->socket_open!=NULL) startup->socket_open(startup->cbdata,TRUE); if(startup->options&FTP_OPT_DEBUG_DATA) - lprintf(LOG_DEBUG,"%04d DATA socket %d opened",ctrl_sock,*data_sock); + lprintf(LOG_DEBUG,"%04d <%s> DATA socket %d opened",ctrl_sock, user->alias,*data_sock); /* Use port-1 for all data connections */ reuseaddr=TRUE; @@ -2060,8 +2067,8 @@ static void filexfer(union xp_sockaddr* addr, SOCKET ctrl_sock, CRYPT_SESSION ct addr_len = sizeof(server_addr); if((result=getsockname(ctrl_sock, &server_addr.addr,&addr_len))!=0) { - lprintf(LOG_ERR,"%04d !ERROR %d (%d) getting address/port of command socket (%u)" - ,ctrl_sock,result,ERROR_VALUE,pasv_sock); + lprintf(LOG_ERR,"%04d <%s> !DATA ERROR %d (%d) getting address/port of command socket (%u)" + ,ctrl_sock, user->alias,result,ERROR_VALUE,pasv_sock); return; } @@ -2073,8 +2080,8 @@ static void filexfer(union xp_sockaddr* addr, SOCKET ctrl_sock, CRYPT_SESSION ct result=bind(*data_sock, &server_addr.addr,addr_len); } if(result!=0) { - lprintf(LOG_ERR,"%04d !DATA ERROR %d (%d) binding socket %d" - ,ctrl_sock, result, ERROR_VALUE, *data_sock); + lprintf(LOG_ERR,"%04d <%s> DATA ERROR %d (%d) binding socket %d" + ,ctrl_sock, user->alias, result, ERROR_VALUE, *data_sock); sockprintf(ctrl_sock,ctrl_sess,"425 Error %d binding socket",ERROR_VALUE); if(tmpfile && !(startup->options&FTP_OPT_KEEP_TEMP_FILES)) ftp_remove(ctrl_sock, __LINE__, filename); @@ -2085,8 +2092,8 @@ static void filexfer(union xp_sockaddr* addr, SOCKET ctrl_sock, CRYPT_SESSION ct result=connect(*data_sock, &addr->addr,xp_sockaddr_len(addr)); if(result!=0) { - lprintf(LOG_WARNING,"%04d !DATA ERROR %d (%d) connecting to client %s port %u on socket %d" - ,ctrl_sock,result,ERROR_VALUE + lprintf(LOG_WARNING,"%04d <%s> !DATA ERROR %d (%d) connecting to client %s port %u on socket %d" + ,ctrl_sock, user->alias,result,ERROR_VALUE ,host_ip,inet_addrport(addr),*data_sock); sockprintf(ctrl_sock,ctrl_sess,"425 Error %d connecting to socket",ERROR_VALUE); if(tmpfile && !(startup->options&FTP_OPT_KEEP_TEMP_FILES)) @@ -2096,13 +2103,13 @@ static void filexfer(union xp_sockaddr* addr, SOCKET ctrl_sock, CRYPT_SESSION ct return; } if(startup->options&FTP_OPT_DEBUG_DATA) - lprintf(LOG_DEBUG,"%04d DATA socket %d connected to %s port %u" - ,ctrl_sock,*data_sock,host_ip,inet_addrport(addr)); + lprintf(LOG_DEBUG,"%04d <%s> DATA socket %d connected to %s port %u" + ,ctrl_sock, user->alias,*data_sock,host_ip,inet_addrport(addr)); if (protected) { if (start_tls(data_sock, data_sess, FALSE) || *data_sess == -1) { - lprintf(LOG_DEBUG,"%04d !DATA ERROR activating TLS" - ,ctrl_sock); + lprintf(LOG_DEBUG,"%04d <%s> !DATA ERROR activating TLS" + ,ctrl_sock, user->alias); sockprintf(ctrl_sock,ctrl_sess,"425 Error activating TLS"); if(tmpfile && !(startup->options&FTP_OPT_KEEP_TEMP_FILES)) ftp_remove(ctrl_sock, __LINE__, filename); @@ -2116,11 +2123,11 @@ static void filexfer(union xp_sockaddr* addr, SOCKET ctrl_sock, CRYPT_SESSION ct if(startup->options&FTP_OPT_DEBUG_DATA) { addr_len=sizeof(*addr); if((result=getsockname(pasv_sock, &addr->addr,&addr_len))!=0) - lprintf(LOG_ERR,"%04d !ERROR %d (%d) getting address/port of passive socket (%u)" - ,ctrl_sock,result,ERROR_VALUE,pasv_sock); + lprintf(LOG_ERR,"%04d <%s> PASV !DATA ERROR %d (%d) getting address/port of passive socket (%u)" + ,ctrl_sock, user->alias,result,ERROR_VALUE,pasv_sock); else - lprintf(LOG_DEBUG,"%04d PASV DATA socket %d listening on %s port %u" - ,ctrl_sock,pasv_sock,host_ip,inet_addrport(addr)); + lprintf(LOG_DEBUG,"%04d <%s> PASV DATA socket %d listening on %s port %u" + ,ctrl_sock, user->alias,pasv_sock,host_ip,inet_addrport(addr)); } /* Setup for select() */ @@ -2138,7 +2145,8 @@ static void filexfer(union xp_sockaddr* addr, SOCKET ctrl_sock, CRYPT_SESSION ct socket_debug[ctrl_sock]&=~SOCKET_DEBUG_SELECT; #endif if(result<1) { - lprintf(LOG_WARNING,"%04d !PASV select returned %d (error: %d)",ctrl_sock,result,ERROR_VALUE); + lprintf(LOG_WARNING,"%04d <%s> PASV !DATA select returned %d (error: %d)" + ,ctrl_sock, user->alias,result,ERROR_VALUE); sockprintf(ctrl_sock,ctrl_sess,"425 Error %d selecting socket for connection",ERROR_VALUE); if(tmpfile && !(startup->options&FTP_OPT_KEEP_TEMP_FILES)) ftp_remove(ctrl_sock, __LINE__, filename); @@ -2155,8 +2163,8 @@ static void filexfer(union xp_sockaddr* addr, SOCKET ctrl_sock, CRYPT_SESSION ct socket_debug[ctrl_sock]&=~SOCKET_DEBUG_ACCEPT; #endif if(*data_sock==INVALID_SOCKET) { - lprintf(LOG_WARNING,"%04d !PASV DATA ERROR %d accepting connection on socket %d" - ,ctrl_sock,ERROR_VALUE,pasv_sock); + lprintf(LOG_WARNING,"%04d <%s> PASV !DATA ERROR %d accepting connection on socket %d" + ,ctrl_sock, user->alias,ERROR_VALUE,pasv_sock); sockprintf(ctrl_sock,ctrl_sess,"425 Error %d accepting connection",ERROR_VALUE); if(tmpfile && !(startup->options&FTP_OPT_KEEP_TEMP_FILES)) ftp_remove(ctrl_sock, __LINE__, filename); @@ -2166,11 +2174,11 @@ static void filexfer(union xp_sockaddr* addr, SOCKET ctrl_sock, CRYPT_SESSION ct if(startup->socket_open!=NULL) startup->socket_open(startup->cbdata,TRUE); if(startup->options&FTP_OPT_DEBUG_DATA) - lprintf(LOG_DEBUG,"%04d PASV DATA socket %d connected to %s port %u" - ,ctrl_sock,*data_sock,host_ip,inet_addrport(addr)); + lprintf(LOG_DEBUG,"%04d <%s> PASV DATA socket %d connected to %s port %u" + ,ctrl_sock, user->alias,*data_sock,host_ip,inet_addrport(addr)); if (protected) { if (start_tls(data_sock, data_sess, FALSE) || *data_sess == -1) { - lprintf(LOG_WARNING,"%04d !PASV ERROR starting TLS", pasv_sock); + lprintf(LOG_WARNING,"%04d <%s> PASV !DATA ERROR starting TLS", pasv_sock, user->alias); sockprintf(ctrl_sock,ctrl_sess,"425 Error negotiating TLS"); if(tmpfile && !(startup->options&FTP_OPT_KEEP_TEMP_FILES)) ftp_remove(ctrl_sock, __LINE__, filename); @@ -2185,15 +2193,15 @@ static void filexfer(union xp_sockaddr* addr, SOCKET ctrl_sock, CRYPT_SESSION ct l=1; if(ioctlsocket(*data_sock, FIONBIO, &l)!=0) { - lprintf(LOG_ERR,"%04d !DATA ERROR %d disabling socket blocking" - ,ctrl_sock, ERROR_VALUE); + lprintf(LOG_ERR,"%04d <%s> !DATA ERROR %d disabling socket blocking" + ,ctrl_sock, user->alias, ERROR_VALUE); sockprintf(ctrl_sock,ctrl_sess,"425 Error %d disabling socket blocking" ,ERROR_VALUE); break; } if((xfer=malloc(sizeof(xfer_t)))==NULL) { - lprintf(LOG_CRIT,"%04d !MALLOC FAILURE LINE %d",ctrl_sock,__LINE__); + lprintf(LOG_CRIT,"%04d <%s> !DATA MALLOC FAILURE LINE %d",ctrl_sock, user->alias,__LINE__); sockprintf(ctrl_sock,ctrl_sess,"425 MALLOC FAILURE"); break; } @@ -2317,7 +2325,7 @@ static BOOL ftpalias(char* fullalias, char* filename, user_t* user, client_t* cl if(!strnicmp(p,BBS_VIRTUAL_PATH,strlen(BBS_VIRTUAL_PATH))) { if((dir=getdir(p+strlen(BBS_VIRTUAL_PATH),user,client))<0) { - lprintf(LOG_WARNING,"0000 !Invalid virtual path (%s) for %s",p,user->alias); + lprintf(LOG_WARNING,"0000 <%s> !Invalid virtual path: %s",user->alias, p); /* invalid or no access */ continue; } @@ -3139,7 +3147,7 @@ static void ctrl_thread(void* arg) #endif if(rd<1) { if(transfer_inprogress==TRUE) { - lprintf(LOG_WARNING,"%04d Aborting transfer due to receive error",sock); + lprintf(LOG_WARNING,"%04d !Aborting transfer due to receive error",sock); transfer_aborted=TRUE; } break; @@ -3296,16 +3304,16 @@ static void ctrl_thread(void* arg) continue; } if(user.misc&(DELETED|INACTIVE)) { - lprintf(LOG_WARNING,"%04d !DELETED or INACTIVE user #%d (%s)" - ,sock,user.number,user.alias); + lprintf(LOG_WARNING,"%04d <%s> !DELETED or INACTIVE user #%d" + ,sock,user.alias,user.number); user.number=0; if(badlogin(sock, sess, &login_attempts, NULL, NULL, NULL, NULL)) break; continue; } if(user.rest&FLAG('T')) { - lprintf(LOG_WARNING,"%04d !T RESTRICTED user #%d (%s)" - ,sock,user.number,user.alias); + lprintf(LOG_WARNING,"%04d <%s> !T RESTRICTED user #%d" + ,sock,user.alias,user.number); user.number=0; if(badlogin(sock, sess, &login_attempts, NULL, NULL, NULL, NULL)) break; @@ -3313,15 +3321,15 @@ static void ctrl_thread(void* arg) } if(user.ltoday>=scfg.level_callsperday[user.level] && !(user.exempt&FLAG('L'))) { - lprintf(LOG_WARNING,"%04d !MAXIMUM LOGONS (%d) reached for %s" - ,sock,scfg.level_callsperday[user.level],user.alias); + lprintf(LOG_WARNING,"%04d <%s> !MAXIMUM LOGONS (%d) reached for level %u" + ,sock,user.alias,scfg.level_callsperday[user.level], user.level); sockprintf(sock,sess,"530 Maximum logons per day reached."); user.number=0; continue; } if(user.rest&FLAG('L') && user.ltoday>=1) { - lprintf(LOG_WARNING,"%04d !L RESTRICTED user #%d (%s) already on today" - ,sock,user.number,user.alias); + lprintf(LOG_WARNING,"%04d <%s> !L RESTRICTED user already on today" + ,sock,user.alias); sockprintf(sock,sess,"530 Maximum logons per day reached."); user.number=0; continue; @@ -3340,15 +3348,15 @@ static void ctrl_thread(void* arg) putuserrec(&scfg,user.number,U_NETMAIL,LEN_NETMAIL,password); } else if(user.level>=SYSOP_LEVEL && !stricmp(password,sys_pass)) { - lprintf(LOG_INFO,"%04d Sysop access granted to %s", sock, user.alias); + lprintf(LOG_INFO,"%04d <%s> Sysop access granted", sock, user.alias); sysop=TRUE; } else if(stricmp(password,user.pass)) { if(scfg.sys_misc&SM_ECHO_PW) - lprintf(LOG_WARNING,"%04d !FAILED Password attempt for user %s: '%s' expected '%s'" + lprintf(LOG_WARNING,"%04d <%s> !FAILED Password attempt: '%s' expected '%s'" ,sock, user.alias, password, user.pass); else - lprintf(LOG_WARNING,"%04d !FAILED Password attempt for user %s" + lprintf(LOG_WARNING,"%04d <%s> !FAILED Password attempt" ,sock, user.alias); user.number=0; if(badlogin(sock, sess, &login_attempts, user.alias, password, host_name, &ftp.client_addr)) @@ -3366,7 +3374,7 @@ static void ctrl_thread(void* arg) } client_on(sock,&client,TRUE /* update */); - lprintf(LOG_INFO,"%04d %s logged in (%u today, %u total)" + lprintf(LOG_INFO,"%04d <%s> logged in (%u today, %u total)" ,sock,user.alias,user.ltoday+1, user.logons+1); logintime=time(NULL); timeleft=(long)gettimeleft(&scfg,&user,logintime); @@ -3488,7 +3496,7 @@ static void ctrl_thread(void* arg) if((timeleft=(long)gettimeleft(&scfg,&user,logintime))<1L) { sockprintf(sock,sess,"421 Sorry, you've run out of time."); - lprintf(LOG_WARNING,"%04d Out of time, disconnecting",sock); + lprintf(LOG_WARNING,"%04d <%s> Out of time, disconnecting",sock, user.alias); break; } @@ -3497,7 +3505,7 @@ static void ctrl_thread(void* arg) /********************************/ if(!stricmp(cmd, "REIN")) { - lprintf(LOG_INFO,"%04d %s reinitialized control session",sock,user.alias); + lprintf(LOG_INFO,"%04d <%s> reinitialized control session",sock,user.alias); user.number=0; sysop=FALSE; filepos=0; @@ -3623,7 +3631,7 @@ static void ctrl_thread(void* arg) FIND_CHAR(tp, delim); *tp=0; if(inet_ptoaddr(addr_str, &data_addr, sizeof(data_addr))==NULL) { - lprintf(LOG_WARNING,"%04d Unable to parse IPv6 address %s",sock,addr_str); + lprintf(LOG_WARNING,"%04d <%s> !Unable to parse IPv6 address: %s",sock, user.alias, addr_str); sockprintf(sock,sess,"522 Unable to parse IPv6 address (1)"); continue; } @@ -3634,14 +3642,14 @@ static void ctrl_thread(void* arg) data_addr.in6.sin6_family=AF_INET6; break; default: - lprintf(LOG_WARNING,"%04d UNSUPPORTED protocol: %d", sock, prot); + lprintf(LOG_WARNING,"%04d <%s> !UNSUPPORTED protocol: %d", sock, user.alias, prot); sockprintf(sock,sess,"522 Network protocol not supported, use (1)"); continue; } } else { /* LPRT */ if(sscanf(p,"%u,%u",&h1, &h2)!=2) { - lprintf(LOG_ERR, "Unable to parse LPRT %s", p); + lprintf(LOG_ERR, "%04d <%s> !Unable to parse LPRT: %s", sock, user.alias, p); sockprintf(sock,sess, "521 Address family not supported"); continue; } @@ -3654,7 +3662,7 @@ static void ctrl_thread(void* arg) switch(h1) { case 4: /* IPv4 */ if(h2 != 4) { - lprintf(LOG_ERR, "Unable to parse LPRT %s", p); + lprintf(LOG_ERR, "%04d <%s> !Unable to parse LPRT: %s", sock, user.alias, p); sockprintf(sock,sess, "501 IPv4 Address is the wrong length"); continue; } @@ -3665,7 +3673,7 @@ static void ctrl_thread(void* arg) p++; } if(atoi(p)!=2) { - lprintf(LOG_ERR, "Unable to parse LPRT %s", p); + lprintf(LOG_ERR, "%04d <%s> !Unable to parse LPRT %s", sock, user.alias, p); sockprintf(sock,sess, "501 IPv4 Port is the wrong length"); continue; } @@ -3682,7 +3690,7 @@ static void ctrl_thread(void* arg) break; case 6: /* IPv6 */ if(h2 != 16) { - lprintf(LOG_ERR, "Unable to parse LPRT %s", p); + lprintf(LOG_ERR, "%04d <%s> !Unable to parse LPRT: %s",sock, user.alias, p); sockprintf(sock,sess, "501 IPv6 Address is the wrong length"); continue; } @@ -3693,7 +3701,7 @@ static void ctrl_thread(void* arg) p++; } if(atoi(p)!=2) { - lprintf(LOG_ERR, "Unable to parse LPRT %s", p); + lprintf(LOG_ERR, "%04d <%s> !Unable to parse LPRT: %s",sock, user.alias, p); sockprintf(sock,sess, "501 IPv6 Port is the wrong length"); continue; } @@ -3709,7 +3717,7 @@ static void ctrl_thread(void* arg) data_addr.in6.sin6_family=AF_INET6; break; default: - lprintf(LOG_ERR, "Unable to parse LPRT %s", p); + lprintf(LOG_ERR, "%04d <%s> !Unable to parse LPRT: %s",sock, user.alias, p); sockprintf(sock,sess, "521 Address family not supported"); continue; } @@ -3717,7 +3725,7 @@ static void ctrl_thread(void* arg) inet_addrtop(&data_addr, data_ip, sizeof(data_ip)); if(data_port< IPPORT_RESERVED) { - lprintf(LOG_WARNING,"%04d !SUSPECTED BOUNCE ATTACK ATTEMPT by %s to %s port %u" + lprintf(LOG_WARNING,"%04d <%s> !SUSPECTED BOUNCE ATTACK ATTEMPT to %s port %u" ,sock,user.alias ,data_ip,data_port); ftp_hacklog("FTP BOUNCE", user.alias, cmd, host_name, &ftp.client_addr); @@ -3737,27 +3745,27 @@ static void ctrl_thread(void* arg) ftp_close_socket(&pasv_sock,&pasv_sess,__LINE__); if((pasv_sock=ftp_open_socket(pasv_addr.addr.sa_family, SOCK_STREAM))==INVALID_SOCKET) { - lprintf(LOG_WARNING,"%04d !PASV ERROR %d opening socket", sock,ERROR_VALUE); + lprintf(LOG_WARNING,"%04d <%s> !PASV ERROR %d opening socket", sock, user.alias, ERROR_VALUE); sockprintf(sock,sess,"425 Error %d opening PASV data socket", ERROR_VALUE); continue; } reuseaddr=FALSE; if((result=setsockopt(pasv_sock,SOL_SOCKET,SO_REUSEADDR,(char*)&reuseaddr,sizeof(reuseaddr)))!=0) { - lprintf(LOG_WARNING,"%04d !PASV ERROR %d disabling REUSEADDR socket option" - ,sock,ERROR_VALUE); + lprintf(LOG_WARNING,"%04d <%s> !PASV ERROR %d disabling REUSEADDR socket option" + ,sock, user.alias, ERROR_VALUE); sockprintf(sock,sess,"425 Error %d disabling REUSEADDR socket option", ERROR_VALUE); continue; } if(startup->options&FTP_OPT_DEBUG_DATA) - lprintf(LOG_DEBUG,"%04d PASV DATA socket %d opened",sock,pasv_sock); + lprintf(LOG_DEBUG,"%04d <%s> PASV DATA socket %d opened",sock, user.alias, pasv_sock); for(port=startup->pasv_port_low; port<=startup->pasv_port_high; port++) { if(startup->options&FTP_OPT_DEBUG_DATA) - lprintf(LOG_DEBUG,"%04d PASV DATA trying to bind socket to port %u" - ,sock,port); + lprintf(LOG_DEBUG,"%04d <%s> PASV DATA trying to bind socket to port %u" + ,sock, user.alias, port); inet_setaddrport(&pasv_addr, port); @@ -3767,27 +3775,27 @@ static void ctrl_thread(void* arg) break; } if(result!= 0) { - lprintf(LOG_ERR,"%04d !PASV ERROR %d (%d) binding socket to port %u" - ,sock, result, ERROR_VALUE, port); + lprintf(LOG_ERR,"%04d <%s> !PASV ERROR %d (%d) binding socket to port %u" + ,sock, user.alias, result, ERROR_VALUE, port); sockprintf(sock,sess,"425 Error %d binding data socket",ERROR_VALUE); ftp_close_socket(&pasv_sock,&pasv_sess,__LINE__); continue; } if(startup->options&FTP_OPT_DEBUG_DATA) - lprintf(LOG_DEBUG,"%04d PASV DATA socket %d bound to port %u",sock,pasv_sock,port); + lprintf(LOG_DEBUG,"%04d <%s> PASV DATA socket %d bound to port %u",sock, user.alias, pasv_sock, port); addr_len=sizeof(addr); if((result=getsockname(pasv_sock, &addr.addr,&addr_len))!=0) { - lprintf(LOG_ERR,"%04d !PASV ERROR %d (%d) getting address/port" - ,sock, result, ERROR_VALUE); + lprintf(LOG_ERR,"%04d <%s> !PASV ERROR %d (%d) getting address/port" + ,sock, user.alias, result, ERROR_VALUE); sockprintf(sock,sess,"425 Error %d getting address/port",ERROR_VALUE); ftp_close_socket(&pasv_sock,&pasv_sess,__LINE__); continue; } if((result=listen(pasv_sock, 1))!= 0) { - lprintf(LOG_ERR,"%04d !PASV ERROR %d (%d) listening on port %u" - ,sock, result, ERROR_VALUE,port); + lprintf(LOG_ERR,"%04d <%s> !PASV ERROR %d (%d) listening on port %u" + ,sock, user.alias, result, ERROR_VALUE,port); sockprintf(sock,sess,"425 Error %d listening on data socket",ERROR_VALUE); ftp_close_socket(&pasv_sock,&pasv_sess,__LINE__); continue; @@ -3841,8 +3849,9 @@ static void ctrl_thread(void* arg) ip_addr=ntohl(pasv_addr.in.sin_addr.s_addr); if(startup->options&FTP_OPT_DEBUG_DATA) - lprintf(LOG_INFO,"%04d PASV DATA IP address in response: %u.%u.%u.%u (subject to NAT)" + lprintf(LOG_INFO,"%04d <%s> PASV DATA IP address in response: %u.%u.%u.%u (subject to NAT)" ,sock + ,user.alias ,(ip_addr>>24)&0xff ,(ip_addr>>16)&0xff ,(ip_addr>>8)&0xff @@ -3925,7 +3934,7 @@ static void ctrl_thread(void* arg) if(!transfer_inprogress) sockprintf(sock,sess,"226 No tranfer in progress."); else { - lprintf(LOG_WARNING,"%04d %s aborting transfer" + lprintf(LOG_WARNING,"%04d <%s> aborting transfer" ,sock,user.alias); transfer_aborted=TRUE; YIELD(); /* give send thread time to abort */ @@ -3942,7 +3951,7 @@ static void ctrl_thread(void* arg) else { if(!direxist(p)) { sockprintf(sock,sess,"550 Directory does not exist."); - lprintf(LOG_WARNING,"%04d !%s attempted to mount invalid directory: %s" + lprintf(LOG_WARNING,"%04d <%s> !attempted to mount invalid directory: %s" ,sock, user.alias, p); continue; } @@ -3951,7 +3960,7 @@ static void ctrl_thread(void* arg) } sockprintf(sock,sess,"250 %s file system mounted." ,local_fsys ? "Local" : "BBS"); - lprintf(LOG_INFO,"%04d %s mounted %s file system" + lprintf(LOG_INFO,"%04d <%s> mounted %s file system" ,sock, user.alias, local_fsys ? "local" : "BBS"); continue; } @@ -3969,8 +3978,8 @@ static void ctrl_thread(void* arg) if (cmd[3] == 'T' || cmd[3] == 'D') { if (cmd[3] == 'D') { if((fp=fopen(ftp_tmpfname(fname,"lst",sock),"w+b"))==NULL) { - lprintf(LOG_ERR,"%04d !ERROR %d (%s) line %d opening %s (useron=%s)" - ,sock, errno, strerror(errno), __LINE__, fname, user.alias); + lprintf(LOG_ERR,"%04d <%s> !ERROR %d (%s) line %d opening %s" + ,sock, user.alias, errno, strerror(errno), __LINE__, fname); sockprintf(sock,sess, "451 Insufficient system storage"); continue; } @@ -4007,7 +4016,7 @@ static void ctrl_thread(void* arg) strcat(path, "*"); } - lprintf(LOG_INFO,"%04d %s MLSx listing: %s in %s mode", sock, user.alias, path, mode); + lprintf(LOG_INFO,"%04d <%s> MLSx listing: %s in %s mode", sock, user.alias, path, mode); now=time(NULL); if(localtime_r(&now,&cur_tm)==NULL) @@ -4040,8 +4049,8 @@ static void ctrl_thread(void* arg) detail=FALSE; if((fp=fopen(ftp_tmpfname(fname,"lst",sock),"w+b"))==NULL) { - lprintf(LOG_ERR,"%04d !ERROR %d (%s) line %d opening %s (useron=%s)" - ,sock, errno, strerror(errno), __LINE__, fname, user.alias); + lprintf(LOG_ERR,"%04d <%s> !ERROR %d (%s) line %d opening %s" + ,sock, user.alias, errno, strerror(errno), __LINE__, fname); sockprintf(sock,sess, "451 Insufficient system storage"); continue; } @@ -4059,7 +4068,7 @@ static void ctrl_thread(void* arg) filespec="*"; SAFEPRINTF2(path,"%s%s",local_dir, filespec); - lprintf(LOG_INFO,"%04d %s listing: %s in %s mode", sock, user.alias, path, mode); + lprintf(LOG_INFO,"%04d <%s> listing: %s in %s mode", sock, user.alias, path, mode); sockprintf(sock,sess, "150 Directory of %s%s", local_dir, filespec); now=time(NULL); @@ -4111,7 +4120,7 @@ static void ctrl_thread(void* arg) if(!strnicmp(tp,BBS_FSYS_DIR,strlen(BBS_FSYS_DIR))) { local_fsys=FALSE; sockprintf(sock,sess,"250 CWD command successful (BBS file system mounted)."); - lprintf(LOG_INFO,"%04d %s mounted BBS file system", sock, user.alias); + lprintf(LOG_INFO,"%04d <%s> mounted BBS file system", sock, user.alias); continue; } if(!strnicmp(tp,LOCAL_FSYS_DIR,strlen(LOCAL_FSYS_DIR))) { @@ -4134,7 +4143,7 @@ static void ctrl_thread(void* arg) if(!direxist(path)) { sockprintf(sock,sess,"550 Directory does not exist (%s).",path); - lprintf(LOG_WARNING,"%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); } else { SAFECOPY(local_dir,path); @@ -4169,13 +4178,13 @@ static void ctrl_thread(void* arg) else /* relative */ SAFEPRINTF2(fname,"%s%s",local_dir,p); - if((i=MKDIR(fname))==0) { + if(MKDIR(fname) == 0) { sockprintf(sock,sess,"257 \"%s\" directory created",fname); - lprintf(LOG_NOTICE,"%04d %s created directory: %s",sock,user.alias,fname); + lprintf(LOG_NOTICE,"%04d <%s> created directory: %s",sock,user.alias,fname); } else { - sockprintf(sock,sess,"521 Error %d creating directory: %s",i,fname); - lprintf(LOG_WARNING,"%04d !%s attempted to create directory: %s (Error %d)" - ,sock,user.alias,fname,i); + sockprintf(sock,sess,"521 Error %d creating directory: %s",errno,fname); + lprintf(LOG_WARNING,"%04d <%s> !ERROR %d (%s) attempting to create directory: %s" + ,sock,user.alias,errno,strerror(errno),fname); } continue; } @@ -4188,13 +4197,13 @@ static void ctrl_thread(void* arg) else /* relative */ SAFEPRINTF2(fname,"%s%s",local_dir,p); - if((i=rmdir(fname))==0) { + if(rmdir(fname) == 0) { sockprintf(sock,sess,"250 \"%s\" directory removed",fname); - lprintf(LOG_NOTICE,"%04d %s removed directory: %s",sock,user.alias,fname); + lprintf(LOG_NOTICE,"%04d <%s> removed directory: %s",sock,user.alias,fname); } else { - sockprintf(sock,sess,"450 Error %d removing directory: %s",i,fname); - lprintf(LOG_WARNING,"%04d !%s attempted to remove directory: %s (Error %d)" - ,sock,user.alias,fname,i); + sockprintf(sock,sess,"450 Error %d removing directory: %s", errno, fname); + lprintf(LOG_WARNING,"%04d <%s> !ERROR %d (%s) removing directory: %s" + ,sock, user.alias, errno, strerror(errno), fname); } continue; } @@ -4208,7 +4217,7 @@ static void ctrl_thread(void* arg) SAFEPRINTF2(ren_from,"%s%s",local_dir,p); if(!fexist(ren_from)) { sockprintf(sock,sess,"550 File not found: %s",ren_from); - lprintf(LOG_WARNING,"%04d !%s attempted to rename %s (not found)" + lprintf(LOG_WARNING,"%04d <%s> !ERROR renaming %s (not found)" ,sock,user.alias,ren_from); } else sockprintf(sock,sess,"350 File exists, ready for destination name"); @@ -4223,13 +4232,13 @@ static void ctrl_thread(void* arg) else /* relative */ SAFEPRINTF2(fname,"%s%s",local_dir,p); - if((i=rename(ren_from, fname))==0) { + if(rename(ren_from, fname) == 0) { sockprintf(sock,sess,"250 \"%s\" renamed to \"%s\"",ren_from,fname); - lprintf(LOG_NOTICE,"%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 { - sockprintf(sock,sess,"450 Error %d renaming file: %s",i,ren_from); - lprintf(LOG_WARNING,"%04d !%s attempted to rename file: %s (Error %d)" - ,sock,user.alias,ren_from,i); + sockprintf(sock,sess,"450 Error %d renaming file: %s", errno, ren_from); + lprintf(LOG_WARNING,"%04d <%s> !ERRROR %d (%s) renaming file: %s" + ,sock, user.alias, errno, strerror(errno), ren_from); } continue; } @@ -4250,7 +4259,7 @@ static void ctrl_thread(void* arg) else /* relative */ SAFEPRINTF2(fname,"%s%s",local_dir,p); if(!fexist(fname)) { - lprintf(LOG_WARNING,"%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,sess,"550 File not found: %s",fname); continue; } @@ -4268,18 +4277,18 @@ static void ctrl_thread(void* arg) continue; } if(!strnicmp(cmd,"DELE ",5)) { - if((i=ftp_remove(sock, __LINE__, fname))==0) { + if(ftp_remove(sock, __LINE__, fname) == 0) { sockprintf(sock,sess,"250 \"%s\" removed successfully.",fname); - lprintf(LOG_NOTICE,"%04d %s deleted file: %s",sock,user.alias,fname); + lprintf(LOG_NOTICE,"%04d <%s> deleted file: %s",sock,user.alias,fname); } else { - sockprintf(sock,sess,"450 Error %d removing file: %s",i,fname); - lprintf(LOG_WARNING,"%04d !%s attempted to delete file: %s (Error %d)" - ,sock,user.alias,fname,i); + sockprintf(sock,sess,"450 Error %d removing file: %s", errno, fname); + lprintf(LOG_WARNING,"%04d <%s> !ERROR %d (%s) deleting file: %s" + ,sock, user.alias, errno, strerror(errno), fname); } continue; } /* RETR */ - lprintf(LOG_INFO,"%04d %s downloading: %s (%"PRIuOFF" bytes) in %s mode" + lprintf(LOG_INFO,"%04d <%s> downloading: %s (%"PRIuOFF" bytes) in %s mode" ,sock,user.alias,fname,flength(fname) ,mode); sockprintf(sock,sess,"150 Opening BINARY mode data connection for file transfer."); @@ -4303,7 +4312,7 @@ static void ctrl_thread(void* arg) else /* relative */ SAFEPRINTF2(fname,"%s%s",local_dir,p); - lprintf(LOG_INFO,"%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 ,mode); sockprintf(sock,sess,"150 Opening BINARY mode data connection for file transfer."); filexfer(&data_addr,sock,sess,pasv_sock,pasv_sess,&data_sock,&data_sess,fname,filepos @@ -4330,7 +4339,7 @@ static void ctrl_thread(void* arg) l = 0; if(cmd[4]!=0) - lprintf(LOG_DEBUG,"%04d MLSx: %s",sock,cmd); + lprintf(LOG_DEBUG,"%04d <%s> MLSx: %s",sock, user.alias, cmd); /* path specified? */ p=cmd+4; @@ -4364,8 +4373,8 @@ static void ctrl_thread(void* arg) fp = NULL; if (cmd[3] == 'D') { if((fp=fopen(ftp_tmpfname(fname,"lst",sock),"w+b"))==NULL) { - lprintf(LOG_ERR,"%04d !ERROR %d (%s) line %d opening %s (useron=%s)" - ,sock, errno, strerror(errno), __LINE__, fname, user.alias); + lprintf(LOG_ERR,"%04d <%s> !ERROR %d (%s) line %d opening %s" + ,sock, user.alias, errno, strerror(errno), __LINE__, fname); sockprintf(sock,sess, "451 Insufficient system storage"); continue; } @@ -4405,7 +4414,7 @@ static void ctrl_thread(void* arg) else { send_mlsx_entry(fp, sock, sess, mlsx_feats, "cdir", (startup->options&FTP_OPT_ALLOW_QWK) ? "elc" : "el", UINT64_MAX, 0, str, NULL, 0, "/"); } - lprintf(LOG_INFO,"%04d %s listing: root in %s mode",sock,user.alias, mode); + lprintf(LOG_INFO,"%04d <%s> listing: root in %s mode",sock,user.alias, mode); /* QWK Packet */ if(startup->options&FTP_OPT_ALLOW_QWK) { @@ -4457,7 +4466,7 @@ static void ctrl_thread(void* arg) aliaspath[0]=0; if(!strnicmp(np,BBS_VIRTUAL_PATH,strlen(BBS_VIRTUAL_PATH))) { if((dir=getdir(np+strlen(BBS_VIRTUAL_PATH),&user,&client))<0) { - lprintf(LOG_WARNING,"0000 !Invalid virtual path (%s) for %s",np,user.alias); + lprintf(LOG_WARNING,"%04d <%s> !Invalid virtual path:%s",sock,user.alias,np); continue; /* No access or invalid virtual path */ } tp=strrchr(np,'/'); @@ -4476,7 +4485,7 @@ static void ctrl_thread(void* arg) } if(!alias_dir && !fexist(np)) { - lprintf(LOG_WARNING,"0000 !Missing aliased file (%s) for %s",np,user.alias); + lprintf(LOG_WARNING,"%04d <%s> !Missing aliased file: %s",sock, user.alias, np); continue; } @@ -4530,7 +4539,7 @@ static void ctrl_thread(void* arg) SAFEPRINTF(aliaspath, "/%s", scfg.lib[lib]->sname); send_mlsx_entry(fp, sock, sess, mlsx_feats, "cdir", (startup->options&FTP_OPT_ALLOW_QWK) ? "elc" : "el", UINT64_MAX, 0, str, NULL, 0, aliaspath); } - lprintf(LOG_INFO,"%04d %s listing: %s library in %s mode" + lprintf(LOG_INFO,"%04d <%s> listing: %s library in %s mode" ,sock,user.alias,scfg.lib[lib]->sname,mode); for(i=0;i<scfg.total_dirs;i++) { if(scfg.dir[i]->lib!=lib) @@ -4550,7 +4559,7 @@ static void ctrl_thread(void* arg) l++; } } else if(chk_ar(&scfg,scfg.dir[dir]->ar,&user,&client)) { - lprintf(LOG_INFO,"%04d %s listing: %s/%s directory in %s mode" + lprintf(LOG_INFO,"%04d <%s> listing: %s/%s directory in %s mode" ,sock,user.alias,scfg.lib[lib]->sname,scfg.dir[dir]->code_suffix,mode); if (cmd[3] == 'T' && !*mls_fname) { @@ -4601,7 +4610,7 @@ static void ctrl_thread(void* arg) } globfree(&g); } else - lprintf(LOG_INFO,"%04d %s listing: %s/%s directory in %s mode (empty - no access)" + lprintf(LOG_INFO,"%04d <%s> listing: %s/%s directory in %s mode (empty - no access)" ,sock,user.alias,scfg.lib[lib]->sname,scfg.dir[dir]->code_suffix,mode); if (cmd[3] == 'D') { @@ -4627,7 +4636,7 @@ static void ctrl_thread(void* arg) lib=curlib; if(cmd[4]!=0) - lprintf(LOG_DEBUG,"%04d LIST/NLST: %s",sock,cmd); + lprintf(LOG_DEBUG,"%04d <%s> LIST/NLST: %s", sock, user.alias, cmd); /* path specified? */ p=cmd+4; @@ -4639,8 +4648,8 @@ static void ctrl_thread(void* arg) } if((fp=fopen(ftp_tmpfname(fname,"lst",sock),"w+b"))==NULL) { - lprintf(LOG_ERR,"%04d !ERROR %d (%s) line %d opening %s (useron=%s)" - ,sock, errno, strerror(errno), __LINE__, fname, user.alias); + lprintf(LOG_ERR,"%04d <%s> !ERROR %d (%s) line %d opening %s" + ,sock, user.alias, errno, strerror(errno), __LINE__, fname); sockprintf(sock,sess, "451 Insufficient system storage"); continue; } @@ -4700,7 +4709,7 @@ static void ctrl_thread(void* arg) } if(lib<0) { /* Root dir */ - lprintf(LOG_INFO,"%04d %s listing: root in %s mode",sock,user.alias, mode); + lprintf(LOG_INFO,"%04d <%s> listing: root in %s mode",sock,user.alias, mode); /* QWK Packet */ if(startup->options&FTP_OPT_ALLOW_QWK) { @@ -4768,7 +4777,7 @@ static void ctrl_thread(void* arg) /* Virtual Path? */ if(!strnicmp(np,BBS_VIRTUAL_PATH,strlen(BBS_VIRTUAL_PATH))) { if((dir=getdir(np+strlen(BBS_VIRTUAL_PATH),&user,&client))<0) { - lprintf(LOG_WARNING,"0000 !Invalid virtual path (%s) for %s",np,user.alias); + lprintf(LOG_WARNING,"%04d <%s> !Invalid virtual path: %s", sock, user.alias, np); continue; /* No access or invalid virtual path */ } tp=strrchr(np,'/'); @@ -4784,7 +4793,7 @@ static void ctrl_thread(void* arg) } if(!alias_dir && !fexist(np)) { - lprintf(LOG_WARNING,"0000 !Missing aliased file (%s) for %s",np,user.alias); + lprintf(LOG_WARNING,"%04d <%s> !Missing aliased file: %s", sock, user.alias, np); continue; } @@ -4837,7 +4846,7 @@ static void ctrl_thread(void* arg) fprintf(fp,"%s\r\n",scfg.lib[i]->sname); } } else if(dir<0) { - lprintf(LOG_INFO,"%04d %s listing: %s library in %s mode" + lprintf(LOG_INFO,"%04d <%s> listing: %s library in %s mode" ,sock,user.alias,scfg.lib[lib]->sname,mode); for(i=0;i<scfg.total_dirs;i++) { if(scfg.dir[i]->lib!=lib) @@ -4859,7 +4868,7 @@ static void ctrl_thread(void* arg) fprintf(fp,"%s\r\n",scfg.dir[i]->code_suffix); } } else if(chk_ar(&scfg,scfg.dir[dir]->ar,&user,&client)) { - lprintf(LOG_INFO,"%04d %s listing: %s/%s directory in %s mode" + lprintf(LOG_INFO,"%04d <%s> listing: %s/%s directory in %s mode" ,sock,user.alias,scfg.lib[lib]->sname,scfg.dir[dir]->code_suffix,mode); SAFEPRINTF2(path,"%s%s",scfg.dir[dir]->path,filespec); @@ -4910,7 +4919,7 @@ static void ctrl_thread(void* arg) } globfree(&g); } else - lprintf(LOG_INFO,"%04d %s listing: %s/%s directory in %s mode (empty - no access)" + lprintf(LOG_INFO,"%04d <%s> listing: %s/%s directory in %s mode (empty - no access)" ,sock,user.alias,scfg.lib[lib]->sname,scfg.dir[dir]->code_suffix,mode); fclose(fp); @@ -4967,7 +4976,7 @@ static void ctrl_thread(void* arg) credits=TRUE; /* include in d/l stats */ tmpfile=FALSE; delfile=FALSE; - lprintf(LOG_INFO,"%04d %s %.4s by alias: %s" + lprintf(LOG_INFO,"%04d <%s> %.4s by alias: %s" ,sock,user.alias,cmd,p); p=getfname(fname); if(dir>=0) @@ -5007,11 +5016,11 @@ static void ctrl_thread(void* arg) if(lib<0 && startup->options&FTP_OPT_ALLOW_QWK && !stricmp(p,str) && !delecmd) { if(!fexistcase(qwkfile)) { - lprintf(LOG_INFO,"%04d %s creating QWK packet...",sock,user.alias); + lprintf(LOG_INFO,"%04d <%s> creating QWK packet...",sock,user.alias); sprintf(str,"%spack%04u.now",scfg.data_dir,user.number); if(!ftouch(str)) - lprintf(LOG_ERR,"%04d !ERROR creating semaphore file: %s" - ,sock, str); + lprintf(LOG_ERR,"%04d <%s> !ERROR creating semaphore file: %s" + ,sock, user.alias, str); t=time(NULL); while(fexist(str)) { if(!socket_check(sock,NULL,NULL,0)) @@ -5025,14 +5034,14 @@ static void ctrl_thread(void* arg) continue; } if(fexist(str)) { - lprintf(LOG_WARNING,"%04d !TIMEOUT waiting for QWK packet creation",sock); + lprintf(LOG_WARNING,"%04d <%s> !TIMEOUT waiting for QWK packet creation", sock, user.alias); sockprintf(sock,sess,"451 Time-out waiting for packet creation."); ftp_remove(sock, __LINE__, str); filepos=0; continue; } if(!fexistcase(qwkfile)) { - lprintf(LOG_INFO,"%04d No QWK Packet created (no new messages)",sock); + lprintf(LOG_INFO,"%04d <%s> No QWK Packet created (no new messages)", sock, user.alias); sockprintf(sock,sess,"550 No QWK packet created (no new messages)"); filepos=0; continue; @@ -5043,7 +5052,7 @@ static void ctrl_thread(void* arg) delfile=TRUE; credits=FALSE; if(!getsize && !getdate) - lprintf(LOG_INFO,"%04d %s downloading QWK packet (%"PRIuOFF" bytes) in %s mode" + lprintf(LOG_INFO,"%04d <%s> downloading QWK packet (%"PRIuOFF" bytes) in %s mode" ,sock,user.alias,flength(fname) ,mode); /* ASCII Index File */ @@ -5055,8 +5064,8 @@ static void ctrl_thread(void* arg) continue; } if((fp=fopen(ftp_tmpfname(fname,"ndx",sock),"w+b"))==NULL) { - lprintf(LOG_ERR,"%04d !ERROR %d (%s) line %d opening %s (useron=%s)" - ,sock, errno, strerror(errno), __LINE__, fname, user.alias); + lprintf(LOG_ERR,"%04d <%s> !ERROR %d (%s) line %d opening %s" + ,sock, user.alias, errno, strerror(errno), __LINE__, fname); sockprintf(sock,sess, "451 Insufficient system storage"); filepos=0; continue; @@ -5065,7 +5074,7 @@ static void ctrl_thread(void* arg) if(getdate) file_date=time(NULL); else { - lprintf(LOG_INFO,"%04d %s downloading index for %s in %s mode" + lprintf(LOG_INFO,"%04d <%s> downloading index for %s in %s mode" ,sock,user.alias,genvpath(lib,dir,str) ,mode); credits=FALSE; @@ -5175,17 +5184,17 @@ static void ctrl_thread(void* arg) else { #ifdef JAVASCRIPT if(startup->options&FTP_OPT_NO_JAVASCRIPT) { - lprintf(LOG_ERR,"%04d !JavaScript disabled, cannot generate %s",sock,fname); + lprintf(LOG_ERR,"%04d <%s> !JavaScript disabled, cannot generate %s",sock, user.alias, fname); sockprintf(sock,sess, "451 JavaScript disabled"); filepos=0; continue; } if(js_runtime == NULL) { - lprintf(LOG_DEBUG,"%04d JavaScript: Creating runtime: %lu bytes" - ,sock,startup->js.max_bytes); + lprintf(LOG_DEBUG,"%04d <%s> JavaScript: Creating runtime: %lu bytes" + ,sock, user.alias,startup->js.max_bytes); if((js_runtime = jsrt_GetNew(startup->js.max_bytes, 1000, __FILE__, __LINE__))==NULL) { - lprintf(LOG_ERR,"%04d !ERROR creating JavaScript runtime",sock); + lprintf(LOG_ERR,"%04d <%s> !ERROR creating JavaScript runtime",sock, user.alias); sockprintf(sock,sess,"451 Error creating JavaScript runtime"); filepos=0; continue; @@ -5195,26 +5204,26 @@ static void ctrl_thread(void* arg) if(js_cx==NULL) { /* Context not yet created, create it now */ /* js_initcx() starts a request */ if(((js_cx=js_initcx(js_runtime, sock,&js_glob,&js_ftp,&js_callback))==NULL)) { - lprintf(LOG_ERR,"%04d !ERROR initializing JavaScript context",sock); + lprintf(LOG_ERR,"%04d <%s> !ERROR initializing JavaScript context",sock, user.alias); sockprintf(sock,sess,"451 Error initializing JavaScript context"); filepos=0; continue; } if(js_CreateUserClass(js_cx, js_glob, &scfg)==NULL) - lprintf(LOG_ERR,"%04d !JavaScript ERROR creating user class",sock); + lprintf(LOG_ERR,"%04d <%s> !JavaScript ERROR creating user class",sock, user.alias); if(js_CreateFileClass(js_cx, js_glob)==NULL) - lprintf(LOG_ERR,"%04d !JavaScript ERROR creating file class",sock); + lprintf(LOG_ERR,"%04d <%s> !JavaScript ERROR creating file class",sock, user.alias); if(js_CreateUserObject(js_cx, js_glob, &scfg, "user", &user, &client, /* global_user: */TRUE)==NULL) - lprintf(LOG_ERR,"%04d !JavaScript ERROR creating user object",sock); + lprintf(LOG_ERR,"%04d <%s> !JavaScript ERROR creating user object",sock, user.alias); if(js_CreateClientObject(js_cx, js_glob, "client", &client, sock, -1)==NULL) - lprintf(LOG_ERR,"%04d !JavaScript ERROR creating client object",sock); + lprintf(LOG_ERR,"%04d <%s> !JavaScript ERROR creating client object",sock, user.alias); if(js_CreateFileAreaObject(js_cx, js_glob, &scfg, &user, &client ,startup->html_index_file)==NULL) - lprintf(LOG_ERR,"%04d !JavaScript ERROR creating file area object",sock); + lprintf(LOG_ERR,"%04d <%s> !JavaScript ERROR creating file area object",sock, user.alias); } else JS_BEGINREQUEST(js_cx); @@ -5264,13 +5273,13 @@ static void ctrl_thread(void* arg) JS_ENDREQUEST(js_cx); #endif if((fp=fopen(ftp_tmpfname(fname,"html",sock),"w+b"))==NULL) { - lprintf(LOG_ERR,"%04d !ERROR %d (%s) line %d opening %s (useron=%s)" - ,sock, errno, strerror(errno), __LINE__, fname, user.alias); + lprintf(LOG_ERR,"%04d <%s> !ERROR %d (%s) line %d opening %s" + ,sock, user.alias, errno, strerror(errno), __LINE__, fname); sockprintf(sock,sess, "451 Insufficient system storage"); filepos=0; continue; } - lprintf(LOG_INFO,"%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,genvpath(lib,dir,str) ,mode); credits=FALSE; @@ -5289,7 +5298,7 @@ static void ctrl_thread(void* arg) } else if(dir>=0) { if(!chk_ar(&scfg,scfg.dir[dir]->ar,&user,&client)) { - lprintf(LOG_WARNING,"%04d !%s has insufficient access to /%s/%s" + lprintf(LOG_WARNING,"%04d <%s> has insufficient access to /%s/%s" ,sock,user.alias ,scfg.lib[scfg.dir[dir]->lib]->sname ,scfg.dir[dir]->code_suffix); @@ -5300,7 +5309,7 @@ static void ctrl_thread(void* arg) if(!getsize && !getdate && !delecmd && !chk_ar(&scfg,scfg.dir[dir]->dl_ar,&user,&client)) { - lprintf(LOG_WARNING,"%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 ,scfg.lib[scfg.dir[dir]->lib]->sname ,scfg.dir[dir]->code_suffix); @@ -5310,7 +5319,7 @@ static void ctrl_thread(void* arg) } if(delecmd && !dir_op(&scfg,&user,&client,dir) && !(user.exempt&FLAG('R'))) { - lprintf(LOG_WARNING,"%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 ,scfg.lib[scfg.dir[dir]->lib]->sname ,scfg.dir[dir]->code_suffix); @@ -5331,7 +5340,7 @@ static void ctrl_thread(void* arg) filedat=getfileixb(&scfg,&f); if(!filedat && !(startup->options&FTP_OPT_DIR_FILES) && !(scfg.dir[dir]->misc&DIR_FILES)) { sockprintf(sock,sess,"550 File not found: %s",p); - lprintf(LOG_WARNING,"%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,genvpath(lib,dir,str),p,cmd); filepos=0; continue; @@ -5345,7 +5354,7 @@ static void ctrl_thread(void* arg) else f.cdt=flength(fname); if(f.cdt>(user.cdt+user.freecdt)) { - lprintf(LOG_WARNING,"%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 ,scfg.dir[dir]->code_suffix ,p @@ -5365,7 +5374,7 @@ static void ctrl_thread(void* arg) if(fexistcase(fname)) { success=TRUE; if(!getsize && !getdate && !delecmd) - lprintf(LOG_INFO,"%04d %s downloading: %s (%"PRIuOFF" bytes) in %s mode" + lprintf(LOG_INFO,"%04d <%s> downloading: %s (%"PRIuOFF" bytes) in %s mode" ,sock,user.alias,fname,flength(fname) ,mode); } @@ -5387,11 +5396,11 @@ static void ctrl_thread(void* arg) ,tm.tm_hour,tm.tm_min,tm.tm_sec); } else if(delecmd && success) { if(removecase(fname)!=0) { - lprintf(LOG_ERR,"%04d !ERROR %d deleting %s",sock,errno,fname); + lprintf(LOG_ERR,"%04d <%d> !ERROR %d (%s) deleting %s",sock,user.alias, errno, strerror(errno), fname); sockprintf(sock,sess,"450 %s could not be deleted (error: %d)" ,fname,errno); } else { - lprintf(LOG_NOTICE,"%04d %s deleted %s",sock,user.alias,fname); + lprintf(LOG_NOTICE,"%04d <%s> deleted %s",sock,user.alias,fname); if(filedat) removefiledat(&scfg,&f); sockprintf(sock,sess,"250 %s deleted.",fname); @@ -5404,7 +5413,7 @@ static void ctrl_thread(void* arg) } else { sockprintf(sock,sess,"550 File not found: %s",p); - lprintf(LOG_WARNING,"%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,genvpath(lib,dir,str),p,cmd); } filepos=0; @@ -5495,13 +5504,13 @@ static void ctrl_thread(void* arg) sprintf(str,"%s.rep",scfg.sys_id); if(!(startup->options&FTP_OPT_ALLOW_QWK) || stricmp(p,str)) { - lprintf(LOG_WARNING,"%04d !%s attempted to upload to invalid directory" + lprintf(LOG_WARNING,"%04d <%s> !attempted to upload to invalid directory" ,sock,user.alias); sockprintf(sock,sess,"553 Invalid directory."); continue; } sprintf(fname,"%sfile/%04d.rep",scfg.data_dir,user.number); - lprintf(LOG_INFO,"%04d %s uploading: %s in %s mode" + lprintf(LOG_INFO,"%04d <%s> uploading: %s in %s mode" ,sock,user.alias,fname ,mode); } else { @@ -5510,7 +5519,7 @@ static void ctrl_thread(void* arg) if(!dir_op(&scfg,&user,&client,dir) && !(user.exempt&FLAG('U'))) { if(!chk_ar(&scfg,scfg.dir[dir]->ul_ar,&user,&client)) { - lprintf(LOG_WARNING,"%04d !%s cannot upload to /%s/%s (insufficient access)" + lprintf(LOG_WARNING,"%04d <%s> cannot upload to /%s/%s (insufficient access)" ,sock,user.alias ,scfg.lib[scfg.dir[dir]->lib]->sname ,scfg.dir[dir]->code_suffix); @@ -5519,7 +5528,7 @@ static void ctrl_thread(void* arg) } if(!append && scfg.dir[dir]->maxfiles && getfiles(&scfg,dir)>=scfg.dir[dir]->maxfiles) { - lprintf(LOG_WARNING,"%04d !%s cannot upload to /%s/%s (directory full: %ld files)" + lprintf(LOG_WARNING,"%04d <%s> cannot upload to /%s/%s (directory full: %ld files)" ,sock,user.alias ,scfg.lib[scfg.dir[dir]->lib]->sname ,scfg.dir[dir]->code_suffix @@ -5544,7 +5553,7 @@ static void ctrl_thread(void* arg) || (startup->options&FTP_OPT_HTML_INDEX_FILE && !stricmp(p,startup->html_index_file)) ) { - lprintf(LOG_WARNING,"%04d !%s attempted to overwrite existing file: %s" + lprintf(LOG_WARNING,"%04d <%s> attempted to overwrite existing file: %s" ,sock,user.alias,fname); sockprintf(sock,sess,"553 File already exists."); continue; @@ -5561,7 +5570,7 @@ static void ctrl_thread(void* arg) f.size=-1; if(!getfileixb(&scfg,&f) || !getfiledat(&scfg,&f)) { if(filepos) { - lprintf(LOG_WARNING,"%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); sockprintf(sock,sess,"550 File not found: %s",p); continue; @@ -5570,13 +5579,13 @@ static void ctrl_thread(void* arg) } /* Verify user is original uploader */ if((append || filepos) && stricmp(f.uler,user.alias)) { - lprintf(LOG_WARNING,"%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); sockprintf(sock,sess,"553 Insufficient access (can't resume upload from different user)."); continue; } } - lprintf(LOG_INFO,"%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 ,p /* filename */ ,genvpath(lib,dir,str) /* virtual path */ @@ -5627,14 +5636,14 @@ static void ctrl_thread(void* arg) p+=strlen(LOCAL_FSYS_DIR); if(!direxist(p)) { sockprintf(sock,sess,"550 Directory does not exist."); - lprintf(LOG_WARNING,"%04d !%s attempted to mount invalid directory: %s" + lprintf(LOG_WARNING,"%04d <%s> attempted to mount invalid directory: %s" ,sock, user.alias, p); continue; } SAFECOPY(local_dir,p); local_fsys=TRUE; sockprintf(sock,sess,"250 CWD command successful (local file system mounted)."); - lprintf(LOG_INFO,"%04d %s mounted local file system", sock, user.alias); + lprintf(LOG_INFO,"%04d <%s> mounted local file system", sock, user.alias); continue; } success=FALSE; @@ -5729,13 +5738,13 @@ static void ctrl_thread(void* arg) if(!strnicmp(cmd, "MKD", 3) || !strnicmp(cmd,"XMKD",4) || !strnicmp(cmd,"SITE EXEC",9)) { - lprintf(LOG_WARNING,"%04d !SUSPECTED HACK ATTEMPT by %s: '%s'" + lprintf(LOG_WARNING,"%04d <%s> !SUSPECTED HACK ATTEMPT: %s" ,sock,user.alias,cmd); ftp_hacklog("FTP", user.alias, cmd, host_name, &ftp.client_addr); } // TODO: STAT is mandatory sockprintf(sock,sess,"500 Syntax error: '%s'",cmd); - lprintf(LOG_WARNING,"%04d !UNSUPPORTED COMMAND from %s: '%s'" + lprintf(LOG_WARNING,"%04d <%s> !UNSUPPORTED COMMAND: %s" ,sock,user.alias,cmd); } /* while(1) */ @@ -5779,11 +5788,11 @@ static void ctrl_thread(void* arg) if(user.number) { /* Update User Statistics */ if(!logoutuserdat(&scfg, &user, time(NULL), logintime)) - lprintf(LOG_ERR,"%04d !ERROR in logoutuserdat",sock); + lprintf(LOG_ERR,"%04d <%s> !ERROR in logoutuserdat", sock, user.alias); /* Remove QWK-pack semaphore file (if left behind) */ sprintf(str,"%spack%04u.now",scfg.data_dir,user.number); ftp_remove(sock, __LINE__, str); - lprintf(LOG_INFO,"%04d %s logged off",sock,user.alias); + lprintf(LOG_INFO,"%04d <%s> logged off", sock, user.alias); } #ifdef _WIN32