--- sbbs/src/sbbs3/main.cpp 2018/04/24 16:41:23 1.1.1.1 +++ sbbs/src/sbbs3/main.cpp 2018/04/24 16:42:40 1.1.1.2 @@ -1,14 +1,14 @@ /* main.cpp */ -/* Synchronet main/telnet server thread and related functions */ +/* Synchronet terminal server thread and related functions */ -/* $Id: main.cpp,v 1.1.1.1 2018/04/24 16:41:23 root Exp $ */ +/* $Id: main.cpp,v 1.1.1.2 2018/04/24 16:42:40 root Exp $ */ /**************************************************************************** * @format.tab-size 4 (Plain Text/Source Code File Header) * * @format.use-tabs true (see http://www.synchro.net/ptsc_hdr.html) * * * - * Copyright 2006 Rob Swindell - http://www.synchro.net/copyright.html * + * Copyright 2011 Rob Swindell - http://www.synchro.net/copyright.html * * * * This program is free software; you can redistribute it and/or * * modify it under the terms of the GNU General Public License * @@ -38,6 +38,9 @@ #include "sbbs.h" #include "ident.h" #include "telnet.h" +#include "netwrap.h" +#include "js_rtpool.h" +#include "js_request.h" #ifdef __unix__ #include @@ -49,7 +52,7 @@ //--------------------------------------------------------------------------- -#define TELNET_SERVER "Synchronet Telnet Server" +#define TELNET_SERVER "Synchronet Terminal Server" #define STATUS_WFC "Listening" #define TIMEOUT_THREAD_WAIT 60 // Seconds (was 15) @@ -73,11 +76,10 @@ #define SSH_END() #endif -time_t uptime=0; -DWORD served=0; +volatile time_t uptime=0; +volatile ulong served=0; -static ulong node_threads_running=0; -static ulong thread_count=0; +static protected_uint32_t node_threads_running; char lastuseron[LEN_ALIAS+1]; /* Name of user last online */ RingBuf* node_inbuf[MAX_NODES]; @@ -107,16 +109,17 @@ extern "C" { static bbs_startup_t* startup=NULL; -static void status(char* str) +static const char* status(const char* str) { if(startup!=NULL && startup->status!=NULL) startup->status(startup->cbdata,str); + return str; } static void update_clients() { if(startup!=NULL && startup->clients!=NULL) - startup->clients(startup->cbdata,node_threads_running); + startup->clients(startup->cbdata,node_threads_running.value); } void client_on(SOCKET sock, client_t* client, BOOL update) @@ -133,28 +136,36 @@ static void client_off(SOCKET sock) static void thread_up(BOOL setuid) { - thread_count++; if(startup!=NULL && startup->thread_up!=NULL) startup->thread_up(startup->cbdata,TRUE,setuid); } static void thread_down() { - if(thread_count>0) - thread_count--; if(startup!=NULL && startup->thread_up!=NULL) startup->thread_up(startup->cbdata,FALSE,FALSE); } -int lputs(int level, char* str) +int lputs(int level, const char* str) { - if(startup==NULL || startup->lputs==NULL || str==NULL) + if(level <= LOG_ERR) { + errorlog(&scfg,startup==NULL ? NULL:startup->host_name, str); + if(startup!=NULL && startup->errormsg!=NULL) + startup->errormsg(startup->cbdata,level,str); + } + + if(startup==NULL || startup->lputs==NULL || str==NULL || level > startup->log_level) return(0); +#if defined(_WIN32) + if(IsBadCodePtr((FARPROC)startup->lputs)) + return(0); +#endif + return(startup->lputs(startup->cbdata,level,str)); } -int lprintf(int level, char *fmt, ...) +int lprintf(int level, const char *fmt, ...) { va_list argptr; char sbuf[1024]; @@ -166,20 +177,27 @@ int lprintf(int level, char *fmt, ...) return(lputs(level,sbuf)); } -int eprintf(int level, char *fmt, ...) +int eprintf(int level, const char *fmt, ...) { va_list argptr; char sbuf[1024]; - if(startup==NULL || startup->event_lputs==NULL) - return(0); - va_start(argptr,fmt); vsnprintf(sbuf,sizeof(sbuf),fmt,argptr); sbuf[sizeof(sbuf)-1]=0; va_end(argptr); - strip_ctrl(sbuf); - return(startup->event_lputs(level,sbuf)); + + if(level <= LOG_ERR) { + errorlog(&scfg,startup==NULL ? NULL:startup->host_name, sbuf); + if(startup!=NULL && startup->errormsg!=NULL) + startup->errormsg(startup->cbdata,level,sbuf); + } + + if(startup==NULL || startup->event_lputs==NULL || level > startup->log_level) + return(0); + + strip_ctrl(sbuf, sbuf); + return(startup->event_lputs(startup->event_cbdata,level,sbuf)); } SOCKET open_socket(int type, const char* protocol) @@ -219,7 +237,7 @@ int close_socket(SOCKET sock) if(startup!=NULL && startup->socket_open!=NULL) startup->socket_open(startup->cbdata,FALSE); if(result!=0 && ERROR_VALUE!=ENOTSOCK) - lprintf(LOG_ERR,"!ERROR %d closing socket %d",ERROR_VALUE,sock); + lprintf(LOG_WARNING,"!ERROR %d closing socket %d",ERROR_VALUE,sock); return(result); } @@ -255,12 +273,12 @@ static BOOL winsock_startup(void) int status; /* Status Code */ if((status = WSAStartup(MAKEWORD(1,1), &WSAData))==0) { - lprintf(LOG_INFO,"%s %s",WSAData.szDescription, WSAData.szSystemStatus); + lprintf(LOG_DEBUG,"%s %s",WSAData.szDescription, WSAData.szSystemStatus); WSAInitialized=TRUE; return(TRUE); } - lprintf(LOG_ERR,"!WinSock startup ERROR %d", status); + lprintf(LOG_CRIT,"!WinSock startup ERROR %d", status); return(FALSE); } @@ -273,8 +291,9 @@ static BOOL winsock_startup(void) DLLEXPORT void DLLCALL sbbs_srand() { - DWORD seed = time(NULL) ^ (DWORD)GetCurrentThreadId(); + DWORD seed; + xp_randomize(); #if defined(HAS_DEV_RANDOM) && defined(RANDOM_DEV) int rf; @@ -282,6 +301,8 @@ DLLEXPORT void DLLCALL sbbs_srand() read(rf, &seed, sizeof(seed)); close(rf); } +#else + seed = time(NULL) ^ (DWORD)GetCurrentThreadId(); #endif srand(seed); @@ -500,6 +521,34 @@ DLLCALL js_DefineSyncMethods(JSContext* return(JS_TRUE); } +/* + * Always resolve all here since + * 1) We'll always be enumerating anyways + * 2) The speed penalty won't be seen in production code anyways + */ +JSBool +DLLCALL js_SyncResolve(JSContext* cx, JSObject* obj, char *name, jsSyncPropertySpec* props, jsSyncMethodSpec* funcs, jsConstIntSpec* consts, int flags) +{ + JSBool ret=JS_TRUE; + + if(props) { + if(!js_DefineSyncProperties(cx, obj, props)) + ret=JS_FALSE; + } + + if(funcs) { + if(!js_DefineSyncMethods(cx, obj, funcs, 0)) + ret=JS_FALSE; + } + + if(consts) { + if(!js_DefineConstIntegers(cx, obj, consts, flags)) + ret=JS_FALSE; + } + + return(ret); +} + #else // NON-JSDOCS JSBool @@ -527,6 +576,51 @@ DLLCALL js_DefineSyncMethods(JSContext* return(JS_TRUE); } +JSBool +DLLCALL js_SyncResolve(JSContext* cx, JSObject* obj, char *name, jsSyncPropertySpec* props, jsSyncMethodSpec* funcs, jsConstIntSpec* consts, int flags) +{ + uint i; + jsval val; + + if(props) { + for(i=0;props[i].name;i++) { + if(name==NULL || strcmp(name, props[i].name)==0) { + if(!JS_DefinePropertyWithTinyId(cx, obj, + props[i].name,props[i].tinyid, JSVAL_VOID, NULL, NULL, props[i].flags|JSPROP_SHARED)) + return(JS_FALSE); + if(name) + return(JS_TRUE); + } + } + } + if(funcs) { + for(i=0;funcs[i].name;i++) { + if(name==NULL || strcmp(name, funcs[i].name)==0) { + if(!JS_DefineFunction(cx, obj, funcs[i].name, funcs[i].call, funcs[i].nargs, 0)) + return(JS_FALSE); + if(name) + return(JS_TRUE); + } + } + } + if(consts) { + for(i=0;consts[i].name;i++) { + if(name==NULL || strcmp(name, consts[i].name)==0) { + if(!JS_NewNumberValue(cx, consts[i].val, &val)) + return(JS_FALSE); + + if(!JS_DefineProperty(cx, obj, consts[i].name, val ,NULL, NULL, flags)) + return(JS_FALSE); + + if(name) + return(JS_TRUE); + } + } + } + + return(JS_TRUE); +} + #endif /* This is a stream-lined version of JS_DefineConstDoubles */ @@ -543,7 +637,7 @@ DLLCALL js_DefineConstIntegers(JSContext if(!JS_DefineProperty(cx, obj, ints[i].name, val ,NULL, NULL, flags)) return(JS_FALSE); } - + return(JS_TRUE); } @@ -568,6 +662,7 @@ js_log(JSContext *cx, JSObject *obj, uin int32 level=LOG_INFO; JSString* str=NULL; sbbs_t* sbbs; + jsrefcount rc; if((sbbs=(sbbs_t*)JS_GetContextPrivate(cx))==NULL) return(JS_FALSE); @@ -576,13 +671,17 @@ js_log(JSContext *cx, JSObject *obj, uin JS_ValueToInt32(cx,argv[i++],&level); for(; ionline==ON_LOCAL) { - if(startup!=NULL && startup->event_lputs!=NULL) - startup->event_lputs(level,JS_GetStringBytes(str)); + if(startup!=NULL && startup->event_lputs!=NULL && level <= startup->log_level) + startup->event_lputs(startup->event_cbdata,level,JS_GetStringBytes(str)); } else - lputs(level,JS_GetStringBytes(str)); + lprintf(level,"Node %d %s", sbbs->cfg.node_num, JS_GetStringBytes(str)); + JS_RESUMEREQUEST(cx, rc); } if(str==NULL) @@ -598,6 +697,7 @@ js_read(JSContext *cx, JSObject *obj, ui uchar* buf; int32 len=128; sbbs_t* sbbs; + jsrefcount rc; if((sbbs=(sbbs_t*)JS_GetContextPrivate(cx))==NULL) return(JS_FALSE); @@ -608,7 +708,9 @@ js_read(JSContext *cx, JSObject *obj, ui if((buf=(uchar*)malloc(len))==NULL) return(JS_TRUE); + rc=JS_SUSPENDREQUEST(cx); len=RingBufRead(&sbbs->inbuf,buf,len); + JS_RESUMEREQUEST(cx, rc); if(len>0) *rval = STRING_TO_JSVAL(JS_NewStringCopyN(cx,(char*)buf,len)); @@ -623,6 +725,7 @@ js_readln(JSContext *cx, JSObject *obj, char* buf; int32 len=128; sbbs_t* sbbs; + jsrefcount rc; if((sbbs=(sbbs_t*)JS_GetContextPrivate(cx))==NULL) return(JS_FALSE); @@ -633,7 +736,9 @@ js_readln(JSContext *cx, JSObject *obj, if((buf=(char*)malloc(len))==NULL) return(JS_TRUE); + rc=JS_SUSPENDREQUEST(cx); len=sbbs->getstr(buf,len,K_NONE); + JS_RESUMEREQUEST(cx, rc); if(len>0) *rval = STRING_TO_JSVAL(JS_NewStringCopyZ(cx,buf)); @@ -648,6 +753,7 @@ js_write(JSContext *cx, JSObject *obj, u uintN i; JSString* str=NULL; sbbs_t* sbbs; + jsrefcount rc; if((sbbs=(sbbs_t*)JS_GetContextPrivate(cx))==NULL) return(JS_FALSE); @@ -655,10 +761,12 @@ js_write(JSContext *cx, JSObject *obj, u for (i = 0; i < argc; i++) { if((str=JS_ValueToString(cx, argv[i]))==NULL) return(JS_FALSE); + rc=JS_SUSPENDREQUEST(cx); if(sbbs->online==ON_LOCAL) eprintf(LOG_INFO,"%s",JS_GetStringBytes(str)); else sbbs->bputs(JS_GetStringBytes(str)); + JS_RESUMEREQUEST(cx, rc); } if(str==NULL) @@ -675,6 +783,7 @@ js_write_raw(JSContext *cx, JSObject *ob char* str=NULL; size_t len; sbbs_t* sbbs; + jsrefcount rc; if((sbbs=(sbbs_t*)JS_GetContextPrivate(cx))==NULL) return(JS_FALSE); @@ -682,7 +791,9 @@ js_write_raw(JSContext *cx, JSObject *ob for (i = 0; i < argc; i++) { if((str=js_ValueToStringBytes(cx, argv[i], &len))==NULL) return(JS_FALSE); + rc=JS_SUSPENDREQUEST(cx); sbbs->putcom(str, len); + JS_RESUMEREQUEST(cx, rc); } return(JS_TRUE); @@ -692,13 +803,16 @@ static JSBool js_writeln(JSContext *cx, JSObject *obj, uintN argc, jsval *argv, jsval *rval) { sbbs_t* sbbs; + jsrefcount rc; if((sbbs=(sbbs_t*)JS_GetContextPrivate(cx))==NULL) return(JS_FALSE); js_write(cx,obj,argc,argv,rval); + rc=JS_SUSPENDREQUEST(cx); if(sbbs->online==ON_REMOTE) sbbs->bputs(crlf); + JS_RESUMEREQUEST(cx, rc); return(JS_TRUE); } @@ -708,6 +822,7 @@ js_printf(JSContext *cx, JSObject *obj, { char* p; sbbs_t* sbbs; + jsrefcount rc; if((sbbs=(sbbs_t*)JS_GetContextPrivate(cx))==NULL) return(JS_FALSE); @@ -717,10 +832,12 @@ js_printf(JSContext *cx, JSObject *obj, return(JS_FALSE); } + rc=JS_SUSPENDREQUEST(cx); if(sbbs->online==ON_LOCAL) eprintf(LOG_INFO,"%s",p); else sbbs->bputs(p); + JS_RESUMEREQUEST(cx, rc); *rval = STRING_TO_JSVAL(JS_NewStringCopyZ(cx, p)); @@ -734,6 +851,7 @@ js_alert(JSContext *cx, JSObject *obj, u { JSString * str; sbbs_t* sbbs; + jsrefcount rc; if((sbbs=(sbbs_t*)JS_GetContextPrivate(cx))==NULL) return(JS_FALSE); @@ -741,10 +859,12 @@ js_alert(JSContext *cx, JSObject *obj, u if((str=JS_ValueToString(cx, argv[0]))==NULL) return(JS_FALSE); + rc=JS_SUSPENDREQUEST(cx); sbbs->attr(sbbs->cfg.color[clr_err]); sbbs->bputs(JS_GetStringBytes(str)); sbbs->attr(LIGHTGRAY); sbbs->bputs(crlf); + JS_RESUMEREQUEST(cx, rc); return(JS_TRUE); } @@ -754,6 +874,7 @@ js_confirm(JSContext *cx, JSObject *obj, { JSString * str; sbbs_t* sbbs; + jsrefcount rc; if((sbbs=(sbbs_t*)JS_GetContextPrivate(cx))==NULL) return(JS_FALSE); @@ -761,17 +882,40 @@ js_confirm(JSContext *cx, JSObject *obj, if((str=JS_ValueToString(cx, argv[0]))==NULL) return(JS_FALSE); + rc=JS_SUSPENDREQUEST(cx); *rval = BOOLEAN_TO_JSVAL(sbbs->yesno(JS_GetStringBytes(str))); + JS_RESUMEREQUEST(cx, rc); return(JS_TRUE); } static JSBool +js_deny(JSContext *cx, JSObject *obj, uintN argc, jsval *argv, jsval *rval) +{ + JSString * str; + sbbs_t* sbbs; + jsrefcount rc; + + if((sbbs=(sbbs_t*)JS_GetContextPrivate(cx))==NULL) + return(JS_FALSE); + + if((str=JS_ValueToString(cx, argv[0]))==NULL) + return(JS_FALSE); + + rc=JS_SUSPENDREQUEST(cx); + *rval = BOOLEAN_TO_JSVAL(sbbs->noyes(JS_GetStringBytes(str))); + JS_RESUMEREQUEST(cx, rc); + return(JS_TRUE); +} + + +static JSBool js_prompt(JSContext *cx, JSObject *obj, uintN argc, jsval *argv, jsval *rval) { char instr[81]; JSString * prompt; JSString * str; sbbs_t* sbbs; + jsrefcount rc; if((sbbs=(sbbs_t*)JS_GetContextPrivate(cx))==NULL) return(JS_FALSE); @@ -786,12 +930,15 @@ js_prompt(JSContext *cx, JSObject *obj, } else instr[0]=0; + rc=JS_SUSPENDREQUEST(cx); sbbs->bprintf("\1n\1y\1h%s\1w: ",JS_GetStringBytes(prompt)); if(!sbbs->getstr(instr,sizeof(instr)-1,K_EDIT)) { *rval = JSVAL_NULL; + JS_RESUMEREQUEST(cx, rc); return(JS_TRUE); } + JS_RESUMEREQUEST(cx, rc); if((str=JS_NewStringCopyZ(cx, instr))==NULL) return(JS_FALSE); @@ -843,9 +990,14 @@ static jsSyncMethodSpec js_global_functi }, {"confirm", js_confirm, 1, JSTYPE_BOOLEAN, JSDOCSTR("value") ,JSDOCSTR("displays a Yes/No prompt and returns true or false " - "based on users confirmation (ala client-side JS)") + "based on user's confirmation (ala client-side JS, true = yes)") ,310 }, + {"deny", js_deny, 1, JSTYPE_BOOLEAN, JSDOCSTR("value") + ,JSDOCSTR("displays a No/Yes prompt and returns true or false " + "based on user's denial (true = no)") + ,31501 + }, {0} }; @@ -856,12 +1008,20 @@ js_ErrorReporter(JSContext *cx, const ch char file[MAX_PATH+1]; sbbs_t* sbbs; const char* warning; + jsrefcount rc; + int log_level; + char nodestr[128]; if((sbbs=(sbbs_t*)JS_GetContextPrivate(cx))==NULL) return; + + if(sbbs->cfg.node_num) + SAFEPRINTF(nodestr,"Node %d",sbbs->cfg.node_num); + else + SAFECOPY(nodestr,sbbs->client_name); if(report==NULL) { - lprintf(LOG_ERR,"!JavaScript: %s", message); + lprintf(LOG_ERR,"%s !JavaScript: %s", nodestr, message); return; } @@ -880,15 +1040,20 @@ js_ErrorReporter(JSContext *cx, const ch warning="strict warning"; else warning="warning"; - } else + log_level = LOG_WARNING; + } else { warning=nulstr; + log_level = LOG_ERR; + } + rc=JS_SUSPENDREQUEST(cx); if(sbbs->online==ON_LOCAL) - eprintf(LOG_ERR,"!JavaScript %s%s%s: %s",warning,file,line,message); + eprintf(log_level,"!JavaScript %s%s%s: %s",warning,file,line,message); else { - lprintf(LOG_ERR,"!JavaScript %s%s%s: %s",warning,file,line,message); + lprintf(log_level,"%s !JavaScript %s%s%s: %s",nodestr,warning,file,line,message); sbbs->bprintf("!JavaScript %s%s%s: %s\r\n",warning,file,line,message); } + JS_RESUMEREQUEST(cx, rc); } bool sbbs_t::js_init(ulong* stack_frame) @@ -906,7 +1071,7 @@ bool sbbs_t::js_init(ulong* stack_frame) lprintf(LOG_DEBUG,"%s JavaScript: Creating runtime: %lu bytes" ,node,startup->js.max_bytes); - if((js_runtime = JS_NewRuntime(startup->js.max_bytes))==NULL) + if((js_runtime = jsrt_GetNew(startup->js.max_bytes, 1000, __FILE__, __LINE__))==NULL) return(false); lprintf(LOG_DEBUG,"%s JavaScript: Initializing context (stack: %lu bytes)" @@ -914,6 +1079,7 @@ bool sbbs_t::js_init(ulong* stack_frame) if((js_cx = JS_NewContext(js_runtime, startup->js.cx_stack))==NULL) return(false); + JS_BEGINREQUEST(js_cx); memset(&js_branch,0,sizeof(js_branch)); js_branch.limit = startup->js.branch_limit; @@ -934,6 +1100,7 @@ bool sbbs_t::js_init(ulong* stack_frame) if((js_glob=js_CreateCommonObjects(js_cx, &scfg, &cfg, js_global_functions ,uptime, startup->host_name, SOCKLIB_DESC /* system */ ,&js_branch /* js */ + ,&startup->js ,&client, client_socket /* client */ ,&js_server_props /* server */ ))==NULL) @@ -965,6 +1132,7 @@ bool sbbs_t::js_init(ulong* stack_frame) } while(0); + JS_ENDREQUEST(js_cx); if(!success) { JS_DestroyContext(js_cx); js_cx=NULL; @@ -974,13 +1142,31 @@ bool sbbs_t::js_init(ulong* stack_frame) return(true); } +void sbbs_t::js_cleanup(const char* node) +{ + /* Free Context */ + if(js_cx!=NULL) { + lprintf(LOG_DEBUG,"%s JavaScript: Destroying context",node); + JS_DestroyContext(js_cx); + js_cx=NULL; + } + + if(js_runtime!=NULL) { + lprintf(LOG_DEBUG,"%s JavaScript: Destroying runtime",node); + jsrt_Release(js_runtime); + js_runtime=NULL; + } +} + void sbbs_t::js_create_user_objects(void) { if(js_cx==NULL) return; - - if(!js_CreateUserObjects(js_cx, js_glob, &cfg, &useron, NULL, subscan)) + + JS_BEGINREQUEST(js_cx); + if(!js_CreateUserObjects(js_cx, js_glob, &cfg, &useron, &client, NULL, subscan)) lprintf(LOG_ERR,"!JavaScript ERROR creating user objects"); + JS_ENDREQUEST(js_cx); } #endif /* JAVASCRIPT */ @@ -1054,6 +1240,13 @@ static BYTE* telnet_interpret(sbbs_t* sb if(sbbs->telnet_cmdlen>=2 && command==TELNET_SB) { if(inbuf[i]==TELNET_SE && sbbs->telnet_cmd[sbbs->telnet_cmdlen-2]==TELNET_IAC) { + + if(startup->options&BBS_OPT_DEBUG_TELNET) + lprintf(LOG_DEBUG,"Node %d %s telnet sub-negotiation command: %s" + ,sbbs->cfg.node_num + ,sbbs->telnet_mode&TELNET_MODE_GATE ? "passed-through" : "received" + ,telnet_opt_desc(option)); + /* sub-option terminated */ if(option==TELNET_TERM_TYPE && sbbs->telnet_cmd[3]==TELNET_TERM_IS) { @@ -1071,6 +1264,34 @@ static BYTE* telnet_interpret(sbbs_t* sb ,sbbs->cfg.node_num ,sbbs->telnet_mode&TELNET_MODE_GATE ? "passed-through" : "received" ,speed); + sbbs->cur_rate=atoi(speed); + sbbs->cur_cps=sbbs->cur_rate/10; +#if 0 + } else if(option==TELNET_NEW_ENVIRON + && sbbs->telnet_cmd[3]==TELNET_ENVIRON_IS) { + BYTE* p; + BYTE* end=sbbs->telnet_cmd+(sbbs->telnet_cmdlen-2); + for(p=sbbs->telnet_cmd+4; p < end; ) { + if(*p==TELNET_ENVIRON_VAR || *p==TELNET_ENVIRON_USERVAR) { + p++; + lprintf(LOG_DEBUG,"Node %d %s telnet environment var/val: %.*s" + ,sbbs->cfg.node_num + ,sbbs->telnet_mode&TELNET_MODE_GATE ? "passed-through" : "received" + ,end-p + ,p); + p+=strlen((char*)p); + } else + p++; + } +#endif + } else if(option==TELNET_SEND_LOCATION) { + safe_snprintf(sbbs->telnet_location + ,sizeof(sbbs->telnet_location) + ,"%.*s",(int)sbbs->telnet_cmdlen-5,sbbs->telnet_cmd+3); + lprintf(LOG_DEBUG,"Node %d %s telnet location: %s" + ,sbbs->cfg.node_num + ,sbbs->telnet_mode&TELNET_MODE_GATE ? "passed-through" : "received" + ,sbbs->telnet_location); } else if(option==TELNET_NEGOTIATE_WINDOW_SIZE) { long cols = (sbbs->telnet_cmd[3]<<8) | sbbs->telnet_cmd[4]; @@ -1112,13 +1333,16 @@ static BYTE* telnet_interpret(sbbs_t* sb if(!(sbbs->telnet_mode&TELNET_MODE_GATE)) { if(command==TELNET_DO || command==TELNET_DONT) { /* local options */ - if(sbbs->telnet_local_option[option]!=command) { + if(sbbs->telnet_local_option[option]==command) + SetEvent(sbbs->telnet_ack_event); + else { sbbs->telnet_local_option[option]=command; sbbs->send_telnet_cmd(telnet_opt_ack(command),option); } } else { /* WILL/WONT (remote options) */ - if(sbbs->telnet_remote_option[option]!=command) { - + if(sbbs->telnet_remote_option[option]==command) + SetEvent(sbbs->telnet_ack_event); + else { switch(option) { case TELNET_BINARY_TX: case TELNET_ECHO: @@ -1126,6 +1350,7 @@ static BYTE* telnet_interpret(sbbs_t* sb case TELNET_TERM_SPEED: case TELNET_SUP_GA: case TELNET_NEGOTIATE_WINDOW_SIZE: + case TELNET_SEND_LOCATION: sbbs->telnet_remote_option[option]=command; sbbs->send_telnet_cmd(telnet_opt_ack(command),option); break; @@ -1160,6 +1385,20 @@ static BYTE* telnet_interpret(sbbs_t* sb ,TELNET_IAC,TELNET_SE); sbbs->putcom(buf,6); } +#if 0 + else if(command==TELNET_WILL && option==TELNET_NEW_ENVIRON) { + if(startup->options&BBS_OPT_DEBUG_TELNET) + lprintf(LOG_DEBUG,"Node %d requesting USER environment variable value" + ,sbbs->cfg.node_num); + + char buf[64]; + int len=sprintf(buf,"%c%c%c%c%cUSER%c%c" + ,TELNET_IAC,TELNET_SB + ,TELNET_NEW_ENVIRON,TELNET_ENVIRON_SEND,TELNET_ENVIRON_VAR + ,TELNET_IAC,TELNET_SE); + sbbs->putcom(buf,len); + } +#endif } } @@ -1199,18 +1438,23 @@ void sbbs_t::send_telnet_cmd(uchar cmd, } } -void sbbs_t::request_telnet_opt(uchar cmd, uchar opt) +bool sbbs_t::request_telnet_opt(uchar cmd, uchar opt, unsigned waitforack) { if(cmd==TELNET_DO || cmd==TELNET_DONT) { /* remote option */ if(telnet_remote_option[opt]==telnet_opt_ack(cmd)) - return; /* already set in this mode, do nothing */ + return true; /* already set in this mode, do nothing */ telnet_remote_option[opt]=telnet_opt_ack(cmd); } else { /* local option */ if(telnet_local_option[opt]==telnet_opt_ack(cmd)) - return; /* already set in this mode, do nothing */ + return true; /* already set in this mode, do nothing */ telnet_local_option[opt]=telnet_opt_ack(cmd); } + if(waitforack) + ResetEvent(telnet_ack_event); send_telnet_cmd(cmd,opt); + if(waitforack) + return WaitForEvent(telnet_ack_event, waitforack)==WAIT_OBJECT_0; + return true; } void input_thread(void *arg) @@ -1227,6 +1471,7 @@ void input_thread(void *arg) SOCKET high_socket; SOCKET sock; + SetThreadName("Node Input"); thread_up(TRUE /* setuid */); #ifdef _DEBUG @@ -1354,8 +1599,16 @@ void input_thread(void *arg) #ifdef USE_CRYPTLIB if(sbbs->ssh_mode && sock==sbbs->client_socket) { - if(!cryptStatusOK(cryptPopData(sbbs->ssh_session, (char*)inbuf, rd, &i))) - rd=0; + int err; + if(!cryptStatusOK((err=cryptPopData(sbbs->ssh_session, (char*)inbuf, rd, &i)))) { + if(pthread_mutex_unlock(&sbbs->input_thread_mutex)!=0) + sbbs->errormsg(WHERE,ERR_UNLOCK,"input_thread_mutex",0); + if(err==CRYPT_ERROR_TIMEOUT) + continue; + /* Handle the SSH error here... */ + lprintf(LOG_WARNING,"Node %d !ERROR %d receiving on Cryptlib session", sbbs->cfg.node_num, err); + break; + } else { if(!i) { if(pthread_mutex_unlock(&sbbs->input_thread_mutex)!=0) @@ -1377,6 +1630,8 @@ void input_thread(void *arg) #ifdef __unix__ if(sock==sbbs->client_socket) { #endif + if(!sbbs->online) // sbbs_t::hangup() called? + break; if(ERROR_VALUE == ENOTSOCK) lprintf(LOG_NOTICE,"Node %d socket closed by peer on receive", sbbs->cfg.node_num); else if(ERROR_VALUE==ECONNRESET) @@ -1470,7 +1725,7 @@ void input_thread(void *arg) #ifdef USE_CRYPTLIB /* - * This thread copies anything recieved from the client to the passthru_socket + * This thread copies anything received from the client to the passthru_socket * It can only do that when the input thread is locked. * Luckily, the input thread is currently locked exactly when we want it to be. * Since the passthru socket is 8-bit clean and does NOT use a protocol, @@ -1490,6 +1745,7 @@ void passthru_output_thread(void* arg) int rd; int wr; + SetThreadName("Passthrough Output"); thread_up(FALSE /* setuid */); sbbs->passthru_output_thread_running = true; @@ -1567,7 +1823,7 @@ void passthru_output_thread(void* arg) if(rd == 0) { - lprintf(LOG_NOTICE,"Node %d passthru input socket disconnected", sbbs->cfg.node_num); + lprintf(LOG_DEBUG,"Node %d passthru input socket disconnected", sbbs->cfg.node_num); break; } @@ -1601,6 +1857,7 @@ void passthru_input_thread(void* arg) BYTE ch; int i; + SetThreadName("Passthrough Input"); thread_up(FALSE /* setuid */); sbbs->passthru_input_thread_running = true; @@ -1657,7 +1914,7 @@ void passthru_input_thread(void* arg) if(i == 0) { - lprintf(LOG_NOTICE,"Node %d passthru disconnected", sbbs->cfg.node_num); + lprintf(LOG_NOTICE,"Node %d SSH passthru disconnected", sbbs->cfg.node_num); break; } @@ -1693,6 +1950,7 @@ void output_thread(void* arg) struct timeval tv; ulong mss=IO_THREAD_BUF_SIZE; + SetThreadName("Node Output"); thread_up(TRUE /* setuid */); if(sbbs->cfg.node_num) @@ -1768,7 +2026,7 @@ void output_thread(void* arg) * into linear buffer. */ if(avail>sizeof(buf)) { - lprintf(LOG_WARNING,"!%s: Insufficient linear output buffer (%lu > %lu)" + lprintf(LOG_WARNING,"%s !Insufficient linear output buffer (%lu > %lu)" ,node, avail, sizeof(buf)); avail=sizeof(buf); } @@ -1784,16 +2042,19 @@ void output_thread(void* arg) tv.tv_usec=1000; FD_ZERO(&socket_set); + if(sbbs->client_socket==INVALID_SOCKET) // Make the race condition less likely to actually happen... TODO: Fix race + continue; FD_SET(sbbs->client_socket,&socket_set); i=select(sbbs->client_socket+1,NULL,&socket_set,NULL,&tv); if(i==SOCKET_ERROR) { if(sbbs->client_socket!=INVALID_SOCKET) - lprintf(LOG_ERR,"!%s: ERROR %d selecting socket %u for send" + lprintf(LOG_ERR,"%s !ERROR %d selecting socket %u for send" ,node,ERROR_VALUE,sbbs->client_socket); if(sbbs->cfg.node_num) /* Only break if node output (not server) */ break; - RingBufReInit(&sbbs->outbuf); /* Flush output buffer */ + RingBufReInit(&sbbs->outbuf); /* Purge output ring buffer */ + bufbot=buftop=0; /* Purge linear buffer */ continue; } if(i<1) { @@ -1802,8 +2063,14 @@ void output_thread(void* arg) #ifdef USE_CRYPTLIB if(sbbs->ssh_mode) { - if(!cryptStatusOK(cryptPushData(sbbs->ssh_session, (char*)buf+bufbot, buftop-bufbot, &i))) + int err; + if(!cryptStatusOK((err=cryptPushData(sbbs->ssh_session, (char*)buf+bufbot, buftop-bufbot, &i)))) { + /* Handle the SSH error here... */ + lprintf(LOG_WARNING,"%s !ERROR %d sending on Cryptlib session", node, err); i=-1; + sbbs->online=FALSE; + i=buftop-bufbot; // Pretend we sent it all + } else cryptFlushData(sbbs->ssh_session); } @@ -1818,7 +2085,7 @@ void output_thread(void* arg) else if(ERROR_VALUE==ECONNABORTED) lprintf(LOG_NOTICE,"%s connection aborted by peer on send", node); else - lprintf(LOG_WARNING,"!%s: ERROR %d sending on socket %d" + lprintf(LOG_WARNING,"%s !ERROR %d sending on socket %d" ,node, ERROR_VALUE, sbbs->client_socket); sbbs->online=FALSE; /* was break; on 4/7/00 */ @@ -1845,7 +2112,7 @@ void output_thread(void* arg) } if(i!=(int)(buftop-bufbot)) { - lprintf(LOG_WARNING,"!%s: Short socket send (%u instead of %u)" + lprintf(LOG_WARNING,"%s !Short socket send (%u instead of %u)" ,node, i ,buftop-bufbot); short_sends++; } @@ -1879,29 +2146,33 @@ void event_thread(void* arg) int offset; bool check_semaphores; bool packed_rep; - ulong l; + ulong l; + /* TODO: This is a silly hack... */ + uint32_t l32; time_t now; time_t start; time_t lastsemchk=0; time_t lastnodechk=0; - time_t lastprepack=0; + time32_t lastprepack=0; + time_t tmptime; node_t node; glob_t g; sbbs_t* sbbs = (sbbs_t*) arg; struct tm now_tm; struct tm tm; - eprintf(LOG_DEBUG,"BBS Events thread started"); + eprintf(LOG_INFO,"BBS Events thread started"); sbbs->event_thread_running = true; sbbs_srand(); /* Seed random number generator */ + SetThreadName("BBS Events"); thread_up(TRUE /* setuid */); #ifdef JAVASCRIPT if(!(startup->options&BBS_OPT_NO_JAVASCRIPT)) { - if(!sbbs->js_init(&stack_frame)) /* This must be done in the context of the event thread */ + if(!sbbs->js_init(&stack_frame)) /* This must be done in the context of the events thread */ lprintf(LOG_ERR,"!JavaScript Initialization FAILURE"); } #endif @@ -1913,20 +2184,20 @@ void event_thread(void* arg) else { for(i=0;icfg.total_events;i++) { sbbs->cfg.event[i]->last=0; - if(filelength(file)<(long)(sizeof(time_t)*(i+1))) { + if(filelength(file)<(long)(sizeof(time32_t)*(i+1))) { eprintf(LOG_WARNING,"Initializing last run time for event: %s" ,sbbs->cfg.event[i]->code); - write(file,&sbbs->cfg.event[i]->last,sizeof(time_t)); + write(file,&sbbs->cfg.event[i]->last,sizeof(sbbs->cfg.event[i]->last)); } else { - if(read(file,&sbbs->cfg.event[i]->last,sizeof(time_t))!=sizeof(time_t)) - sbbs->errormsg(WHERE,ERR_READ,str,sizeof(time_t)); + if(read(file,&sbbs->cfg.event[i]->last,sizeof(sbbs->cfg.event[i]->last))!=sizeof(sbbs->cfg.event[i]->last)) + sbbs->errormsg(WHERE,ERR_READ,str,sizeof(time32_t)); } /* Event always runs after initialization? */ if(sbbs->cfg.event[i]->misc&EVENT_INIT) sbbs->cfg.event[i]->last=-1; } lastprepack=0; - read(file,&lastprepack,sizeof(time_t)); /* expected to fail first time */ + read(file,&lastprepack,sizeof(lastprepack)); /* expected to fail first time */ close(file); } @@ -1937,13 +2208,13 @@ void event_thread(void* arg) else { for(i=0;icfg.total_qhubs;i++) { sbbs->cfg.qhub[i]->last=0; - if(filelength(file)<(long)(sizeof(time_t)*(i+1))) { + if(filelength(file)<(long)(sizeof(time32_t)*(i+1))) { eprintf(LOG_WARNING,"Initializing last call-out time for QWKnet hub: %s" ,sbbs->cfg.qhub[i]->id); - write(file,&sbbs->cfg.qhub[i]->last,sizeof(time_t)); + write(file,&sbbs->cfg.qhub[i]->last,sizeof(sbbs->cfg.qhub[i]->last)); } else { - if(read(file,&sbbs->cfg.qhub[i]->last,sizeof(time_t))!=sizeof(time_t)) - sbbs->errormsg(WHERE,ERR_READ,str,sizeof(time_t)); + if(read(file,&sbbs->cfg.qhub[i]->last,sizeof(sbbs->cfg.qhub[i]->last))!=sizeof(sbbs->cfg.qhub[i]->last)) + sbbs->errormsg(WHERE,ERR_READ,str,sizeof(sbbs->cfg.qhub[i]->last)); } } close(file); @@ -1956,10 +2227,10 @@ void event_thread(void* arg) else { for(i=0;icfg.total_phubs;i++) { sbbs->cfg.phub[i]->last=0; - if(filelength(file)<(long)(sizeof(time_t)*(i+1))) - write(file,&sbbs->cfg.phub[i]->last,sizeof(time_t)); + if(filelength(file)<(long)(sizeof(time32_t)*(i+1))) + write(file,&sbbs->cfg.phub[i]->last,sizeof(sbbs->cfg.phub[i]->last)); else - read(file,&sbbs->cfg.phub[i]->last,sizeof(time_t)); + read(file,&sbbs->cfg.phub[i]->last,sizeof(sbbs->cfg.phub[i]->last)); } close(file); } @@ -1994,12 +2265,15 @@ void event_thread(void* arg) getuserdat(&sbbs->cfg,&sbbs->useron); if(sbbs->useron.number && flength(g.gl_pathv[i])>0) { SAFEPRINTF(semfile,"%s.lock",g.gl_pathv[i]); - if(!fmutex(semfile,startup->host_name,24*60*60)) + if(!fmutex(semfile,startup->host_name,24*60*60)) { + eprintf(LOG_INFO,"%s exists (unpack in progress?)", semfile); continue; + } sbbs->online=ON_LOCAL; eprintf(LOG_INFO,"Un-packing QWK Reply packet from %s",sbbs->useron.alias); sbbs->getusrsubs(); sbbs->unpack_rep(g.gl_pathv[i]); + delfiles(sbbs->cfg.temp_dir,ALLFILES); /* clean-up temp_dir after unpacking */ sbbs->batch_create_list(); /* FREQs? */ sbbs->batdn_total=0; @@ -2015,18 +2289,17 @@ void event_thread(void* arg) offset=strlen(sbbs->cfg.data_dir)+4; glob(str,0,NULL,&g); for(i=0;i<(int)g.gl_pathc;i++) { - eprintf(LOG_DEBUG,"QWK pack semaphore signaled: %s", g.gl_pathv[i]); + eprintf(LOG_INFO,"QWK pack semaphore signaled: %s", g.gl_pathv[i]); sbbs->useron.number=atoi(g.gl_pathv[i]+offset); SAFEPRINTF2(semfile,"%spack%04u.lock",sbbs->cfg.data_dir,sbbs->useron.number); if(!fmutex(semfile,startup->host_name,24*60*60)) { - eprintf(LOG_WARNING,"%s exists (already being packed?)", semfile); + eprintf(LOG_INFO,"%s exists (pack in progress?)", semfile); continue; } getuserdat(&sbbs->cfg,&sbbs->useron); if(sbbs->useron.number && !(sbbs->useron.misc&(DELETED|INACTIVE))) { eprintf(LOG_INFO,"Packing QWK Message Packet for %s",sbbs->useron.alias); sbbs->online=ON_LOCAL; - delfiles(sbbs->cfg.temp_dir,ALLFILES); sbbs->getmsgptrs(); sbbs->getusrsubs(); sbbs->batdn_total=0; @@ -2067,7 +2340,7 @@ void event_thread(void* arg) if(sbbs->useron.number && !(sbbs->useron.misc&(DELETED|INACTIVE)) /* Pre-QWK */ - && sbbs->chk_ar(sbbs->cfg.preqwk_ar,&sbbs->useron)) { + && sbbs->chk_ar(sbbs->cfg.preqwk_ar,&sbbs->useron,/* client: */NULL)) { for(k=1;k<=sbbs->cfg.sys_nodes;k++) { if(sbbs->getnodedat(k,&node,0)!=0) continue; @@ -2079,7 +2352,6 @@ void event_thread(void* arg) continue; eprintf(LOG_INFO,"Pre-packing QWK for %s",sbbs->useron.alias); sbbs->online=ON_LOCAL; - delfiles(sbbs->cfg.temp_dir,ALLFILES); sbbs->getmsgptrs(); sbbs->getusrsubs(); sbbs->batdn_total=0; @@ -2100,7 +2372,7 @@ void event_thread(void* arg) break; } lseek(file,(long)sbbs->cfg.total_events*4L,SEEK_SET); - write(file,&lastprepack,sizeof(time_t)); + write(file,&lastprepack,sizeof(lastprepack)); close(file); remove(semfile); @@ -2187,13 +2459,12 @@ void event_thread(void* arg) if(check_semaphores) { // See if any packets have come in - for(j=0;j<101;j++) { - SAFEPRINTF4(str,"%s%s.q%c%c",sbbs->cfg.data_dir,sbbs->cfg.qhub[i]->id - ,j>10 ? ((j-1)/10)+'0' : 'w' - ,j ? ((j-1)%10)+'0' : 'k'); - if(fexistcase(str) && flength(str)>0) { /* silently ignore 0-byte QWK packets */ + SAFEPRINTF2(str,"%s%s.q??",sbbs->cfg.data_dir,sbbs->cfg.qhub[i]->id); + glob(str,GLOB_NOSORT,NULL,&g); + for(j=0;j<(int)g.gl_pathc;j++) { + SAFECOPY(str,g.gl_pathv[j]); + if(flength(str)>0) { /* silently ignore 0-byte QWK packets */ eprintf(LOG_DEBUG,"Inbound QWK Packet detected: %s", str); - delfiles(sbbs->cfg.temp_dir,ALLFILES); sbbs->online=ON_LOCAL; sbbs->console|=CON_L_ECHO; if(sbbs->unpack_qwk(str,i)==false) { @@ -2203,18 +2474,21 @@ void event_thread(void* arg) if(rename(str,newname)==0) { char logmsg[MAX_PATH*3]; SAFEPRINTF2(logmsg,"%s renamed to %s",str,newname); - sbbs->logline("Q!",logmsg); + sbbs->logline(LOG_NOTICE,"Q!",logmsg); } } + delfiles(sbbs->cfg.temp_dir,ALLFILES); sbbs->console&=~CON_L_ECHO; sbbs->online=FALSE; remove(str); } } + globfree(&g); } /* Qnet call out based on time */ - if(localtime_r(&sbbs->cfg.qhub[i]->last,&tm)==NULL) + tmptime=sbbs->cfg.qhub[i]->last; + if(localtime_r(&tmptime,&tm)==NULL) memset(&tm,0,sizeof(tm)); if((sbbs->cfg.qhub[i]->last==-1L /* or frequency */ || ((sbbs->cfg.qhub[i]->freq @@ -2233,8 +2507,8 @@ void event_thread(void* arg) for(j=0;jcfg.qhub[i]->subs;j++) { sbbs->subscan[sbbs->cfg.qhub[i]->sub[j]].ptr=0; if(file!=-1) { - lseek(file,sbbs->cfg.sub[sbbs->cfg.qhub[i]->sub[j]]->ptridx*sizeof(long),SEEK_SET); - read(file,&sbbs->subscan[sbbs->cfg.qhub[i]->sub[j]].ptr,sizeof(long)); + lseek(file,sbbs->cfg.sub[sbbs->cfg.qhub[i]->sub[j]]->ptridx*sizeof(int32_t),SEEK_SET); + read(file,&sbbs->subscan[sbbs->cfg.qhub[i]->sub[j]].ptr,sizeof(sbbs->subscan[sbbs->cfg.qhub[i]->sub[j]].ptr)); } } if(file!=-1) @@ -2248,12 +2522,14 @@ void event_thread(void* arg) else { for(j=l=0;jcfg.qhub[i]->subs;j++) { while(filelength(file)< - sbbs->cfg.sub[sbbs->cfg.qhub[i]->sub[j]]->ptridx*4L) - write(file,&l,4); /* initialize ptrs to null */ + sbbs->cfg.sub[sbbs->cfg.qhub[i]->sub[j]]->ptridx*4L) { + l32=l; + write(file,&l32,4); /* initialize ptrs to null */ + } lseek(file - ,sbbs->cfg.sub[sbbs->cfg.qhub[i]->sub[j]]->ptridx*sizeof(long) + ,sbbs->cfg.sub[sbbs->cfg.qhub[i]->sub[j]]->ptridx*sizeof(int32_t) ,SEEK_SET); - write(file,&sbbs->subscan[sbbs->cfg.qhub[i]->sub[j]].ptr,sizeof(long)); + write(file,&sbbs->subscan[sbbs->cfg.qhub[i]->sub[j]].ptr,sizeof(sbbs->subscan[sbbs->cfg.qhub[i]->sub[j]].ptr)); } close(file); } @@ -2266,8 +2542,8 @@ void event_thread(void* arg) sbbs->errormsg(WHERE,ERR_OPEN,str,O_WRONLY); break; } - lseek(file,sizeof(time_t)*i,SEEK_SET); - write(file,&sbbs->cfg.qhub[i]->last,sizeof(time_t)); + lseek(file,sizeof(time32_t)*i,SEEK_SET); + write(file,&sbbs->cfg.qhub[i]->last,sizeof(sbbs->cfg.qhub[i]->last)); close(file); if(sbbs->cfg.qhub[i]->call[0]) { @@ -2291,7 +2567,8 @@ void event_thread(void* arg) || sbbs->cfg.phub[i]->node>last_node) continue; /* PostLink call out based on time */ - if(localtime_r(&sbbs->cfg.phub[i]->last,&tm)==NULL) + tmptime=sbbs->cfg.phub[i]->last; + if(localtime_r(&tmptime,&tm)==NULL) memset(&tm,0,sizeof(tm)); if(sbbs->cfg.phub[i]->last==-1 || (((sbbs->cfg.phub[i]->freq /* or frequency */ @@ -2307,8 +2584,8 @@ void event_thread(void* arg) sbbs->errormsg(WHERE,ERR_OPEN,str,O_WRONLY); break; } - lseek(file,sizeof(time_t)*i,SEEK_SET); - write(file,&sbbs->cfg.phub[i]->last,sizeof(time_t)); + lseek(file,sizeof(time32_t)*i,SEEK_SET); + write(file,&sbbs->cfg.phub[i]->last,sizeof(sbbs->cfg.phub[i]->last)); close(file); if(sbbs->cfg.phub[i]->call[0]) { @@ -2339,7 +2616,8 @@ void event_thread(void* arg) && !(sbbs->cfg.event[i]->misc&EVENT_EXCL)) continue; // ignore non-exclusive events for other instances - if(localtime_r(&sbbs->cfg.event[i]->last,&tm)==NULL) + tmptime=sbbs->cfg.event[i]->last; + if(localtime_r(&tmptime,&tm)==NULL) memset(&tm,0,sizeof(tm)); if(sbbs->cfg.event[i]->last==-1 || (((sbbs->cfg.event[i]->freq @@ -2349,7 +2627,9 @@ void event_thread(void* arg) && (now_tm.tm_mday!=tm.tm_mday || now_tm.tm_mon!=tm.tm_mon))) && sbbs->cfg.event[i]->days&(1<cfg.event[i]->mdays==0 - || sbbs->cfg.event[i]->mdays&(1<cfg.event[i]->mdays&(1<cfg.event[i]->months==0 + || sbbs->cfg.event[i]->months&(1<cfg.event[i]->misc&EVENT_EXCL) { /* exclusive event */ @@ -2359,7 +2639,7 @@ void event_thread(void* arg) ,sbbs->cfg.event[i]->node,sbbs->cfg.event[i]->code); eprintf(LOG_DEBUG,"%s event last run: %s (0x%08lx)" ,sbbs->cfg.event[i]->code - ,timestr(&sbbs->cfg, &sbbs->cfg.event[i]->last, str) + ,timestr(&sbbs->cfg, sbbs->cfg.event[i]->last, str) ,sbbs->cfg.event[i]->last); lastnodechk=0; /* really last event time check */ start=time(NULL); @@ -2385,7 +2665,7 @@ void event_thread(void* arg) continue; } lseek(file,(long)i*4L,SEEK_SET); - read(file,&sbbs->cfg.event[i]->last,sizeof(time_t)); + read(file,&sbbs->cfg.event[i]->last,sizeof(sbbs->cfg.event[i]->last)); close(file); if(now-sbbs->cfg.event[i]->last<(60*60)) /* event is done */ break; @@ -2489,10 +2769,15 @@ void event_thread(void* arg) ex_mode |= EX_SH; ex_mode|=(sbbs->cfg.event[i]->misc&EX_NATIVE); sbbs->online=ON_LOCAL; - sbbs->external( - sbbs->cmdstr(sbbs->cfg.event[i]->cmd,nulstr,sbbs->cfg.event[i]->dir,NULL) - ,ex_mode - ,sbbs->cfg.event[i]->dir); + { + int result= + sbbs->external( + sbbs->cmdstr(sbbs->cfg.event[i]->cmd,nulstr,sbbs->cfg.event[i]->dir,NULL) + ,ex_mode + ,sbbs->cfg.event[i]->dir); + if(!(ex_mode&EX_BG)) + eprintf(LOG_INFO,"Timed event: %s returned %d",strupr(str), result); + } sbbs->cfg.event[i]->last=time(NULL); SAFEPRINTF(str,"%stime.dab",sbbs->cfg.ctrl_dir); if((file=sbbs->nopen(str,O_WRONLY))==-1) { @@ -2500,7 +2785,7 @@ void event_thread(void* arg) break; } lseek(file,(long)i*4L,SEEK_SET); - write(file,&sbbs->cfg.event[i]->last,sizeof(time_t)); + write(file,&sbbs->cfg.event[i]->last,sizeof(sbbs->cfg.event[i]->last)); close(file); if(sbbs->cfg.event[i]->misc&EVENT_EXCL) { /* exclusive event */ @@ -2519,15 +2804,17 @@ void event_thread(void* arg) mswait(1000); } sbbs->cfg.node_num=0; + sbbs->js_cleanup(sbbs->client_name); + sbbs->event_thread_running = false; thread_down(); - eprintf(LOG_DEBUG,"BBS Event thread terminated (%u threads remain)", thread_count); + eprintf(LOG_INFO,"BBS Events thread terminated"); } //**************************************************************************** -sbbs_t::sbbs_t(ushort node_num, DWORD addr, char* name, SOCKET sd, +sbbs_t::sbbs_t(ushort node_num, SOCKADDR_IN addr, const char* name, SOCKET sd, scfg_t* global_cfg, char* global_text[], client_t* client_info) { char nodestr[32]; @@ -2537,7 +2824,7 @@ sbbs_t::sbbs_t(ushort node_num, DWORD ad if(node_num) SAFEPRINTF(nodestr,"Node %d",node_num); else - strcpy(nodestr,name); + SAFECOPY(nodestr,name); lprintf(LOG_DEBUG,"%s constructor using socket %d (settings=%lx)" ,nodestr, sd, global_cfg->node_misc); @@ -2584,6 +2871,7 @@ sbbs_t::sbbs_t(ushort node_num, DWORD ad client_socket_dup=INVALID_SOCKET; client_ident[0]=0; + telnet_location[0]=0; terminal[0]=0; rlogin_name[0]=0; rlogin_pass[0]=0; @@ -2606,14 +2894,14 @@ sbbs_t::sbbs_t(ushort node_num, DWORD ad event_time = 0; event_code = nulstr; nodesync_inside = false; - errorlog_inside = false; errormsg_inside = false; gettimeleft_inside = false; timeleft = 60*10; /* just incase this is being used for calling gettimeleft() */ uselect_total = 0; lbuflen = 0; keybufbot=keybuftop=0; /* initialize [unget]keybuf pointers */ - connection="Telnet"; + SAFECOPY(connection,"Telnet"); + node_connection=NODE_CONNECTION_TELNET; ZERO_VAR(telnet_local_option); ZERO_VAR(telnet_remote_option); @@ -2621,8 +2909,10 @@ sbbs_t::sbbs_t(ushort node_num, DWORD ad telnet_cmdlen=0; telnet_mode=0; telnet_last_rxch=0; + telnet_ack_event=CreateEvent(NULL, /* Manual Reset: */FALSE,/* InitialState */FALSE,NULL); sys_status=lncntr=tos=criterrs=slcnt=0L; + column=0; curatr=LIGHTGRAY; attr_sp=0; /* attribute stack pointer */ errorlevel=0; @@ -2702,10 +2992,9 @@ bool sbbs_t::init() socklen_t addr_len; SOCKADDR_IN addr; - if(cfg.node_num>0) { - RingBufInit(&inbuf, IO_THREAD_BUF_SIZE); + RingBufInit(&inbuf, IO_THREAD_BUF_SIZE); + if(cfg.node_num>0) node_inbuf[cfg.node_num-1]=&inbuf; - } RingBufInit(&outbuf, IO_THREAD_BUF_SIZE); outbuf.highwater_mark=startup->outbuf_highwater_mark; @@ -2733,7 +3022,7 @@ bool sbbs_t::init() ,cfg.node_num, result, ERROR_VALUE); return(false); } - lprintf(LOG_INFO,"Node %d attached to local interface %s port %d" + lprintf(LOG_INFO,"Node %d attached to local interface %s port %u" ,cfg.node_num, inet_ntoa(addr.sin_addr), ntohs(addr.sin_port)); local_addr=addr.sin_addr.s_addr; @@ -2796,7 +3085,7 @@ bool sbbs_t::init() ,hhmmtostr(&cfg,&tm,tmp) ,wday[tm.tm_wday] ,mon[tm.tm_mon],tm.tm_mday,tm.tm_year+1900); - logline("L!",str); + logline(LOG_NOTICE,"L!",str); log(crlf); catsyslog(1); } @@ -3003,11 +3292,14 @@ sbbs_t::~sbbs_t() if(cfg.node_num>0) node_inbuf[cfg.node_num-1]=NULL; - if(cfg.node_num>0 && !input_thread_running) + if(!input_thread_running) RingBufDispose(&inbuf); if(!output_thread_running) RingBufDispose(&outbuf); + if(telnet_ack_event!=NULL) + CloseEvent(telnet_ack_event); + /* Close all open files */ if(nodefile!=-1) { close(nodefile); @@ -3026,20 +3318,7 @@ sbbs_t::~sbbs_t() /* Free allocated class members */ /********************************/ -#ifdef JAVASCRIPT - /* Free Context */ - if(js_cx!=NULL) { - lprintf(LOG_DEBUG,"%s JavaScript: Destroying context",node); - JS_DestroyContext(js_cx); - js_cx=NULL; - } - - if(js_runtime!=NULL) { - lprintf(LOG_DEBUG,"%s JavaScript: Destroying runtime",node); - JS_DestroyRuntime(js_runtime); - js_runtime=NULL; - } -#endif + js_cleanup(node); /* Reset text.dat */ @@ -3138,34 +3417,32 @@ int sbbs_t::nopen(char *str, int access) else share=SH_DENYRW; if(!(access&O_TEXT)) access|=O_BINARY; - while(((file=sopen(str,access,share,S_IREAD|S_IWRITE))==-1) + while(((file=sopen(str,access,share,DEFFILEMODE))==-1) && (errno==EACCES || errno==EAGAIN) && count++(LOOP_NOPEN/2) && count<=LOOP_NOPEN) { SAFEPRINTF2(logstr,"NOPEN COLLISION - File: \"%s\" Count: %d" ,str,count); - logline("!!",logstr); + logline(LOG_WARNING,"!!",logstr); } if(file==-1 && (errno==EACCES || errno==EAGAIN)) { SAFEPRINTF2(logstr,"NOPEN ACCESS DENIED - File: \"%s\" errno: %d" ,str,errno); - logline("!!",logstr); + logline(LOG_WARNING,"!!",logstr); bputs("\7\r\nNOPEN: ACCESS DENIED\r\n\7"); } return(file); } -void sbbs_t::spymsg(char* msg) +void sbbs_t::spymsg(const char* msg) { char str[512]; - struct in_addr addr; if(cfg.node_num<1) return; - addr.s_addr=client_addr; SAFEPRINTF4(str,"\r\n\r\n*** Spy Message ***\r\nNode %d: %s [%s]\r\n*** %s ***\r\n\r\n" - ,cfg.node_num,client_name,inet_ntoa(addr),msg); + ,cfg.node_num,client_name,inet_ntoa(client_addr.sin_addr),msg); if(startup->node_spybuf!=NULL && startup->node_spybuf[cfg.node_num-1]!=NULL) { RingBufWrite(startup->node_spybuf[cfg.node_num-1],(uchar*)str,strlen(str)); @@ -3246,7 +3523,7 @@ int sbbs_t::mv(char *src, char *dest, ch } setvbuf(outp,NULL,_IOFBF,8*1024); ftime=filetime(ind); - length=filelength(ind); + length=(long)filelength(ind); if(length) { /* Something to copy */ if((buf=(char *)malloc(MV_BUFLEN))==NULL) { fclose(inp); @@ -3292,6 +3569,10 @@ int sbbs_t::mv(char *src, char *dest, ch void sbbs_t::hangup(void) { + if(online) { + lprintf(LOG_DEBUG,"Node %d disconnecting client", cfg.node_num); + online=FALSE; // moved from the bottom of this function on Jan-25-2009 + } if(client_socket_dup!=INVALID_SOCKET && client_socket_dup!=client_socket) closesocket(client_socket_dup); client_socket_dup=INVALID_SOCKET; @@ -3303,7 +3584,6 @@ void sbbs_t::hangup(void) client_socket=INVALID_SOCKET; } sem_post(&outbuf.sem); - online=FALSE; } int sbbs_t::incom(unsigned long timeout) @@ -3334,14 +3614,16 @@ int sbbs_t::outcom(uchar ch) return(0); } -void sbbs_t::putcom(char *str, int len) +int sbbs_t::putcom(const char *str, size_t len) { - int i; + size_t i; - if(!len) - len=strlen(str); - for(i=0;ilogin_attempt_throttle + && (login_attempts=loginAttempts(startup->login_attempt_list, &sbbs->client_addr)) > 1) { + lprintf(LOG_DEBUG,"Node %d Throttling suspicious connection from: %s (%u login attempts)" + ,sbbs->cfg.node_num, inet_ntoa(sbbs->client_addr.sin_addr), login_attempts); + mswait(login_attempts*startup->login_attempt_throttle); + } + if(sbbs->answer()) { if(sbbs->qwklogon) { @@ -3630,7 +3921,7 @@ void node_thread(void* arg) sbbs->freevars(&sbbs->main_csi); sbbs->clearvars(&sbbs->main_csi); - sbbs->main_csi.length=filelength(file); + sbbs->main_csi.length=(long)filelength(file); if((sbbs->main_csi.cs=(uchar *)malloc(sbbs->main_csi.length))==NULL) { close(file); sbbs->errormsg(WHERE,ERR_ALLOC,str,sbbs->main_csi.length); @@ -3699,7 +3990,7 @@ void node_thread(void* arg) || sbbs->passthru_input_thread_running || sbbs->passthru_output_thread_running #endif ) { - lprintf(LOG_INFO,"Node %d Waiting for %s to terminate..." + lprintf(LOG_DEBUG,"Node %d Waiting for %s to terminate..." ,sbbs->cfg.node_num ,(sbbs->input_thread_running && sbbs->output_thread_running) ? "I/O threads" : sbbs->input_thread_running @@ -3738,10 +4029,11 @@ void node_thread(void* arg) /* node.useron=0; needed for hang-ups while in multinode chat */ sbbs->putnodedat(sbbs->cfg.node_num,&node); - if(node_threads_running>0) - node_threads_running--; - lprintf(LOG_DEBUG,"Node %d thread terminated (%u node threads remain, %lu clients served)" - ,sbbs->cfg.node_num, node_threads_running, served); + { + int32_t remain = protected_uint32_adjust(&node_threads_running, -1); + lprintf(LOG_INFO,"Node %d thread terminated (%u node threads remain, %lu clients served)" + ,sbbs->cfg.node_num, remain, served); + } if(!sbbs->input_thread_running && !sbbs->output_thread_running) delete sbbs; else @@ -3793,7 +4085,7 @@ void sbbs_t::daily_maint(void) backup(str,sbbs->cfg.mail_backup_level,FALSE); } - lputs(LOG_INFO,"Checking for inactive/expired user records..."); + lputs(LOG_INFO,status("Checking for inactive/expired user records...")); lastusernum=lastuser(&sbbs->cfg); for(usernum=1;usernum<=lastusernum;usernum++) { @@ -3880,13 +4172,13 @@ void sbbs_t::daily_maint(void) > sbbs->cfg.sys_autodel)) { /* Inactive too long */ SAFEPRINTF2(str,"Auto-Deleted %s #%u",user.alias,user.number); sbbs->logentry("!*",str); - sbbs->delallmail(user.number); + sbbs->delallmail(user.number, MAIL_ANY); putusername(&sbbs->cfg,user.number,nulstr); putuserrec(&sbbs->cfg,user.number,U_MISC,8,ultoa(user.misc|DELETED,str,16)); } } - lputs(LOG_INFO,"Purging deleted/expired e-mail"); + lputs(LOG_INFO,status("Purging deleted/expired e-mail")); SAFEPRINTF(sbbs->smb.file,"%smail",sbbs->cfg.data_dir); sbbs->smb.retry_time=sbbs->cfg.smb_retry_time; sbbs->smb.subnum=INVALID_SUB; @@ -3909,16 +4201,7 @@ void sbbs_t::daily_maint(void) sbbs->external(sbbs->cmdstr(sbbs->cfg.sys_daily,nulstr,nulstr,NULL) ,EX_OFFLINE); } -} - -time_t checktime(void) -{ - struct tm tm; - - memset(&tm,0,sizeof(tm)); - tm.tm_year=94; - tm.tm_mday=1; - return(mktime(&tm)-0x2D24BD00L); + status(STATUS_WFC); } const char* DLLCALL js_ver(void) @@ -3962,13 +4245,13 @@ long DLLCALL bbs_ver_num(void) void DLLCALL bbs_terminate(void) { - lprintf(LOG_DEBUG,"BBS Server terminate"); + lprintf(LOG_INFO,"BBS Server terminate"); terminate_server=true; } static void cleanup(int code) { - lputs(LOG_INFO,"BBS System thread terminating"); + lputs(LOG_INFO,"Terminal Server thread terminating"); if(telnet_socket!=INVALID_SOCKET) { close_socket(telnet_socket); @@ -3997,6 +4280,8 @@ static void cleanup(int code) semfile_list_free(&recycle_semfiles); semfile_list_free(&shutdown_semfiles); + protected_uint32_destroy(node_threads_running); + #ifdef _WIN32 if(exec_mutex!=NULL) { CloseHandle(exec_mutex); @@ -4021,15 +4306,14 @@ static void cleanup(int code) status("Down"); thread_down(); if(terminate_server || code) - lprintf(LOG_INFO,"BBS System thread terminated (%u threads remain, %lu clients served)" - ,thread_count, served); + lprintf(LOG_INFO,"Terminal Server thread terminated (%lu clients served)", served); if(startup->terminated!=NULL) startup->terminated(startup->cbdata,code); } void DLLCALL bbs_thread(void* arg) { - char* host_name; + const char* host_name; char* identity; char* p; char str[MAX_PATH+1]; @@ -4092,18 +4376,23 @@ void DLLCALL bbs_thread(void* arg) ZERO_VAR(js_server_props); SAFEPRINTF3(js_server_props.version,"%s %s%c",TELNET_SERVER,VERSION,REVISION); js_server_props.version_detail=bbs_ver(); - js_server_props.clients=&node_threads_running; + js_server_props.clients=&node_threads_running.value; js_server_props.options=&startup->options; js_server_props.interface_addr=&startup->telnet_interface; uptime=0; served=0; + startup->recycle_now=FALSE; startup->shutdown_now=FALSE; terminate_server=false; + SetThreadName("BBS"); + do { + protected_uint32_init(&node_threads_running,0); + thread_up(FALSE /* setuid */); status("Initializing"); @@ -4111,7 +4400,7 @@ void DLLCALL bbs_thread(void* arg) /* Defeat the lameo hex0rs - the name and copyright must remain intact */ if(crc32(COPYRIGHT_NOTICE,0)!=COPYRIGHT_CRC || crc32(VERSION_NOTICE,10)!=SYNCHRONET_CRC) { - lprintf(LOG_ERR,"!CORRUPTED LIBRARY FILE"); + lprintf(LOG_CRIT,"!CORRUPTED LIBRARY FILE"); cleanup(1); return; } @@ -4119,7 +4408,6 @@ void DLLCALL bbs_thread(void* arg) memset(text, 0, sizeof(text)); memset(&scfg, 0, sizeof(scfg)); - node_threads_running=0; lastuseron[0]=0; char compiler[32]; @@ -4136,10 +4424,10 @@ void DLLCALL bbs_thread(void* arg) #endif ); lprintf(LOG_INFO,"Compiled %s %s with %s", __DATE__, __TIME__, compiler); - lprintf(LOG_INFO,"SMBLIB %s (format %x.%02x)",smb_lib_ver(),smb_ver()>>8,smb_ver()&0xff); + lprintf(LOG_DEBUG,"SMBLIB %s (format %x.%02x)",smb_lib_ver(),smb_ver()>>8,smb_ver()&0xff); if(startup->first_node<1 || startup->first_node>startup->last_node) { - lprintf(LOG_ERR,"!ILLEGAL node configuration (first: %d, last: %d)" + lprintf(LOG_CRIT,"!ILLEGAL node configuration (first: %d, last: %d)" ,startup->first_node, startup->last_node); cleanup(1); return; @@ -4150,7 +4438,7 @@ void DLLCALL bbs_thread(void* arg) #pragma warn -8066 /* Disable "Unreachable code" warning */ #endif if(sizeof(node_t)!=SIZEOF_NODE_T) { - lprintf(LOG_ERR,"!COMPILER ERROR: sizeof(node_t)=%d instead of %d" + lprintf(LOG_CRIT,"!COMPILER ERROR: sizeof(node_t)=%d instead of %d" ,sizeof(node_t),SIZEOF_NODE_T); cleanup(1); return; @@ -4158,7 +4446,7 @@ void DLLCALL bbs_thread(void* arg) #ifdef _WIN32 if((exec_mutex=CreateMutex(NULL,false,NULL))==NULL) { - lprintf(LOG_ERR,"!ERROR %d creating exec_mutex", GetLastError()); + lprintf(LOG_CRIT,"!ERROR %d creating exec_mutex", GetLastError()); cleanup(1); return; } @@ -4172,7 +4460,7 @@ void DLLCALL bbs_thread(void* arg) t=time(NULL); lprintf(LOG_INFO,"Initializing on %.24s with options: %lx" - ,CTIME_R(&t,str),startup->options); + ,ctime_r(&t,str),startup->options); if(chdir(startup->ctrl_dir)!=0) lprintf(LOG_ERR,"!ERROR %d changing directory to: %s", errno, startup->ctrl_dir); @@ -4184,8 +4472,8 @@ void DLLCALL bbs_thread(void* arg) scfg.node_num=startup->first_node; SAFECOPY(logstr,UNKNOWN_LOAD_ERROR); if(!load_cfg(&scfg, text, TRUE, logstr)) { - lprintf(LOG_ERR,"!ERROR %s",logstr); - lprintf(LOG_ERR,"!FAILED to load configuration files"); + lprintf(LOG_CRIT,"!ERROR %s",logstr); + lprintf(LOG_CRIT,"!FAILED to load configuration files"); cleanup(1); return; } @@ -4193,16 +4481,8 @@ void DLLCALL bbs_thread(void* arg) if(startup->host_name[0]==0) SAFECOPY(startup->host_name,scfg.sys_inetaddr); - if(!(scfg.sys_misc&SM_LOCAL_TZ) && !(startup->options&BBS_OPT_LOCAL_TIMEZONE)) { - if(putenv("TZ=UTC0")) - lprintf(LOG_ERR,"!putenv() FAILED"); - tzset(); - - if((t=checktime())!=0) { /* Check binary time */ - lprintf(LOG_ERR,"!TIME PROBLEM (%ld)",t); - cleanup(1); - return; - } + if((t=checktime())!=0) { /* Check binary time */ + lprintf(LOG_ERR,"!TIME PROBLEM (%ld)",t); } if(uptime==0) @@ -4225,8 +4505,8 @@ void DLLCALL bbs_thread(void* arg) md(scfg.node_path[i-1]); SAFEPRINTF(str,"%sdsts.dab",i ? scfg.node_path[i-1] : scfg.ctrl_dir); if(flength(str)telnet_port); - if(startup->seteuid!=NULL) - startup->seteuid(FALSE); + if(startup->telnet_port < IPPORT_RESERVED) { + if(startup->seteuid!=NULL) + startup->seteuid(FALSE); + } result = retry_bind(telnet_socket,(struct sockaddr *)&server_addr,sizeof(server_addr) ,startup->bind_retry_count,startup->bind_retry_delay,"Telnet Server",lprintf); - if(startup->seteuid!=NULL) - startup->seteuid(TRUE); + if(startup->telnet_port < IPPORT_RESERVED) { + if(startup->seteuid!=NULL) + startup->seteuid(TRUE); + } if(result != 0) { - lprintf(LOG_NOTICE,"%s",BIND_FAILURE_HELP); + lprintf(LOG_CRIT,"%s",BIND_FAILURE_HELP); cleanup(1); return; } @@ -4286,11 +4570,11 @@ void DLLCALL bbs_thread(void* arg) result = listen(telnet_socket, 1); if(result != 0) { - lprintf(LOG_ERR,"!ERROR %d (%d) listening on Telnet socket", result, ERROR_VALUE); + lprintf(LOG_CRIT,"!ERROR %d (%d) listening on Telnet socket", result, ERROR_VALUE); cleanup(1); return; } - lprintf(LOG_INFO,"Telnet server listening on port %d",startup->telnet_port); + lprintf(LOG_INFO,"Telnet Server listening on port %u",startup->telnet_port); if(startup->options&BBS_OPT_ALLOW_RLOGIN) { @@ -4299,12 +4583,12 @@ void DLLCALL bbs_thread(void* arg) rlogin_socket = open_socket(SOCK_STREAM, "rlogin"); if(rlogin_socket == INVALID_SOCKET) { - lprintf(LOG_ERR,"!ERROR %d creating RLogin socket", ERROR_VALUE); + lprintf(LOG_CRIT,"!ERROR %d creating RLogin socket", ERROR_VALUE); cleanup(1); return; } - lprintf(LOG_INFO,"RLogin socket %d opened",rlogin_socket); + lprintf(LOG_DEBUG,"RLogin socket %d opened",rlogin_socket); /*****************************/ /* Listen for incoming calls */ @@ -4315,14 +4599,18 @@ void DLLCALL bbs_thread(void* arg) server_addr.sin_family = AF_INET; server_addr.sin_port = htons(startup->rlogin_port); - if(startup->seteuid!=NULL) - startup->seteuid(FALSE); + if(startup->rlogin_port < IPPORT_RESERVED) { + if(startup->seteuid!=NULL) + startup->seteuid(FALSE); + } result = retry_bind(rlogin_socket,(struct sockaddr *)&server_addr,sizeof(server_addr) ,startup->bind_retry_count,startup->bind_retry_delay,"RLogin Server",lprintf); - if(startup->seteuid!=NULL) - startup->seteuid(TRUE); + if(startup->rlogin_port < IPPORT_RESERVED) { + if(startup->seteuid!=NULL) + startup->seteuid(TRUE); + } if(result != 0) { - lprintf(LOG_NOTICE,"%s",BIND_FAILURE_HELP); + lprintf(LOG_CRIT,"%s",BIND_FAILURE_HELP); cleanup(1); return; } @@ -4330,11 +4618,11 @@ void DLLCALL bbs_thread(void* arg) result = listen(rlogin_socket, 1); if(result != 0) { - lprintf(LOG_ERR,"!ERROR %d (%d) listening on RLogin socket", result, ERROR_VALUE); + lprintf(LOG_CRIT,"!ERROR %d (%d) listening on RLogin socket", result, ERROR_VALUE); cleanup(1); return; } - lprintf(LOG_INFO,"RLogin server listening on port %d",startup->rlogin_port); + lprintf(LOG_INFO,"RLogin Server listening on port %u",startup->rlogin_port); } #ifdef USE_CRYPTLIB @@ -4363,15 +4651,15 @@ void DLLCALL bbs_thread(void* arg) /* Couldn't do that... create a new context and use the key from there... */ if(!cryptStatusOK(i=cryptCreateContext(&ssh_context, CRYPT_UNUSED, CRYPT_ALGO_RSA))) { - lprintf(LOG_ERR,"Cryptlib error %d creating context",i); + lprintf(LOG_ERR,"SSH Cryptlib error %d creating context",i); goto NO_SSH; } if(!cryptStatusOK(i=cryptSetAttributeString(ssh_context, CRYPT_CTXINFO_LABEL, "ssh_server", 10))) { - lprintf(LOG_ERR,"Cryptlib error %d setting key label",i); + lprintf(LOG_ERR,"SSH Cryptlib error %d setting key label",i); goto NO_SSH; } if(!cryptStatusOK(i=cryptGenerateKey(ssh_context))) { - lprintf(LOG_ERR,"Cryptlib error %d generating key",i); + lprintf(LOG_ERR,"SSH Cryptlib error %d generating key",i); goto NO_SSH; } @@ -4387,12 +4675,12 @@ void DLLCALL bbs_thread(void* arg) ssh_socket = open_socket(SOCK_STREAM, "ssh"); if(ssh_socket == INVALID_SOCKET) { - lprintf(LOG_ERR,"!ERROR %d creating SSH socket", ERROR_VALUE); + lprintf(LOG_CRIT,"!ERROR %d creating SSH socket", ERROR_VALUE); cleanup(1); return; } - lprintf(LOG_INFO,"SSH socket %d opened",ssh_socket); + lprintf(LOG_DEBUG,"SSH socket %d opened",ssh_socket); /*****************************/ /* Listen for incoming calls */ @@ -4403,14 +4691,18 @@ void DLLCALL bbs_thread(void* arg) server_addr.sin_family = AF_INET; server_addr.sin_port = htons(startup->ssh_port); - if(startup->seteuid!=NULL) - startup->seteuid(FALSE); + if(startup->ssh_port < IPPORT_RESERVED) { + if(startup->seteuid!=NULL) + startup->seteuid(FALSE); + } result = retry_bind(ssh_socket,(struct sockaddr *)&server_addr,sizeof(server_addr) ,startup->bind_retry_count,startup->bind_retry_delay,"SSH Server",lprintf); - if(startup->seteuid!=NULL) - startup->seteuid(TRUE); + if(startup->ssh_port < IPPORT_RESERVED) { + if(startup->seteuid!=NULL) + startup->seteuid(TRUE); + } if(result != 0) { - lprintf(LOG_NOTICE,"%s",BIND_FAILURE_HELP); + lprintf(LOG_CRIT,"%s",BIND_FAILURE_HELP); cleanup(1); return; } @@ -4418,31 +4710,31 @@ void DLLCALL bbs_thread(void* arg) result = listen(ssh_socket, 1); if(result != 0) { - lprintf(LOG_ERR,"!ERROR %d (%d) listening on SSH socket", result, ERROR_VALUE); + lprintf(LOG_CRIT,"!ERROR %d (%d) listening on SSH socket", result, ERROR_VALUE); cleanup(1); return; } - lprintf(LOG_INFO,"SSH server listening on port %d",startup->ssh_port); + lprintf(LOG_INFO,"SSH Server listening on port %u",startup->ssh_port); } NO_SSH: #endif - sbbs = new sbbs_t(0, server_addr.sin_addr.s_addr - ,"BBS System", telnet_socket, &scfg, text, NULL); + sbbs = new sbbs_t(0, server_addr + ,"Terminal Server", telnet_socket, &scfg, text, NULL); sbbs->online = 0; if(sbbs->init()==false) { - lputs(LOG_ERR,"!BBS initialization failed"); + lputs(LOG_CRIT,"!BBS initialization failed"); cleanup(1); return; } _beginthread(output_thread, 0, sbbs); if(!(startup->options&BBS_OPT_NO_EVENTS)) { - events = new sbbs_t(0, server_addr.sin_addr.s_addr + events = new sbbs_t(0, server_addr ,"BBS Events", INVALID_SOCKET, &scfg, text, NULL); events->online = 0; if(events->init()==false) { - lputs(LOG_ERR,"!Events initialization failed"); + lputs(LOG_CRIT,"!Events initialization failed"); cleanup(1); return; } @@ -4456,12 +4748,11 @@ NO_SSH: for(i=first_node;i<=last_node;i++) { sbbs->getnodedat(i,&node,1); node.status=NODE_WFC; - node.misc&=NODE_EVENT; + node.misc&=NODE_EVENT; /* Note: Turns-off NODE_RRUN flag (and others) */ node.action=0; sbbs->putnodedat(i,&node); } - lprintf(LOG_INFO,"BBS System thread started for nodes %d through %d", first_node, last_node); status(STATUS_WFC); #if defined(_WIN32) && defined(_DEBUG) && defined(_MSC_VER) @@ -4476,7 +4767,7 @@ NO_SSH: FILE_ATTRIBUTE_NORMAL, // file attributes NULL // handle to file with attributes to ))==INVALID_HANDLE_VALUE) { - lprintf(LOG_ERR,"!ERROR %ld creating %s",GetLastError(),str); + lprintf(LOG_CRIT,"!ERROR %ld creating %s",GetLastError(),str); cleanup(1); return; } @@ -4501,10 +4792,11 @@ NO_SSH: recycle_semfiles=semfile_list_init(scfg.ctrl_dir,"recycle","telnet"); SAFEPRINTF(str,"%stelnet.rec",scfg.ctrl_dir); /* legacy */ semfile_list_add(&recycle_semfiles,str); - if(!initialized) { - semfile_list_check(&initialized,recycle_semfiles); + SAFEPRINTF(str,"%stext.dat",scfg.ctrl_dir); + semfile_list_add(&recycle_semfiles,str); + if(!initialized) semfile_list_check(&initialized,shutdown_semfiles); - } + semfile_list_check(&initialized,recycle_semfiles); #ifdef __unix__ // unix-domain spy sockets for(i=first_node;i<=last_node && !(startup->options&BBS_OPT_NO_SPY_SOCKETS);i++) { @@ -4554,35 +4846,34 @@ NO_SSH: if(startup->started!=NULL) startup->started(startup->cbdata); + lprintf(LOG_INFO,"Terminal Server thread started for nodes %d through %d", first_node, last_node); while(!terminate_server) { - if(node_threads_running==0) { /* check for re-run flags */ - bool rerun=false; - for(i=first_node;i<=last_node;i++) { - if(sbbs->getnodedat(i,&node,0)!=0) - continue; - if(node.misc&NODE_RRUN) { - sbbs->getnodedat(i,&node,1); - if(!rerun) - lprintf(LOG_INFO,"Node %d flagged for re-run",i); - rerun=true; - node.misc&=~NODE_RRUN; - sbbs->putnodedat(i,&node); - } - } - if(rerun) - break; + if(node_threads_running.value==0) { /* check for re-run flags and recycle/shutdown sem files */ if(!(startup->options&BBS_OPT_NO_RECYCLE)) { + + bool rerun=false; + for(i=first_node;i<=last_node;i++) { + if(sbbs->getnodedat(i,&node,0)!=0) + continue; + if(node.misc&NODE_RRUN) { + sbbs->getnodedat(i,&node,1); + if(!rerun) + lprintf(LOG_INFO,"Node %d flagged for re-run",i); + rerun=true; + node.misc&=~NODE_RRUN; + sbbs->putnodedat(i,&node); + } + } + if(rerun) + break; + if((p=semfile_list_check(&initialized,recycle_semfiles))!=NULL) { lprintf(LOG_INFO,"%04d Recycle semaphore file (%s) detected" ,telnet_socket,p); break; } -#if 0 /* unused */ - if(startup->recycle_sem!=NULL && sem_trywait(&startup->recycle_sem)==0) - startup->recycle_now=TRUE; -#endif if(startup->recycle_now==TRUE) { lprintf(LOG_INFO,"%04d Recycle semaphore signaled",telnet_socket); startup->recycle_now=FALSE; @@ -4602,6 +4893,7 @@ NO_SSH: } sbbs->online=FALSE; +// sbbs->client_socket=INVALID_SOCKET; #ifdef USE_CRYPTLIB sbbs->ssh_mode=false; #endif @@ -4651,9 +4943,9 @@ NO_SSH: if(i==0) continue; if(ERROR_VALUE==EINTR) - lprintf(LOG_DEBUG,"Telnet Server listening interrupted"); + lprintf(LOG_DEBUG,"Terminal Server listening interrupted"); else if(ERROR_VALUE == ENOTSOCK) - lprintf(LOG_NOTICE,"Telnet Server sockets closed"); + lprintf(LOG_NOTICE,"Terminal Server sockets closed"); else lprintf(LOG_WARNING,"!ERROR %d selecting sockets",ERROR_VALUE); continue; @@ -4781,32 +5073,63 @@ NO_SSH: /* Do SSH stuff here */ if(ssh) { + int ssh_failed=0; if(!cryptStatusOK(i=cryptCreateSession(&sbbs->ssh_session, CRYPT_UNUSED, CRYPT_SESSION_SSH_SERVER))) { - lprintf(LOG_ERR,"%04d Cryptlib error %d creating session", client_socket, i); + lprintf(LOG_WARNING,"%04d SSH Cryptlib error %d creating session", client_socket, i); close_socket(client_socket); continue; } if(!cryptStatusOK(i=cryptSetAttribute(sbbs->ssh_session, CRYPT_SESSINFO_PRIVATEKEY, ssh_context))) { - lprintf(LOG_ERR,"%04d Cryptlib error %d setting private key",client_socket, i); - cryptDestroySession(sbbs->ssh_session); - close_socket(client_socket); - continue; - } - /* Accept any credentials */ - if(!cryptStatusOK(i=cryptSetAttribute(sbbs->ssh_session, CRYPT_SESSINFO_AUTHRESPONSE, 1))) { - lprintf(LOG_ERR,"%04d Cryptlib error %d setting AUTHRESPONSE",client_socket, i); + lprintf(LOG_WARNING,"%04d SSH Cryptlib error %d setting private key",client_socket, i); cryptDestroySession(sbbs->ssh_session); close_socket(client_socket); continue; } if(!cryptStatusOK(i=cryptSetAttribute(sbbs->ssh_session, CRYPT_SESSINFO_NETWORKSOCKET, client_socket))) { - lprintf(LOG_ERR,"%04d Cryptlib error %d setting socket",client_socket, i); + lprintf(LOG_WARNING,"%04d SSH Cryptlib error %d setting socket",client_socket, i); cryptDestroySession(sbbs->ssh_session); close_socket(client_socket); continue; } - if(!cryptStatusOK(i=cryptSetAttribute(sbbs->ssh_session, CRYPT_SESSINFO_ACTIVE, 1))) { - lprintf(LOG_ERR,"%04d Cryptlib error %d setting session active",client_socket, i); + for(ssh_failed=0; ssh_failed < 2; ssh_failed++) { + /* Accept any credentials */ + if(!cryptStatusOK(i=cryptSetAttribute(sbbs->ssh_session, CRYPT_SESSINFO_AUTHRESPONSE, 1))) { + ssh_failed=1; + break; + } + if(!cryptStatusOK(i=cryptSetAttribute(sbbs->ssh_session, CRYPT_SESSINFO_ACTIVE, 1))) { + if(i != CRYPT_ENVELOPE_RESOURCE) { + ssh_failed=2; + break; + } + } + else { + ssh_failed=0; + break; + } + } + switch(ssh_failed) { + case 1: + lprintf(LOG_WARNING,"%04d SSH Cryptlib error %d setting AUTHRESPONSE",client_socket, i); + break; + case 2: + switch(i) { + case CRYPT_ERROR_BADDATA: + lprintf(LOG_NOTICE,"%04d SSH Bad/unrecognized data format", client_socket); + break; + case CRYPT_ERROR_READ: + lprintf(LOG_WARNING,"%04d SSH Read failure", client_socket); + break; + case CRYPT_ERROR_WRITE: + lprintf(LOG_WARNING,"%04d SSH Write failure", client_socket); + break; + default: + lprintf(LOG_WARNING,"%04d SSH Cryptlib error %d setting session active",client_socket, i); + break; + } + break; + } + if(ssh_failed) { cryptDestroySession(sbbs->ssh_session); close_socket(client_socket); continue; @@ -4820,8 +5143,8 @@ NO_SSH: if(sbbs->trashcan(host_ip,"ip")) { SSH_END(); close_socket(client_socket); - lprintf(LOG_NOTICE,"%04d !CLIENT BLOCKED in ip.can" - ,client_socket); + lprintf(LOG_NOTICE,"%04d !CLIENT BLOCKED in ip.can: %s" + ,client_socket, host_ip); SAFEPRINTF(logstr, "Blocked IP: %s",host_ip); sbbs->syslog("@!",logstr); continue; @@ -4850,16 +5173,14 @@ NO_SSH: else host_name=""; - if(!(startup->options&BBS_OPT_NO_HOST_LOOKUP)) { + if(!(startup->options&BBS_OPT_NO_HOST_LOOKUP)) lprintf(LOG_INFO,"%04d Hostname: %s", client_socket, host_name); - for(i=0;h!=NULL && h->h_aliases!=NULL && h->h_aliases[i]!=NULL;i++) - lprintf(LOG_INFO,"%04d HostAlias: %s", client_socket, h->h_aliases[i]); - } if(sbbs->trashcan(host_name,"host")) { SSH_END(); close_socket(client_socket); - lprintf(LOG_NOTICE,"%04d !CLIENT BLOCKED in host.can",client_socket); + lprintf(LOG_NOTICE,"%04d !CLIENT BLOCKED in host.can: %s" + ,client_socket, host_name); SAFEPRINTF(logstr, "Blocked Hostname: %s",host_name); sbbs->syslog("@!",logstr); continue; @@ -4868,13 +5189,16 @@ NO_SSH: identity=NULL; if(startup->options&BBS_OPT_GET_IDENT) { sbbs->bprintf("Resolving identity..."); - identify(&client_addr, startup->telnet_port, str, sizeof(str)-1,0); - identity=strrchr(str,':'); - if(identity!=NULL) { - identity++; /* skip colon */ - while(*identity && *identity<=' ') /* point to user name */ - identity++; - lprintf(LOG_INFO,"%04d Identity: %s",client_socket, identity); + /* ToDo: Make ident timeout configurable */ + if(identify(&client_addr, startup->telnet_port, str, sizeof(str)-1, /* timeout: */1)) { + lprintf(LOG_DEBUG,"%04d Ident Response: %s",client_socket, str); + identity=strrchr(str,':'); + if(identity!=NULL) { + identity++; /* skip colon */ + SKIP_WHITESPACE(identity); + if(*identity) + lprintf(LOG_INFO,"%04d Identity: %s",client_socket, identity); + } } sbbs->putcom(crlf); } @@ -4899,6 +5223,16 @@ NO_SSH: continue; if(node.status==NODE_WFC) { node.status=NODE_LOGON; +#ifdef USE_CRYPTLIB + if(ssh) + node.connection=NODE_CONNECTION_SSH; + else +#endif + if(rlogin) + node.connection=NODE_CONNECTION_RLOGIN; + else + node.connection=NODE_CONNECTION_TELNET; + sbbs->putnodedat(i,&node); break; } @@ -4923,7 +5257,7 @@ NO_SSH: node_socket[i-1]=client_socket; - sbbs_t* new_node = new sbbs_t(i, client_addr.sin_addr.s_addr, host_name + sbbs_t* new_node = new sbbs_t(i, client_addr, host_name ,client_socket ,&scfg, text, &client); @@ -4940,7 +5274,7 @@ NO_SSH: SAFECOPY(new_node->client_ident,identity); if(new_node->init()==false) { - lprintf(LOG_INFO,"%04d !Node %d Initialization failure" + lprintf(LOG_INFO,"%04d Node %d !Initialization failure" ,client_socket,new_node->cfg.node_num); SAFEPRINTF(str,"%snonodes.txt",scfg.text_dir); if(fexist(str)) @@ -4960,7 +5294,8 @@ NO_SSH: } if(rlogin==true) { - new_node->connection="RLogin"; + SAFECOPY(new_node->connection,"RLogin"); + new_node->node_connection=NODE_CONNECTION_RLOGIN; new_node->sys_status|=SS_RLOGIN; new_node->telnet_mode|=TELNET_MODE_OFF; // RLogin does not use Telnet commands } @@ -4979,14 +5314,14 @@ NO_SSH: goto NO_PASSTHRU; } - lprintf(LOG_INFO,"passthru listen socket %d opened",tmp_sock); + lprintf(LOG_DEBUG,"passthru listen socket %d opened",tmp_sock); /*****************************/ /* Listen for incoming calls */ /*****************************/ memset(&tmp_addr, 0, sizeof(tmp_addr)); - tmp_addr.sin_addr.s_addr = htonl(0x7f000001U); + tmp_addr.sin_addr.s_addr = htonl(IPv4_LOCALHOST); tmp_addr.sin_family = AF_INET; tmp_addr.sin_port = 0; @@ -5004,7 +5339,7 @@ NO_SSH: close_socket(tmp_sock); goto NO_PASSTHRU; } - lprintf(LOG_INFO,"Listening passthru socket listening on port %d",htons(tmp_addr.sin_port)); + lprintf(LOG_INFO,"Listening passthru socket listening on port %u",htons(tmp_addr.sin_port)); new_node->passthru_socket = open_socket(SOCK_STREAM, "passthru"); @@ -5014,7 +5349,7 @@ NO_SSH: goto NO_PASSTHRU; } - lprintf(LOG_INFO,"passthru connect socket %d opened",new_node->passthru_socket); + lprintf(LOG_DEBUG,"passthru connect socket %d opened",new_node->passthru_socket); tmp_addr_len=sizeof(tmp_addr); if(getsockname(tmp_sock, (struct sockaddr *)&tmp_addr, &tmp_addr_len)) { @@ -5050,18 +5385,20 @@ NO_SSH: _beginthread(passthru_input_thread, 0, new_node); NO_PASSTHRU: - new_node->connection="SSH"; + SAFECOPY(new_node->connection,"SSH"); + new_node->node_connection=NODE_CONNECTION_SSH; new_node->sys_status|=SS_SSH; new_node->telnet_mode|=TELNET_MODE_OFF; // SSH does not use Telnet commands new_node->ssh_session=sbbs->ssh_session; /* Wait for pending data to be sent then turn off ssh_mode for uber-output */ while(RingBufFull(&sbbs->outbuf)) SLEEP(1); + cryptPopData(sbbs->ssh_session, str, sizeof(str), &i); sbbs->ssh_mode=false; } #endif - node_threads_running++; + protected_uint32_adjust(&node_threads_running, 1); new_node->input_thread=(HANDLE)_beginthread(input_thread,0, new_node); _beginthread(output_thread, 0, new_node); _beginthread(node_thread, 0, new_node); @@ -5097,13 +5434,13 @@ NO_PASSTHRU: sem_post(&sbbs->outbuf.sem); // Wait for all node threads to terminate - if(node_threads_running) { - lprintf(LOG_INFO,"Waiting for %d node threads to terminate...", node_threads_running); + if(node_threads_running.value) { + lprintf(LOG_INFO,"Waiting for %d node threads to terminate...", node_threads_running.value); start=time(NULL); - while(node_threads_running) { + while(node_threads_running.value) { if(time(NULL)-start>TIMEOUT_THREAD_WAIT) { lprintf(LOG_ERR,"!TIMEOUT waiting for %d node thread(s) to " - "terminate", node_threads_running); + "terminate", node_threads_running.value); break; } mswait(100); @@ -5112,12 +5449,12 @@ NO_PASSTHRU: // Wait for Events thread to terminate if(events!=NULL && events->event_thread_running) { - lprintf(LOG_INFO,"Waiting for event thread to terminate..."); + lprintf(LOG_INFO,"Waiting for events thread to terminate..."); start=time(NULL); while(events->event_thread_running) { -#if 0 /* the event thread can/will segfault if it continues to run and dereference sbbs->cfg */ +#if 0 /* the events thread can/will segfault if it continues to run and dereference sbbs->cfg */ if(time(NULL)-start>TIMEOUT_THREAD_WAIT) { - lprintf(LOG_ERR,"!TIMEOUT waiting for BBS event thread to " + lprintf(LOG_ERR,"!TIMEOUT waiting for BBS events thread to " "terminate"); break; } @@ -5147,10 +5484,16 @@ NO_PASSTHRU: sbbs->putnodedat(i,&node); } - if(events!=NULL && !events->event_thread_running) - delete events; + if(events!=NULL) { + if(events->event_thread_running) + lprintf(LOG_ERR,"!Events thread still running, can't delete"); + else + delete events; + } - if(!sbbs->output_thread_running) + if(sbbs->output_thread_running) + lprintf(LOG_ERR,"!Output thread still running, can't delete"); + else delete sbbs; cleanup(0); @@ -5165,6 +5508,3 @@ NO_PASSTHRU: } while(!terminate_server); } - - -