/*****************************************************************************/ /* Logging.c Logging functions for the WASD VMS HTTPd. By default, produces a Web "common" format log suitable for analysis by tools capable of processing that format. Secretes four pseudo-requests logging the BEGINing, OPENing, CLOSEing and ENDing of logging activities. These shouldn't introduce problems for analysis tools as they look like legitimate POST entries for user "HTTPd"! The [LogFormat] directive generates logs in the "common+server", "combined" and a user-defined format. If a user-defined format contains an error the server will exit the first time a request is logged. Caveat emptor! Log file name must be supplied via [LogFile] or the logical name WASD_CONFIG_LOG (process, job, or system level). An error is reporting if logging is enabled without either of these being supplied. If the log file name specified is "SYS$OUTPUT" log entries are written to SYS$OUTPUT. This is useful for checking user-defined log entries before committing files to that format. The [LogNaming] format can be any of "NAME" (default) which names the log file using the first period-delimited component of the IP host name, "HOST" which uses as much of the IP host name as can be accomodated within the maximum 39 character filename limitation (of ODS-2), or "ADDRESS" which uses the full IP host address in the name. Both HOST and ADDRESS have hyphens substituted for periods in the string. If these are specified then by default the service port follows the host name component. This may be suppressed using the [LogPerServiceHostOnly] directive, allowing a minimum extra 3 characters in the name, and combining entries for all ports associated with the host name. The log file can have a [LogPeriod] associated with it. This period determines when a new log file is created. The periods are hourly, daily, weekly and monthly. An hourly period is indicated by HOURLY, a daily period by DAILY, a weekly period by MONDAY, TUESDAY, WEDNESDAY, THURSDAY, FRIDAY, SATURDAY and SUNDAY (the day of the week on which, at midnight or the first request thereafter, the log is recreated), and finally a monthly recreation by MONTHLY. The WASD_CONFIG_LOG logical is then used merely for the directory component and the file name is fixed at HOST_YYYYMMDD_ACCESS.LOG where host is the first dot-separated component of the primary IP host name and YYYY, MM, DD is the year, month and day the log was created, or if hourly period has been specified HOST_YYYYMMDDHH_ACCESS.LOG where the additional HH represents the hour the log was created. When multiple instances, either on the one node or across a cluster, are writing to the same log file (multi-stream), then RMS insists on automatically flushing each log record write (considering the issues with maintaining 'dirty' buffers, perhaps cluster-wide, this is not unreasonable). This does increase the physical disk I/O significantly though, and of course reduces server performance equally (or more so) as a result. The simple (and effective) solution to this is to have only one stream writing to a log file at the one time. This is enabled using the [LogPerInstance] configuration directive. With this active each log file has the node name and then the instance process name appended to the .LOG file type resulting in names similar to (for a two instance single node) 10-168-0-3_80_20020527_ACCESS.LOG_KLAATU_HTTPD-80 10-168-0-3_80_20020527_ACCESS.LOG_KLAATU_HTTPE-80 10-168-0-3_443_20020527_ACCESS.LOG_KLAATU_HTTPD-80 10-168-0-3_443_20020527_ACCESS.LOG_KLAATU_HTTPE-80 Of course these need to be integrated at some stage, either using one of the many log file analysis tools, or a specific utility such as WASD's CALOG.C (Consolidate Access LOGs, pronounced as with the breakfast cereals). COMMON FORMAT ------------- (NCSA, CERN, etc.) 'client rfc1413 auth-user date/time request status bytes' COMBINED FORMAT --------------- (NCSA) 'client rfc1413 auth-user date/time request status bytes referer user-agent' COMMON FORMAT plus server name ------------- (NCSA, CERN, etc.) 'client rfc1413 auth-user date/time request status bytes server' USER-DEFINED FORMAT ------------------- Must begin with a character that is used as a substitute when a particular field is empty (use "\0" for no substitute, as in the "windows log format" example below). Two different "escape" characters introduce the following parameters of characters. A '!' followed by ... 'AR' : authentication realm - none 'AU' : authenticated user name - Apache %u 'BB' : longword bytes in body (excluding response header) - Apache %b 'BQ' : quadword bytes transmitted to the client - none 'BY' : longword bytes transmitted to the client - none 'CA' : client numeric address - Apache %a 'CC' : X509 client certificate authorization distinguishing name - none 'CI' : SSL cipher name (e.g. "AES128-SHA", "AES128-GCM-SHA256") - none 'CL' : content-length value from request header ('-' if no content-length) 'CN' : client host name (or address if DNS lookup disabled) - Apache %h 'CP' : client port 'DI' : insert value of dictionary entry (should be quoted \q!DI:""\q) 'EM' : request elapsed time in milliseconds - none 'ES' : request elapsed time in fractional seconds 'ET' : request elapsed time in seconds - Apache %T 'EU' : request elapsed time in microseconds - none 'HO' : "Host:" request header 'ID' : session track ID - none 'II' : server image information (file name, version, link date-time) 'ME' : request method - none 'NP' : insert notepad value (should be quoted \q!NP\q if likely to break log) 'PA' : request path (NOTE: not the full request path! See 'R') - none 'PL' : payload - number of body bytes received (i.e. POST or PUT) 'PP' : outgoing proxy connection local port 'PR' : HTTP protocol (e.g. "HTTP/2", "HTTP/1.1") - none 'QS' : request query string - none 'RF' : referer - Apache %{referer}i 'RH' : the specified request header (e.g. "RH:cache-control:") 'RP' : request protocol (e.g. HTTP/2, HTTP1.1) 'RQ' : FULL request path (script and any query string) - Apache %r 'RS' : response status code - none 'SC' : script name - none 'SM' : request scheme name (i.e. "http:" or "https:") - none 'SN' : server host name (virtual) - Apache %v 'SP' : server port - Apache %p 'SR' : SSL session reused (cached) - none 'SV' : SSL version (e.g. "SSLv3", "TLSv1") - none 'TC' : request time (common log format) - Apache %t 'TI' : request time (local in ISO 8601 extended format) - none 'TS' : (sortable) request time (UTC in ISO 8601 basic format) - none 'TV' : request time (VMS format) - none 'TU' : request time (UTC) - none 'UA' : user agent - Apache %{user-agent}i 'VS' : virtual service (actual service host:port used by the request) 'XX' : custom, usually site/client-specific, logging item (see below) A '\' followed by ... '0' : a null character (used to define the empty field character) '!' : insert an '!' '\' : insert a '\' 'n' : insert a newline 'q' : insert a quote (so that in the DCL the quotes won't need escaping!) 't' : insert a TAB Any other character is directly inserted into the log entry. PRE-DEFINED PLUS USER-DEFINED ----------------------------- It is possible to use one of the pre-defined keywords with additional user-defined directive appended. The appended directives must include ALL additional literal characters and directives required in the log entry. The syntax is + as in "COMMON+ !EM". XX CUSTOM ITEMS --------------- Sometimes a site will need some specific datum that cannot otherwise easily be derived. The !XX format item calls LoggingCustom() to generate this and insert into the user-defined access log. Current items are: o XX:blb insert a blank line on server startup o XX:conc-auth returns count of current requests using same authorisation o XX:quotas return data on server process quotas used and limits o XX:timeout returns string describing type of timeout EXAMPLES -------- The equivalent of the common log format is: "-!CN !ID !AU [!TC] \q!RQ\q !RS !BY" The combined log format: "-!CN !ID !AU [!TC] \q!RQ\q !RS !BY \q!RF\q \q!UA\q" The WebSite "windows log format" would be created by: "\0!TC\t!CA\t!SN\t!AR\t!AU\t!ME\t!PA\t!RQ\t!EM\t!UA\t!RS\t!BB\t" To get the common log format plus append request duration in seconds: "-!CN !ID !AU [!TC] \q!RQ\q !RS !BY !ES" To include the SSL protocol version and cipher with the combined format: "COMBINED+ !SV !CI" VERSION HISTORY --------------- 10-JUL-2024 MGD bugfix; LoggingDo() abs(rqptr->rqResponse.Duration64) 04-JAN-2021 MGD 'XX:blb' insert visual aid 17-MAY-2020 MGD protocol "HTTP/2" also reported in standard log formats 16-MAY-2018 MGD 'XX:quotas" server process quotas (trouble-shooting only) 23-DEC-2017 MGD 'TI' local request time in ISO 8601 format 'TS' (sortable) UTC request time in ISO 8601 extended format (provide a sortable time string when merging logs) 'TU' UTC request time ('TG' is now a synonym) 16-DEC-2017 MGD 'BY' and 'BQ' now synonymous for non-VAX (both quads) bugfix; 'BB' header length "lost" during HTTP/2 mods 20-OCT-2017 MGD 'II' image information (file name, version, link date-time) stamp (note) events when common/combined with/without plus 09-JUN-2017 MGD bugfix; LoggingDo() 'SR' silliness from v11.0 rework 13-DEC-2016 MGD 'CL' content-length and 'PL' payload (bytes) 13-APR-2016 MGD 'RP' request protocol (a la CGI REQUEST_PROTOCOL) "XX:timeout" logging extension ensure timed-out requests are logged as 408/500 12-MAR-2016 MGD 'DI' insert specified dictionary item value 'NP' insert notepad value 'XX' custom logging items bugfix; LoggingDo() elapsed time items 05-OCT-2015 MGD bugfix; LoggingDo() 'VS' |->ServicePtr| dereference 04-OCT-2015 MGD bugfix; LoggingDo() 'CC' do not reuse pointers! 30-SEP-2015 MGD LoggingDo() MAX_FAO_VECTOR from 64 to 128 10-MAR-2015 MGD add WASD_LOGS "convenience" logical name after WASD_LOG 12-NOV-2014 MGD 'CI, 'SR', 'SV' for SSL cipher, session reused and version COMMON+, COMMON_SERVER+, COMBINED+ composite log formats 29-JAN-2014 MGD access log buffer extended from [4096] to [16384] (UMA SAML) LoggingQuoted() explicitly encode some fields where a raw quotation mark (URI forbidden) can break a log entry 09-APR-2011 MGD 'PP' outgoing proxy connection local port 04-FEB-2010 MGD 'HO' request "Host:" field 'RH' any request header (e.g. "RH:cache-control:") 'VS' virtual service used by the host bugfix; LoggingDo() sys$flush(&RAB) not (&FAB) 01-FEB-2010 MGD bugfix; LoggingDo() initialise (zero) &DummyRequest 15-NOV-2009 MGD bugfix; whatever happened to 'CN'? 13-OCT-2009 MGD allow for []-delimited IPv6 addresses as service names 26-MAY-2009 MGD 'CP' for client port per-service user-defined log format 04-NOV-2006 MGD bugfix; LoggingDo() changes for daily period test to support hourly logging (thanks again JPP) LOGGING_SHUT to a close log file (without disabling logging) 30-SEP-2006 MGD add HOURLY period remove file name length constraint for logs created on an ODS-5 volume (allows full host name components, etc.) 26-JAN-2006 MGD bugfix; 'RQ' include method and protocol (Apache "%r") bugfix; 'EM', 'ES' and 'UE' arithmetic ('doh'!?) 'ET' (equivalent of Apache "%T") 12-OCT-2004 MGD configurable service unavailable 503 when log write fails 04-SEP-2004 MGD 'BQ' for quadword bytes tx 04-AUG-2004 MGD refine end-of-period log file handling 04-MAR-2004 MGD timestamp entry, server account username 28-JAN-2004 MGD LoggingReport(), add HTTP protocol to timestamp and pseudo entries 28-JUN-2003 MGD bugfix; add HTTP protocol to combined/common format URL 'PR' same datum with user format (jf.pieronne@laposte.fr) 08-APR-2003 MGD timestamp and pseudo entry formats, make bytes numeric and leading slash before server POST paths (e.g. "/KLAATU::..") (Analog could complain about both of these), add the server software ID as the user-agent field 26-MAY-2002 MGD logging per-instance 21-DEC-2001 MGD bugfix; 07-NOV-2001 for ALL services :^} 07-NOV-2001 MGD bugfix; close current log file if period changes 25-OCT-2001 MGD timestamp log file(s) every hour, FAB$M_TEF to deallocate unused file space 04-AUG-2001 MGD support module WATCHing 04-MAY-2001 MGD increased LoggingDo() 'String' size from 2048 TO 4096 20-MAR-2001 MGD added FAB$M_DFW, w_deq=nnn, b_mbc=127, improves log performance by 500%!! (jfp@altavista.net) 15-DEC-2000 MGD client certificate authorization (as rfc1413 & 'CC') 15-OCT-2000 MGD correct time string TZ (GMT format) 07-MAY-2000 MGD session track ID 16-FEB-2000 MGD "[LogNaming] HOST", [LogPerServiceHostOnly] processing 12-JUN-1999 MGD modify WATCH log entry format 22-MAR-1999 MGD increased LoggingDo() 'String' size from 1024 to 2048 07-NOV-1998 MGD WATCH facility 27-AUG-1998 MGD exclude specified hosts from being logged 17-MAY-1998 MGD add per-service logging 23-NOV-1997 MGD signal failed log file create/put (e.g. disk quota :^) 25-OCT-1997 MGD log file period new for v4.5, log file now opened for sharing GET, PUT and UPD added 'CI' (cache-involvement) user-format directive bugfix; user format from configuration file 25-SEP-1997 MGD bugfix; ACCVIO if request structure exists but empty (assumed if it existed all the pointers were valid - WRONG!) 06-SEP-1997 MGD added "common+server", "combined", "user-defined" log formats 10-JUL-1997 MGD minor modification for server-admin logging on/off/flush 10-JUL-1996 MGD RequestUriPtr instead of ScriptPtr/PathInfoPtr/QueryStringPtr 01-DEC-1995 MGD HTTPd version 3, "common" log format 27-SEP-1995 MGD use time values in request thread structure 16-JUN-1995 MGD added node name, changed logging fields to be space-separated 07-APR-1995 MGD initial development for addition to multi-threaded daemon */ /*****************************************************************************/ #ifdef WASD_VMS_V7 #undef _VMS__V6__SOURCE #define _VMS__V6__SOURCE #undef __VMS_VER #define __VMS_VER 70000000 #undef __CRTL_VER #define __CRTL_VER 70000000 #endif /* standard C header files */ #include #include #include #include /* VMS related header files */ #include #include #include #include #include #include #include /* application header files */ #include "wasd.h" #include "httpd.h" #include "error.h" #include "logging.h" #define WASD_MODULE "LOGGING" #define LOGGING_NAMING_NAME 1 #define LOGGING_NAMING_HOST 2 #define LOGGING_NAMING_ADDRESS 3 /******************/ /* global storage */ /******************/ char ErrorLoggingFormatLength [] = "log format too long"; int LoggingDayWeekBegins; BOOL LoggingEnabled, LoggingNaming, LoggingPerPeriod, LoggingPerService, LoggingPeriodHourly, LoggingPeriodDaily, LoggingPeriodWeekly, LoggingPeriodMonthly, LoggingProxyLocalPort, LoggingSysOutput, LoggingFileError; int LoggingFileNameLength, LoggingNaming, LoggingTimeStampCount; char LoggingFileName [256], LoggingFormatUser [256], LoggingPeriodName [128]; /********************/ /* external storage */ /********************/ extern BOOL CliLoggingDisabled, CliLoggingEnabled; extern int EfnWait, ExitStatus, HttpdDayOfWeek, HttpdTickSecond, ServerPort; extern int64 HttpdTime64; extern ushort HttpdTime7[]; extern ulong SysPrvMask[]; extern char CliLoggingPeriod[], ErrorSanityCheck[], ServerHostName[], SoftwareID[], TimeGmtString[]; extern CONFIG_STRUCT Config; extern HTTPD_PROCESS HttpdProcess; extern LIST_HEAD RequestList; extern META_CONFIG *MetaGlobalServicePtr; extern LIST_HEAD ServiceList; extern SYS_INFO SysInfo; extern WATCH_STRUCT Watch; /*****************************************************************************/ /* Parameter 'Function' can be: LOGGING_BEGIN server startup LOGGING_OPEN open server logging, other than server startup LOGGING_CLOSE close server logging, other than server shutdown LOGGING_END server shutdown LOGGING_ENTRY log a request LOGGING_SHUT shut (close) the log files LOGGING_TIMESTAMP put a timestamp pseudo-entry into the log file LOGGING_FLUSH close the log file, flushing the contents With per-service logging most of these functions must be performed on each service's log, logging a request entry occurs for the service involved only. */ int Logging ( REQUEST_STRUCT *rqptr, int Function ) { BOOL PrevLoggingEnabled, WatchThisOne; int status; char *cptr, *sptr; SERVICE_STRUCT *svptr; /*********/ /* begin */ /*********/ if (WATCHMOD (rqptr, WATCH_MOD__OTHER)) WatchThis (WATCHALL, WATCH_MOD__OTHER, "Logging() !UL", Function); if (!rqptr && WATCH_CATEGORY(WATCH_LOG)) WatchThisOne = true; else if (rqptr) { if (WATCHING (rqptr, WATCH_LOG)) WatchThisOne = true; else WatchThisOne = false; } else WatchThisOne = false; switch (Function) { case LOGGING_ENTRY : if (!LoggingEnabled) return (STS$K_ERROR); /* if the request path has been mapping-rule set NOlog then don't! */ if (rqptr && rqptr->rqPathSet.NoLog) { if (WATCH_CAT && WatchThisOne) { cptr = rqptr->rqHeader.RequestUriPtr; if (!cptr || !*cptr) cptr = "(none)"; WatchThis (WATCHITM(rqptr), WATCH_LOG, "NOLOG !AZ", cptr); } return (SS$_NORMAL); } if (rqptr && Config.cfLog.ExcludeHostsPtr) { sptr = Config.cfLog.ExcludeHostsPtr; while (*sptr) { if (isdigit(*sptr)) cptr = &rqptr->ClientPtr->IpAddressString; else cptr = rqptr->ClientPtr->Lookup.HostName; while (*cptr) { if (*sptr == STRING_LIST_CHAR) break; if (*sptr == '*') { while (*sptr && *sptr == '*' && *sptr != STRING_LIST_CHAR) sptr++; while (*cptr && *cptr != *sptr) cptr++; } if (to_lower(*cptr) != to_lower(*sptr)) break; if (*cptr) cptr++; if (*sptr) sptr++; } if (!*cptr && (!*sptr || *sptr == STRING_LIST_CHAR)) break; while (*sptr && *sptr != STRING_LIST_CHAR) sptr++; if (*sptr) sptr++; } /* if it was found then return without logging the request */ if (!*cptr && (!*sptr || *sptr == STRING_LIST_CHAR)) { if (WATCH_CAT && WatchThisOne) WatchThis (WATCHITM(rqptr), WATCH_LOG, "EXCLUDE !AZ", rqptr->ClientPtr->Lookup.HostName); return (SS$_NORMAL); } } if (rqptr && rqptr->ServicePtr->NoLog) { if (WATCH_CAT && WatchThisOne) WatchThis (WATCHITM(rqptr), WATCH_LOG, "NOLOG for !AZ//!AZ", rqptr->ServicePtr->RequestSchemeNamePtr, rqptr->ServicePtr->ServerHostPort); return (STS$K_ERROR); } if (rqptr && LoggingPerService) status = LoggingDo (rqptr, rqptr->ServicePtr, Function, WatchThisOne); else status = LoggingDo (rqptr, LIST_GET_HEAD(&ServiceList), Function, WatchThisOne); return (status); case LOGGING_BEGIN : case LOGGING_CLOSE : case LOGGING_END : case LOGGING_FLUSH : case LOGGING_OPEN : case LOGGING_SHUT : case LOGGING_TIMESTAMP : switch (Function) { case LOGGING_BEGIN : if (Config.cfLog.Enabled || CliLoggingEnabled) LoggingEnabled = true; if (CliLoggingDisabled) LoggingEnabled = false; LoggingPerService = Config.cfLog.PerService || Config.cfLog.PerServiceHostOnly; /* in log using host part of file name, name or address? */ LoggingNaming = LOGGING_NAMING_NAME; if (Config.cfLog.Naming[0]) { if (strsame (Config.cfLog.Naming, "NAME", -1)) LoggingNaming = LOGGING_NAMING_NAME; else if (strsame (Config.cfLog.Naming, "HOST", -1)) LoggingNaming = LOGGING_NAMING_HOST; else if (strsame (Config.cfLog.Naming, "ADDRESS", -1)) LoggingNaming = LOGGING_NAMING_ADDRESS; else FaoToStdout ("%HTTPD-W-LOG, naming unknown\n \\!AZ\\\n", Config.cfLog.Naming); } break; case LOGGING_OPEN : if (LoggingEnabled) return (STS$K_ERROR); break; default : if (!LoggingEnabled) return (STS$K_ERROR); break; } PrevLoggingEnabled = LoggingEnabled; if (Function == LOGGING_TIMESTAMP) LoggingTimeStampCount++; if (LoggingPerService) { LIST_ITERATE (svptr, &ServiceList) { status = LoggingDo (rqptr, svptr, Function, WatchThisOne); if (VMSnok (status)) break; } } else status = LoggingDo (rqptr, LIST_GET_HEAD(&ServiceList), Function, WatchThisOne); switch (Function) { case LOGGING_BEGIN : if (VMSnok (status)) LoggingEnabled = false; break; case LOGGING_OPEN : if (VMSok (status)) LoggingEnabled = true; else LoggingEnabled = PrevLoggingEnabled; break; case LOGGING_CLOSE : case LOGGING_END : if (VMSok (status)) LoggingEnabled = LoggingFileError = false; else LoggingEnabled = PrevLoggingEnabled; } return (status); default : ErrorExitVmsStatus (SS$_BUGCHECK, ErrorSanityCheck, FI_LI); } } /*****************************************************************************/ /* What an incomprehensibly long function this has grown to be! :^( The 'svptr' parameter points to the service structure associated with the log. If per-service logging is enabled this will be the appropriate one of however many services are created. If per-service logging is not enabled this will always be the first service created (i.e. the "primary" service). Where service information is required for user-format logging it is accessed from the request structure's service pointer. */ int LoggingDo ( REQUEST_STRUCT *rqptr, SERVICE_STRUCT *svptr, int Function, BOOL WatchThisOne ) { # define MAX_FAO_VECTOR 128 static char *MonthName [] = { "", "Jan", "Feb", "Mar", "Apr", "May", "Jun", "Jul", "Aug", "Sep", "Oct", "Nov", "Dec" }; static $DESCRIPTOR (PeriodFileNameFaoDsc, "!#AZ!AZ!AZ_!UL!2ZL!2ZL!AZ_ACCESS.LOG!AZ!AZ!AZ!AZ"); static $DESCRIPTOR (ServiceFileNameFaoDsc, "!#AZ!AZ!AZ_ACCESS.LOG!AZ!AZ!AZ!AZ"); static $DESCRIPTOR (ClientPortFaoDsc, "!UL\0"); static $DESCRIPTOR (ElapsedResponseDurationDsc, "!UL\0"); static $DESCRIPTOR (ElapsedSecondsDsc, "!UL.!3ZL\0"); static $DESCRIPTOR (HourlyFaoDsc, "!2ZL\0"); static $DESCRIPTOR (LocalPortFaoDsc, "!UL\0"); static $DESCRIPTOR (NumberFaoDsc, "!UL\0"); static $DESCRIPTOR (Number64FaoDsc, "!@UQ\0"); static $DESCRIPTOR (StatusFaoDsc, "!UL\0"); static $DESCRIPTOR (VmsTimeFaoDsc, "!%D\0"); static $DESCRIPTOR (LogFileTimeFaoDsc, "!2ZL/!3AZ/!4ZL:!2ZL:!2ZL:!2ZL !3AZ!2AZ"); /* server-host - - [date/time] \"what-status\" 200 0 */ static $DESCRIPTOR (LogFilePseudoFaoDsc, "!AZ !AZ !AZ [!AZ] \"POST /!AZ::!AZ-!AZ-!8XL HTTP/1.1\" 200 0!AZ!AZ!AZ"); /* server-host - - [date/time] \"TIMESTAMP-count\" 200 0 */ static $DESCRIPTOR (LogFileTimeStampFaoDsc, "!AZ !AZ !AZ [!AZ] \"POST /!AZ::!AZ-!AZ-!8ZL HTTP/1.1\" 200 0!AZ!AZ!AZ"); /* host r-ident user [date/time] \"request\" status bytes */ static char CommonFormat [] = "-!CN !ID !AU [!TC] \\q!RQ\\q !RS !BY"; static $DESCRIPTOR (LogFileCommonFaoDsc, "!AZ !AZ !AZ [!AZ] \"!AZ !AZ!AZ\" !UL !AZ"); /* as for "common" above, plus ' server'*/ static char CommonServerFormat [] = "-!CN !ID !AU [!TC] \\q!RQ\\q !RS !BY !SN"; static $DESCRIPTOR (LogFileCommonServerFaoDsc, "!AZ !AZ !AZ [!AZ] \"!AZ !AZ!AZ\" !UL !AZ !AZ"); /* as for "common" above, plus ' referer user-agent'*/ static char CombinedFormat [] = "-!CN !ID !AU [!TC] \\q!RQ\\q !RS !BY \\q!RF\\q \\q!UA\\q"; static $DESCRIPTOR (LogFileCombinedFaoDsc, "!AZ !AZ !AZ [!AZ] \"!AZ !AZ!AZ\" !UL !AZ \"!AZ\" \"!AZ\""); /* user-defined log-file format */ static $DESCRIPTOR (LogFileUserFaoDsc, "!#(AZ)"); static int ExtendBlocks = LOGGING_DEFAULT_EXTEND_BLOCKS; static ushort WeeklyTime7 [7]; static char ClientPort [16], Elapsed [32], HourlyString [3], IsoTimeString [32], LengthString [32], PayloadString [32], ProcessName [16], SortableTimeString [32], StatusString [16], String [16384], TimeString [32], VmsTimeString [32]; static $DESCRIPTOR (ClientPortDsc, ClientPort); static $DESCRIPTOR (ElapsedDsc, Elapsed); static $DESCRIPTOR (HourlyStringDsc, HourlyString); static $DESCRIPTOR (LengthStringDsc, LengthString); static $DESCRIPTOR (PayloadStringDsc, PayloadString); static $DESCRIPTOR (StatusStringDsc, StatusString); static $DESCRIPTOR (StringDsc, String); static $DESCRIPTOR (TimeStringDsc, TimeString); static $DESCRIPTOR (VmsTimeStringDsc, VmsTimeString); static struct FAB LogFileFab; static struct RAB LogFileRab; /* for when testing the log format */ static CLIENT_STRUCT DummyClient; static NETIO_STRUCT DummyNetIo; static REQUEST_STRUCT DummyRequest; static SERVICE_STRUCT DummyService; BOOL PeriodChanged; int len, size, status, SetimrStatus; ushort slen; ulong *vecptr, *Time64Ptr; ushort *Time7Ptr; ulong FaoVector [MAX_FAO_VECTOR]; char *aptr, *cptr, *sptr, *zptr, *FunctionNamePtr; char MiscChars [MAX_FAO_VECTOR * 2], ClientCertSubject [512]; /*********/ /* begin */ /*********/ if (WATCHMOD (rqptr, WATCH_MOD__OTHER)) WatchThis (WATCHITM(rqptr), WATCH_MOD__OTHER, "LoggingDo() !UL !&X !&X", Function, rqptr, svptr); /* logging to SYS$OUTPUT does not do many of the things that set 'status' */ status = SS$_NORMAL; if (Function == LOGGING_BEGIN) { /*****************/ /* begin logging */ /*****************/ /* if no logging file name from command line then use any config one */ if (!LoggingFileName[0] && Config.cfLog.FileName[0]) strzcpy (LoggingFileName, Config.cfLog.FileName, sizeof(LoggingFileName)); if (!LoggingFileName[0]) { if (!(cptr = SysTrnLnm (WASD_LOG))) if (!(cptr = SysTrnLnm (WASD_LOGS))) if (!(cptr = SysTrnLnm (HTTPD$LOG))) return (SS$_NOLOGNAM); strzcpy (LoggingFileName, cptr, sizeof(LoggingFileName)); } if (!LoggingFileNameLength) LoggingFileNameLength = strlen(LoggingFileName); if (strsame (LoggingFileName, "SYS$OUTPUT", -1)) LoggingSysOutput = true; else LoggingSysOutput = false; if (Config.cfLog.ExtendBlocks) ExtendBlocks = Config.cfLog.ExtendBlocks; if (ExtendBlocks < 0) ExtendBlocks = 0; else if (ExtendBlocks > 65535) ExtendBlocks = 65535; /************************/ /* determine log format */ /************************/ svptr->LogFormatProblem = false; if (LoggingFormatUser[0]) svptr->LogFormatPtr = LoggingFormatUser; else if (svptr->LogFormat[0]) svptr->LogFormatPtr = svptr->LogFormat; else if (Config.cfLog.Format[0]) svptr->LogFormatPtr = Config.cfLog.Format; else svptr->LogFormatPtr = NULL; if (svptr->LogFormatPtr) { if (strsame (svptr->LogFormatPtr, "COMMON", -1)) { svptr->LogFormatCommonServer = svptr->LogFormatCombined = false; svptr->LogFormatCommon = svptr->LogFormatStamp = true; svptr->LogFormatPtr = NULL; } else if (strsame (svptr->LogFormatPtr, "COMMON+", 7)) { svptr->LogFormatCommon = svptr->LogFormatCommonServer = svptr->LogFormatCombined = false; svptr->LogFormatStamp = true; len = strlen(CommonFormat) + strlen(svptr->LogFormatPtr+7); aptr = VmGet (size = len+1); strzcpy (aptr, CommonFormat, size); strzcat (aptr, svptr->LogFormatPtr+7, size); svptr->LogFormatPtr = aptr; } else if (strsame (svptr->LogFormatPtr, "COMMON_SERVER", -1)) { svptr->LogFormatCommon = svptr->LogFormatCombined = false; svptr->LogFormatCommonServer = svptr->LogFormatStamp = true; svptr->LogFormatPtr = NULL; } else if (strsame (svptr->LogFormatPtr, "COMMON_SERVER+", 14)) { svptr->LogFormatCommon = svptr->LogFormatCommonServer = svptr->LogFormatCombined = false; svptr->LogFormatStamp = true; len = strlen(CommonServerFormat) + strlen(svptr->LogFormatPtr+14); aptr = VmGet (size = len+1); strzcpy (aptr, CommonServerFormat, size); strzcat (aptr, svptr->LogFormatPtr+14, size); svptr->LogFormatPtr = aptr; } else if (strsame (svptr->LogFormatPtr, "COMBINED", -1)) { svptr->LogFormatCommon = svptr->LogFormatCommonServer = false; svptr->LogFormatCombined = svptr->LogFormatStamp = true; svptr->LogFormatPtr = NULL; } else if (strsame (svptr->LogFormatPtr, "COMBINED+", 9)) { svptr->LogFormatCommon = svptr->LogFormatCommonServer = svptr->LogFormatCombined = false; svptr->LogFormatStamp = true; len = strlen(CombinedFormat) + strlen(svptr->LogFormatPtr+9); aptr = VmGet (size = len+1); strzcpy (aptr, CombinedFormat, size); strzcat (aptr, svptr->LogFormatPtr+9, size); svptr->LogFormatPtr = aptr; } else svptr->LogFormatCommon = svptr->LogFormatCommonServer = svptr->LogFormatCombined = false; if (svptr->LogFormatPtr) if (strstr (svptr->LogFormatPtr, "!PP")) LoggingProxyLocalPort = true; } else svptr->LogFormatCommon = true; /****************************/ /* determine logging period */ /****************************/ LoggingPerPeriod = LoggingPeriodHourly = LoggingPeriodDaily = LoggingPeriodWeekly = LoggingPeriodMonthly = false; if (!LoggingPeriodName[0] && Config.cfLog.Period[0]) strzcpy (LoggingPeriodName, Config.cfLog.Period, sizeof(LoggingPeriodName)); if (LoggingPeriodName[0]) { svptr->LogDayNumber = svptr->LogMonthNumber = svptr->LogYearNumber = 0; if (strsame (LoggingPeriodName, "HOURLY", 3)) LoggingPerPeriod = LoggingPeriodHourly = true; else if (strsame (LoggingPeriodName, "DAILY", 3)) LoggingPerPeriod = LoggingPeriodDaily = true; else if (strsame (LoggingPeriodName, "SUNDAY", 3)) { LoggingPerPeriod = LoggingPeriodWeekly = true; LoggingDayWeekBegins = 7; } else if (strsame (LoggingPeriodName, "WEEKLY", 3) || strsame (LoggingPeriodName, "MONDAY", 4)) { LoggingPerPeriod = LoggingPeriodWeekly = true; LoggingDayWeekBegins = 1; } else if (strsame (LoggingPeriodName, "TUESDAY", 3)) { LoggingPerPeriod = LoggingPeriodWeekly = true; LoggingDayWeekBegins = 2; } else if (strsame (LoggingPeriodName, "WEDNESDAY", 3)) { LoggingPerPeriod = LoggingPeriodWeekly = true; LoggingDayWeekBegins = 3; } else if (strsame (LoggingPeriodName, "THURSDAY", 3)) { LoggingPerPeriod = LoggingPeriodWeekly = true; LoggingDayWeekBegins = 4; } else if (strsame (LoggingPeriodName, "FRIDAY", 3)) { LoggingPerPeriod = LoggingPeriodWeekly = true; LoggingDayWeekBegins = 5; } else if (strsame (LoggingPeriodName, "SATURDAY", 3)) { LoggingPerPeriod = LoggingPeriodWeekly = true; LoggingDayWeekBegins = 6; } else if (strsame (LoggingPeriodName, "MONTH", 4)) LoggingPerPeriod = LoggingPeriodMonthly = true; else { FaoToStdout ("%HTTPD-W-LOG, period unknown\n \\!AZ\\\n", LoggingPeriodName); LoggingPerPeriod = false; } } /*************************/ /* get logging host name */ /*************************/ zptr = (sptr = svptr->LogHostName) + sizeof(svptr->LogHostName)-1; if (LoggingNaming == LOGGING_NAMING_ADDRESS) { /* as much of the IP address as possible */ for (cptr = svptr->ServerIpAddressString; *cptr && sptr < zptr; cptr++) { if (*cptr == '[' || *cptr == ']') continue; if (*cptr == '.' || *cptr == ':') *sptr++ = '-'; else *sptr++ = *cptr; } } else if (LoggingNaming == LOGGING_NAMING_HOST) { /* as much of the IP host name as possible */ for (cptr = svptr->ServerHostName; *cptr && sptr < zptr; cptr++) { if (*cptr == '[' || *cptr == ']') continue; if (*cptr == '.' || *cptr == ':') *sptr++ = '-'; else *sptr++ = *cptr; } } else { /* default, LOGGING_NAMING_NAME */ if (svptr->ServerHostName[0] == '[') for (cptr = svptr->ServerHostName; *cptr && (*cptr == '[' || *cptr == ']' || *cptr == ':' || isxdigit(*cptr)); cptr++); else for (cptr = svptr->ServerHostName; *cptr && (*cptr == '.' || isdigit(*cptr)); cptr++); if (*cptr) { /* the first part of the host name */ for (cptr = svptr->ServerHostName; *cptr && *cptr != '.' && sptr < zptr; *sptr++ = to_upper(*cptr++)); } else { /* all numeric/IPv6 service name */ for (cptr = svptr->ServerHostName; *cptr && sptr < zptr; cptr++) { if (*cptr == '[' || *cptr == ']') continue; if (*cptr == '.' || *cptr == ':') *sptr++ = '-'; else *sptr++ = *cptr; } } } *sptr = '\0'; zptr = (sptr = ProcessName) + sizeof(ProcessName)-1; for (cptr = HttpdProcess.PrcNam; *cptr && sptr < zptr; cptr++) if (!isalnum(*cptr)) *sptr++ = '-'; else *sptr++ = to_upper(*cptr); *sptr = '\0'; if (!LoggingEnabled) return (SS$_NORMAL); } if (Function == LOGGING_FLUSH) { /******************/ /* flush log file */ /******************/ if (LoggingSysOutput) return (SS$_NORMAL); if (!svptr->LogFileOpen) return (SS$_NORMAL); if (WATCH_CAT && WatchThisOne) WatchThis (WATCHITM(rqptr), WATCH_LOG, "FLUSH !AZ", svptr->LogFileName); sys$flush (&svptr->LogFileRab, 0, 0); return (SS$_NORMAL); } if (Function == LOGGING_SHUT) { /*****************/ /* shut log file */ /*****************/ if (LoggingSysOutput) return (SS$_NORMAL); if (!svptr->LogFileOpen) return (SS$_NORMAL); if (WATCH_CAT && WatchThisOne) WatchThis (WATCHITM(rqptr), WATCH_LOG, "SHUT !AZ", svptr->LogFileName); sys$close (&svptr->LogFileFab, 0, 0); svptr->LogFileOpen = false; return (SS$_NORMAL); } /*************************/ /* log file name change? */ /*************************/ if (rqptr) { /* use the request's times */ Time64Ptr = &rqptr->rqTime.BeginTime64; Time7Ptr = &rqptr->rqTime.BeginTime7; } else { /* use the server's times */ Time64Ptr = &HttpdTime64; Time7Ptr = &HttpdTime7; } if (LoggingPerPeriod && (Time7Ptr[3] != svptr->LogHourNumber || Time7Ptr[2] != svptr->LogDayNumber || Time7Ptr[1] != svptr->LogMonthNumber || Time7Ptr[0] != svptr->LogYearNumber)) { PeriodChanged = false; if (LoggingPeriodHourly) { PeriodChanged = true; svptr->LogYearNumber = Time7Ptr[0]; svptr->LogMonthNumber = Time7Ptr[1]; svptr->LogDayNumber = Time7Ptr[2]; svptr->LogHourNumber = Time7Ptr[3]; } else if (LoggingPeriodDaily) { if (Time7Ptr[2] != svptr->LogDayNumber || Time7Ptr[1] != svptr->LogMonthNumber) { PeriodChanged = true; svptr->LogYearNumber = Time7Ptr[0]; svptr->LogMonthNumber = Time7Ptr[1]; svptr->LogDayNumber = Time7Ptr[2]; svptr->LogHourNumber = Time7Ptr[3]; } } else if (LoggingPeriodWeekly) { LoggingWeek (Time64Ptr, Time7Ptr, &WeeklyTime7); if (WeeklyTime7[0] != svptr->LogYearNumber || WeeklyTime7[1] != svptr->LogMonthNumber || WeeklyTime7[2] != svptr->LogDayNumber) { PeriodChanged = true; svptr->LogYearNumber = WeeklyTime7[0]; svptr->LogMonthNumber = WeeklyTime7[1]; svptr->LogDayNumber = WeeklyTime7[2]; svptr->LogHourNumber = WeeklyTime7[3]; } } else if (LoggingPeriodMonthly) { if (Time7Ptr[1] != svptr->LogMonthNumber) { PeriodChanged = true; svptr->LogYearNumber = Time7Ptr[0]; svptr->LogMonthNumber = Time7Ptr[1]; svptr->LogDayNumber = Time7Ptr[2]; svptr->LogHourNumber = Time7Ptr[3]; } } else ErrorExitVmsStatus (SS$_BUGCHECK, ErrorSanityCheck, FI_LI); if (PeriodChanged) { if (svptr->LogFileOpen) { sys$close (&svptr->LogFileFab, 0, 0); svptr->LogFileOpen = false; } svptr->LogFileNameLength = 0; svptr->LogFileName[0] = '\0'; } } if (!svptr->LogFileOpen && !LoggingSysOutput) { /*********************/ /* open the log file */ /*********************/ /* initialize the FAB before setting up the file name! */ svptr->LogFileFab = cc$rms_fab; if (LoggingPerPeriod) { /*************************************************/ /* per-period logging (with/without per-service) */ /*************************************************/ if (!svptr->LogFileNameLength) { vecptr = FaoVector; len = strlen(svptr->LogHostName); /* basically no constraint on ODS-5 */ if (OdsVolumeStructure (LoggingFileName) != 5) { /* host name component can be from 17 to 20, or 23 chars max */ if (Config.cfLog.PerServiceHostOnly) { if (len > 23) len = 23; } else { if (len + strlen(svptr->ServerPortString) > 22) len = 22 - strlen(svptr->ServerPortString); } if (LoggingPeriodHourly) len -= 2; } *vecptr++ = len; *vecptr++ = svptr->LogHostName; if (Config.cfLog.PerServiceHostOnly) { *vecptr++ = ""; *vecptr++ = ""; } else { *vecptr++ = "_"; *vecptr++ = svptr->ServerPortString; } if (LoggingPeriodWeekly) { *vecptr++ = WeeklyTime7[0]; *vecptr++ = WeeklyTime7[1]; *vecptr++ = WeeklyTime7[2]; } else { *vecptr++ = Time7Ptr[0]; *vecptr++ = Time7Ptr[1]; if (LoggingPeriodMonthly) *vecptr++ = 1; else *vecptr++ = Time7Ptr[2]; } if (LoggingPeriodHourly) { sys$fao (&HourlyFaoDsc, 0, &HourlyStringDsc, Time7Ptr[3]); *vecptr++ = HourlyString; } else *vecptr++ = ""; if (Config.cfLog.PerInstance) { *vecptr++ = "_"; *vecptr++ = SysInfo.NodeName; *vecptr++ = "_"; *vecptr++ = ProcessName; } else { *vecptr++ = ""; *vecptr++ = ""; *vecptr++ = ""; *vecptr++ = ""; } svptr->LogFileNameDsc.dsc$a_pointer = svptr->LogFileName; svptr->LogFileNameDsc.dsc$w_length = sizeof(svptr->LogFileName)-1; status = sys$faol (&PeriodFileNameFaoDsc, &svptr->LogFileNameLength, &svptr->LogFileNameDsc, &FaoVector); if (VMSnok (status)) ErrorExitVmsStatus (status, NULL, FI_LI); svptr->LogFileName[svptr->LogFileNameLength] = '\0'; } /* logging file name is used for the directory component only */ svptr->LogFileFab.fab$l_dna = LoggingFileName; svptr->LogFileFab.fab$b_dns = LoggingFileNameLength; svptr->LogFileFab.fab$l_fna = svptr->LogFileName; svptr->LogFileFab.fab$b_fns = svptr->LogFileNameLength; } else if (LoggingNaming) { /***************************************/ /* per-service logging (no per-period) */ /***************************************/ if (!svptr->LogFileNameLength) { vecptr = FaoVector; len = strlen(svptr->LogHostName); /* basically no constraint on ODS-5 */ if (OdsVolumeStructure (LoggingFileName) != 5) { /* host name component can be from 26 to 29, or 32 chars max */ if (Config.cfLog.PerServiceHostOnly) { if (len > 32) len = 32; } else { if (len + strlen(svptr->ServerPortString) > 31) len = 31 - strlen(svptr->ServerPortString); } } *vecptr++ = len; *vecptr++ = svptr->LogHostName; if (Config.cfLog.PerServiceHostOnly) { *vecptr++ = ""; *vecptr++ = ""; } else { *vecptr++ = "_"; *vecptr++ = svptr->ServerPortString; } if (Config.cfLog.PerInstance) { *vecptr++ = "_"; *vecptr++ = SysInfo.NodeName; *vecptr++ = "_"; *vecptr++ = ProcessName; } else { *vecptr++ = ""; *vecptr++ = ""; *vecptr++ = ""; *vecptr++ = ""; } svptr->LogFileNameDsc.dsc$a_pointer = svptr->LogFileName; svptr->LogFileNameDsc.dsc$w_length = sizeof(svptr->LogFileName)-1; status = sys$faol (&ServiceFileNameFaoDsc, &svptr->LogFileNameLength, &svptr->LogFileNameDsc, &FaoVector); if (VMSnok (status)) ErrorExitVmsStatus (status, NULL, FI_LI); svptr->LogFileName[svptr->LogFileNameLength] = '\0'; } /* logging file name is used for the directory component only */ svptr->LogFileFab.fab$l_dna = LoggingFileName; svptr->LogFileFab.fab$b_dns = LoggingFileNameLength; svptr->LogFileFab.fab$l_fna = svptr->LogFileName; svptr->LogFileFab.fab$b_fns = svptr->LogFileNameLength; } else { /******************/ /* fixed log file */ /******************/ /* the logging file name must be complete */ svptr->LogFileFab.fab$l_fna = LoggingFileName; svptr->LogFileFab.fab$b_fns = LoggingFileNameLength; } /************************/ /* create/open log file */ /************************/ if (WATCH_CAT && WatchThisOne) WatchThis (WATCHITM(rqptr), WATCH_LOG, "OPEN !AZ", svptr->LogFileName); svptr->LogFileFab.fab$l_fop = FAB$M_CIF | FAB$M_DFW | FAB$M_SQO | FAB$M_TEF; svptr->LogFileFab.fab$w_deq = ExtendBlocks; svptr->LogFileFab.fab$b_fac = FAB$M_PUT; svptr->LogFileFab.fab$b_rfm = FAB$C_STMLF; svptr->LogFileFab.fab$b_shr = FAB$M_SHRGET | FAB$M_SHRPUT | FAB$M_SHRUPD; svptr->LogFileFab.fab$b_org = FAB$C_SEQ; svptr->LogFileFab.fab$b_rat = FAB$M_CR; /* turn on SYSPRV to allow access to the logging file */ sys$setprv (1, &SysPrvMask, 0, 0); status = sys$create (&svptr->LogFileFab, 0, 0); sys$setprv (0, &SysPrvMask, 0, 0); if (VMSnok (status)) { if (WATCH_CAT && WatchThisOne) WatchThis (WATCHITM(rqptr), WATCH_LOG, "CREATE !AZ !&S", svptr->LogFileName, status); if (!svptr->LogFileError) { svptr->LogFileError = LoggingFileError = true; FaoToStdout ("%HTTPD-W-LOG, file create error\n-!&M\n \\!AZ\\\n", status, svptr->LogFileName); if (Config.cfLog.WriteFail503) LoggingFileError = true; } return (status); } svptr->LogFileError = LoggingFileError = false; svptr->LogFileRab = cc$rms_rab; svptr->LogFileRab.rab$l_fab = &svptr->LogFileFab; svptr->LogFileRab.rab$b_mbc = 127; svptr->LogFileRab.rab$b_mbf = 4; svptr->LogFileRab.rab$l_rop = RAB$M_EOF | RAB$M_WBH; if (VMSnok (status = sys$connect (&svptr->LogFileRab, 0, 0))) { if (WATCH_CAT && WatchThisOne) WatchThis (WATCHITM(rqptr), WATCH_LOG, "CREATE !AZ !&S", svptr->LogFileName, status); sys$close (&svptr->LogFileFab, 0, 0); return (status); } svptr->LogFileOpen = true; } /***********************/ /* act on the log file */ /***********************/ status = sys$fao (&LogFileTimeFaoDsc, &slen, &TimeStringDsc, Time7Ptr[2], MonthName[Time7Ptr[1]], Time7Ptr[0], Time7Ptr[3], Time7Ptr[4], Time7Ptr[5], TimeGmtString, TimeGmtString+4); TimeString[slen] = '\0'; if (Function == LOGGING_BEGIN || Function == LOGGING_CLOSE || Function == LOGGING_END || Function == LOGGING_OPEN || Function == LOGGING_SHUT || Function == LOGGING_TIMESTAMP) { switch (Function) { case LOGGING_BEGIN : LoggingBlankLine (svptr); FunctionNamePtr = "BEGIN"; break; case LOGGING_CLOSE : FunctionNamePtr = "CLOSE"; break; case LOGGING_END : FunctionNamePtr = "END"; break; case LOGGING_OPEN : FunctionNamePtr = "OPEN"; break; case LOGGING_SHUT : FunctionNamePtr = "SHUT"; break; case LOGGING_TIMESTAMP : FunctionNamePtr = "TIMESTAMP"; break; default : FunctionNamePtr = "*ERROR*"; } if (svptr->LogFormatStamp) { /* nore (stamp) the event in the log file */ vecptr = FaoVector; *vecptr++ = ServerHostName; *vecptr++ = "-"; *vecptr++ = HttpdProcess.UserName; *vecptr++ = TimeString; *vecptr++ = SysInfo.NodeName; *vecptr++ = HttpdProcess.PrcNam; *vecptr++ = FunctionNamePtr; if (Function == LOGGING_TIMESTAMP) *vecptr++ = LoggingTimeStampCount; else *vecptr++ = ExitStatus; if (svptr->LogFormatCommonServer) { *vecptr++ = " \"-\" \"-\""; *vecptr++ = ""; *vecptr++ = ""; } else if (svptr->LogFormatCombined) { *vecptr++ = " \"-\" \""; *vecptr++ = SoftwareID; *vecptr++ = "\""; } else { *vecptr++ = ""; *vecptr++ = ""; *vecptr++ = ""; } if (Function == LOGGING_TIMESTAMP) status = sys$faol (&LogFileTimeStampFaoDsc, &slen, &StringDsc, &FaoVector); else status = sys$faol (&LogFilePseudoFaoDsc, &slen, &StringDsc, &FaoVector); if (VMSnok (status) || status == SS$_BUFFEROVF) ErrorExitVmsStatus (status, NULL, FI_LI); String[slen] = '\0'; if (WATCH_CAT && WatchThisOne) { WatchThis (WATCHITM(rqptr), WATCH_LOG, "ENTRY !UL bytes", slen); WatchData (String, slen); } if (LoggingSysOutput) fprintf (stdout, "%s\n", String); else { svptr->LogFileRab.rab$l_rbf = String; svptr->LogFileRab.rab$w_rsz = slen; if (VMSnok (status = sys$put (&svptr->LogFileRab, 0, 0))) { if (!svptr->LogFileError) { svptr->LogFileError = LoggingFileError = true; FaoToStdout ("%HTTPD-W-LOG, \ file write error\n-!&M\n \\!AZ\\\n", status, svptr->LogFileName); } } else svptr->LogFileError = LoggingFileError = false; } } if (Function == LOGGING_END || Function == LOGGING_CLOSE) { /******************/ /* close log file */ /******************/ if (WATCH_CAT && WatchThisOne) WatchThis (WATCHITM(rqptr), WATCH_LOG, "CLOSE !AZ", svptr->LogFileName); if (LoggingSysOutput) return (SS$_NORMAL); if (Function == LOGGING_END) LoggingBlankLine (svptr); sys$close (&svptr->LogFileFab, 0, 0); svptr->LogFileOpen = false; } if (Function != LOGGING_BEGIN) return (SS$_NORMAL); /***********************/ /* test logging format */ /***********************/ DummyRequest.ClientPtr = &DummyClient; DummyRequest.NetIoPtr = &DummyNetIo; DummyRequest.ServicePtr = &DummyService; rqptr = &DummyRequest; } if (!rqptr) return (SS$_NORMAL); /*************************/ /* format request record */ /*************************/ /* may be too late for the response but ensure it's logged this way */ if (!rqptr->rqHeader.HttpVersion) rqptr->rqResponse.HttpStatus = 408; else if (rqptr->rqTmr.TimeoutType) rqptr->rqResponse.HttpStatus = 500; if (svptr->LogFormatPtr) { /***********************/ /* user-defined format */ /***********************/ int cnt; char *cptr, *sptr, *AbsentPtr; if (svptr->LogFormatProblem) return (SS$_NORMAL); cnt = 0; sptr = MiscChars; AbsentPtr = ""; cptr = svptr->LogFormatPtr; vecptr = FaoVector; while (*cptr) { if (cnt > MAX_FAO_VECTOR) ErrorExitVmsStatus (0, ErrorLoggingFormatLength, FI_LI); if (cnt == 1) AbsentPtr = FaoVector[0]; switch (*cptr) { case '!' : { cptr++; switch (*(USHORTPTR)cptr) { case 'AR' : if (!rqptr->rqAuth.RealmPtr) *vecptr++ = AbsentPtr; else if (!rqptr->rqAuth.RealmPtr[0]) *vecptr++ = AbsentPtr; else *vecptr++ = rqptr->rqAuth.RealmPtr; cnt++; cptr += 2; continue; case 'AU' : if (!rqptr->RemoteUser[0]) *vecptr++ = AbsentPtr; else *vecptr++ = rqptr->RemoteUser; cnt++; cptr += 2; continue; case 'BB' : if (rqptr->NetIoPtr->BytesRawTx64) { static char BytesString [32]; static $DESCRIPTOR (BytesStringDsc, BytesString); int64 num64; int length; DICT_ENTRY_STRUCT *denptr; if (denptr = ResponseDictHeader (rqptr)) length = DICT_GET_VALUE_LEN(denptr); else length = 0; num64 = rqptr->NetIoPtr->BytesRawTx64; num64 -= length; sys$fao (&Number64FaoDsc, 0, &BytesStringDsc, &length); *vecptr++ = BytesString; } else *vecptr++ = "0"; cnt++; cptr += 2; continue; case 'BQ' : case 'BY' : if (rqptr->NetIoPtr->BytesRawTx64) { static char BytesString [32]; static $DESCRIPTOR (BytesStringDsc, BytesString); sys$fao (&Number64FaoDsc, 0, &BytesStringDsc, &rqptr->NetIoPtr->BytesRawTx64); *vecptr++ = BytesString; } else *vecptr++ = "0"; cnt++; cptr += 2; continue; case 'CA' : *vecptr++ = &rqptr->ClientPtr->IpAddressString; cnt++; cptr += 2; continue; case 'CC' : /* replace all spaces with underscores */ if (rqptr->rqAuth.ClientCertSubjectPtr && rqptr->rqAuth.ClientCertSubjectPtr[0]) { char *cptr, *sptr, *zptr; zptr = (sptr = ClientCertSubject) + sizeof(ClientCertSubject)-1; for (cptr = rqptr->rqAuth.ClientCertSubjectPtr; *cptr && sptr < zptr; cptr++) { if (isspace(*cptr)) *sptr++ = '_'; else *sptr++ = *cptr; } *sptr = '\0'; *vecptr++ = ClientCertSubject; } else *vecptr++ = AbsentPtr; cnt++; cptr += 2; continue; case 'CI' : /* SSL cipher name added 11-NOV-2014 */ /* cache involvement removed 03-APR-2002 */ if (rqptr->NetIoPtr->SesolaPtr) *vecptr++ = SesolaRequestCipher ( rqptr->NetIoPtr->SesolaPtr); else *vecptr++ = AbsentPtr; cnt++; cptr += 2; continue; case 'CL' : /* request content-length value */ if (rqptr->rqHeader.ContentLength64) { sys$fao (&Number64FaoDsc, 0, &LengthStringDsc, &rqptr->rqHeader.ContentLength64); *vecptr++ = LengthString; } else if (rqptr->rqDictPtr && DictLookup (rqptr->rqDictPtr, DICT_TYPE_REQUEST, "content-length", 14)) *vecptr++ = "0"; else *vecptr++ = AbsentPtr; cnt++; cptr += 2; continue; case 'CN' : *vecptr++ = rqptr->ClientPtr->Lookup.HostName; cnt++; cptr += 2; continue; case 'CP' : sys$fao (&ClientPortFaoDsc, 0, &ClientPortDsc, rqptr->ClientPtr->IpPort); *vecptr++ = ClientPort; cnt++; cptr += 2; continue; case 'DI' : { int klen; char key [256]; DICT_ENTRY_STRUCT *denptr; cptr += 2; if (*cptr == ':') { aptr = cptr + 1; klen = StringParseOnlyValue (&aptr, key, sizeof(key)); if (klen > 0) if (denptr = DictLookup (rqptr->rqDictPtr, DICT_TYPE_CONFIG, key, klen)) *vecptr++ = DICT_GET_VALUE(denptr); else *vecptr++ = AbsentPtr; else *vecptr++ = AbsentPtr; cptr = aptr; } else *vecptr++ = AbsentPtr; cnt++; continue; } case 'EM' : { static char str [32]; double dsecs; dsecs = (float)abs(rqptr->rqResponse.Duration64); sprintf (str, "%u", (ulong)(dsecs / 10000.0)); *vecptr++ = str; cnt++; cptr += 2; continue; } case 'ES' : { static char str [32]; double dsecs; dsecs = (float)abs(rqptr->rqResponse.Duration64); sprintf (str, "%.6f", dsecs / 10000000.0); *vecptr++ = str; cnt++; cptr += 2; continue; } case 'ET' : { static char str [32]; double dsecs; dsecs = (float)abs(rqptr->rqResponse.Duration64); sprintf (str, "%u", (ulong)(dsecs / 10000000.0)); *vecptr++ = str; cnt++; cptr += 2; continue; } case 'EU' : { static char str [32]; double dsecs; dsecs = (float)abs(rqptr->rqResponse.Duration64); sprintf (str, "%u", (ulong)(dsecs / 10.0)); *vecptr++ = str; cnt++; cptr += 2; continue; } case 'HO' : if (!rqptr->rqHeader.HostPtr) *vecptr++ = AbsentPtr; else *vecptr++ = rqptr->rqHeader.HostPtr; cnt++; cptr += 2; continue; case 'ID' : /* obsoleted with WASD v11.0 */ *vecptr++ = AbsentPtr; cnt++; cptr += 2; continue; case 'II' : *vecptr++ = LoggingQuoted (rqptr, HttpdProcess.ImageInfo); cnt++; cptr += 2; continue; case 'ME' : *vecptr++ = rqptr->rqHeader.MethodName; cnt++; cptr += 2; continue; case 'NP' : if (rqptr->NotePadPtr) *vecptr++ = rqptr->NotePadPtr; else *vecptr++ = AbsentPtr; cnt++; cptr += 2; continue; case 'PA' : if (!rqptr->rqHeader.PathInfoPtr) *vecptr++ = AbsentPtr; else if (!rqptr->rqHeader.PathInfoPtr[0]) *vecptr++ = AbsentPtr; else *vecptr++ = rqptr->rqHeader.PathInfoPtr; cnt++; cptr += 2; continue; case 'PL' : /* payload - i.e. number of bytes read in PUT or POST */ sys$fao (&Number64FaoDsc, 0, &PayloadStringDsc, rqptr->rqBody.ContentCount64); *vecptr++ = PayloadString; cnt++; cptr += 2; continue; case 'PP' : { static char str [16]; sprintf (str, "%d", rqptr->ProxyLocalPort); *vecptr++ = str; cnt++; cptr += 2; continue; } case 'PR' : if (rqptr->Stream2Ptr) *vecptr++ = " HTTP/2"; else switch (rqptr->rqHeader.HttpVersion) { case HTTP_VERSION_1_1 : *vecptr++ = " HTTP/1.1"; break; case HTTP_VERSION_1_0 : *vecptr++ = " HTTP/1.0"; break; case HTTP_VERSION_0_9 : *vecptr++ = " HTTP/0.9"; break; default : *vecptr++ = AbsentPtr; } cnt++; cptr += 2; continue; case 'QS' : if (!rqptr->rqHeader.QueryStringLength) *vecptr++ = AbsentPtr; else *vecptr++ = rqptr->rqHeader.QueryStringPtr; cnt++; cptr += 2; continue; case 'RF' : if (!rqptr->rqHeader.RefererPtr) *vecptr++ = AbsentPtr; else if (!rqptr->rqHeader.RefererPtr[0]) *vecptr++ = AbsentPtr; else *vecptr++ = LoggingQuoted (rqptr, rqptr->rqHeader.RefererPtr); cnt++; cptr += 2; continue; case 'RH' : if (aptr = LoggingRequestHeader (rqptr, cptr)) { if (*aptr) *vecptr++ = aptr; else *vecptr++ = AbsentPtr; cnt++; /* "RH:field-name:" (it's already been validated!) */ for (cptr += 3; *cptr && *cptr != ':'; cptr++); if (*cptr) cptr++; } else { svptr->LogFormatProblem = true; while (*cptr) cptr++; } continue; case 'RP' : if (HTTP2_REQUEST(rqptr)) *vecptr++ = "HTTP/2"; else if (rqptr->rqHeader.HttpVersion == HTTP_VERSION_1_1) *vecptr++ = "HTTP/1.1"; else if (rqptr->rqHeader.HttpVersion == HTTP_VERSION_1_0) *vecptr++ = "HTTP/1.0"; else if (rqptr->rqHeader.HttpVersion == HTTP_VERSION_0_9) *vecptr++ = "HTTP/0.9"; else *vecptr++ = AbsentPtr; cnt++; cptr += 2; continue; case 'RQ' : if (!rqptr->rqHeader.MethodName[0]) *vecptr++ = AbsentPtr; else *vecptr++ = rqptr->rqHeader.MethodName; cnt++; *vecptr++ = " "; cnt++; if (!rqptr->rqHeader.RequestUriPtr || !rqptr->rqHeader.RequestUriPtr[0]) *vecptr++ = AbsentPtr; else *vecptr++ = LoggingQuoted (rqptr, rqptr->rqHeader.RequestUriPtr); cnt++; if (rqptr->Stream2Ptr) { *vecptr++ = " HTTP/2"; cnt++; } else switch (rqptr->rqHeader.HttpVersion) { case HTTP_VERSION_1_0 : *vecptr++ = " HTTP/1.0"; cnt++; break; case HTTP_VERSION_1_1 : *vecptr++ = " HTTP/1.1"; cnt++; break; default : *vecptr++ = ""; cnt++; } cptr += 2; continue; case 'RS' : sys$fao (&StatusFaoDsc, 0, &StatusStringDsc, rqptr->rqResponse.HttpStatus); *vecptr++ = StatusString; cnt++; cptr += 2; continue; case 'SC' : if (!rqptr->ScriptName[0]) *vecptr++ = AbsentPtr; else *vecptr++ = rqptr->ScriptName; cnt++; cptr += 2; continue; case 'SM' : /* must come from request's service pointer */ if (!rqptr->ServicePtr->RequestSchemeNamePtr) *vecptr++ = AbsentPtr; else *vecptr++ = rqptr->ServicePtr->RequestSchemeNamePtr; cnt++; cptr += 2; continue; case 'SN' : /* must come from request's service pointer */ if (!rqptr->ServicePtr->ServerHostName[0]) *vecptr++ = AbsentPtr; else *vecptr++ = rqptr->ServicePtr->ServerHostName; cnt++; cptr += 2; continue; case 'SP' : /* must come from request's service pointer */ if (!rqptr->ServicePtr->ServerPortString[0]) *vecptr++ = AbsentPtr; else *vecptr++ = rqptr->ServicePtr->ServerPortString; cnt++; cptr += 2; continue; case 'SR' : if (rqptr->NetIoPtr->SesolaPtr) if (SesolaRequestSessionReused (rqptr->NetIoPtr->SesolaPtr)) *vecptr++ = "yes"; else *vecptr++ = "no"; else *vecptr++ = AbsentPtr; cnt++; cptr += 2; continue; case 'SV' : if (rqptr->NetIoPtr->SesolaPtr) *vecptr++ = SesolaRequestVersion ( rqptr->NetIoPtr->SesolaPtr); else *vecptr++ = AbsentPtr; cnt++; cptr += 2; continue; case 'TC' : *vecptr++ = TimeString; cnt++; cptr += 2; continue; case 'TI' : HttpIsoTimeString (true, IsoTimeString, &rqptr->rqTime.BeginTime64); *vecptr++ = IsoTimeString; cnt++; cptr += 2; continue; case 'TS' : HttpIsoTimeString (false, SortableTimeString, &rqptr->rqTime.BeginTime64); *vecptr++ = SortableTimeString; cnt++; cptr += 2; continue; case 'TU' : case 'TG' : /* backward compatibility */ if (!rqptr->rqTime.GmDateTime[0]) *vecptr++ = AbsentPtr; else *vecptr++ = rqptr->rqTime.GmDateTime; cnt++; cptr += 2; continue; case 'TV' : sys$fao (&VmsTimeFaoDsc, 0, &VmsTimeStringDsc, &rqptr->rqTime.BeginTime64); *vecptr++ = VmsTimeString; cnt++; cptr += 2; continue; case 'UA' : if (!rqptr->rqHeader.UserAgentPtr) *vecptr++ = AbsentPtr; else if (!rqptr->rqHeader.UserAgentPtr[0]) *vecptr++ = AbsentPtr; else *vecptr++ = LoggingQuoted (rqptr, rqptr->rqHeader.UserAgentPtr); cnt++; cptr += 2; continue; case 'VS' : *vecptr++ = rqptr->ServicePtr->ServerHostPort; cnt++; cptr += 2; continue; case 'XX' : aptr = cptr; if (*vecptr = LoggingCustom (rqptr, &aptr)) vecptr++; else *vecptr++ = AbsentPtr; cnt++; cptr = aptr; continue; default : svptr->LogFormatProblem = true; while (*cptr) cptr++; continue; } } case '\\' : { cptr++; switch (*cptr) { case '0' : *vecptr++ = ""; cnt++; cptr++; continue; case 'n' : *vecptr++ = "\n"; cnt++; cptr++; continue; case 'q' : *vecptr++ = "\""; cnt++; cptr++; continue; case 't' : *vecptr++ = "\t"; cnt++; cptr++; continue; case '!' : *vecptr++ = "!"; cnt++; cptr++; continue; case '\\' : *vecptr++ = "\\"; cnt++; cptr++; continue; default : svptr->LogFormatProblem = true; while (*cptr) cptr++; continue; } } default : { *sptr = *cptr++; *vecptr++ = sptr++; *sptr++ = '\0'; cnt++; continue; } } } FaoCheck (sizeof(FaoVector), &FaoVector, vecptr, FI_LI); /* now set [0] to the repeat count */ FaoVector[0] = cnt - 1; if (cnt <= 1) svptr->LogFormatProblem = true; if (svptr->LogFormatProblem) { MetaConReport (MetaGlobalServicePtr, METACON_REPORT_ERROR, "Log format problem with !AZ!AZ\n\\!AZ\\", svptr->RequestSchemeNamePtr, svptr->ServerHostPort, svptr->LogFormatPtr); FaoToStdout ("%HTTPD-W-LOG, format problem\n \\!AZ\\\n", svptr->LogFormatPtr); /* fall-back to providing a common-format log */ svptr->LogFormatCommon = true; svptr->LogFormatPtr = NULL; FaoToStdout ("-HTTPD-I-LOG, fall-back to COMMON log format\n"); } } if (svptr->LogFormatCommon || svptr->LogFormatCommonServer || svptr->LogFormatCombined) { /*******************/ /* common/combined */ /*******************/ vecptr = FaoVector; *vecptr++ = rqptr->ClientPtr->Lookup.HostName; /* X509 client cert auth (replace all spaces with underscores) */ if (rqptr->rqAuth.ClientCertSubjectPtr && rqptr->rqAuth.ClientCertSubjectPtr[0]) { zptr = (sptr = ClientCertSubject) + sizeof(ClientCertSubject)-1; for (cptr = rqptr->rqAuth.ClientCertSubjectPtr; *cptr && sptr < zptr; cptr++) { if (isspace(*cptr)) *sptr++ = '_'; else *sptr++ = *cptr; } *sptr = '\0'; *vecptr++ = ClientCertSubject; } else /* track ID obsoleted with WASD v11.0 */ *vecptr++ = "-"; /* if authentication has not been supplied "place-mark" remote user */ if (rqptr->RemoteUser[0]) *vecptr++ = rqptr->RemoteUser; else *vecptr++ = "-"; *vecptr++ = TimeString; if (rqptr->rqHeader.MethodName[0]) *vecptr++ = rqptr->rqHeader.MethodName; else *vecptr++ = "-"; if (!rqptr->rqHeader.RequestUriPtr || !rqptr->rqHeader.RequestUriPtr[0]) *vecptr++ = "-"; else *vecptr++ = LoggingQuoted (rqptr, rqptr->rqHeader.RequestUriPtr); if (rqptr->Stream2Ptr) *vecptr++ = " HTTP/2"; else switch (rqptr->rqHeader.HttpVersion) { case HTTP_VERSION_1_0 : *vecptr++ = " HTTP/1.0"; break; case HTTP_VERSION_1_1 : *vecptr++ = " HTTP/1.1"; break; default : *vecptr++ = ""; } *vecptr++ = rqptr->rqResponse.HttpStatus; if (rqptr->NetIoPtr && rqptr->NetIoPtr->BytesRawTx64) { static char BytesString [32]; static $DESCRIPTOR (BytesStringDsc, BytesString); sys$fao (&Number64FaoDsc, 0, &BytesStringDsc, &rqptr->NetIoPtr->BytesRawTx64); *vecptr++ = BytesString; } else *vecptr++ = "0"; if (svptr->LogFormatCommonServer) *vecptr++ = rqptr->ServicePtr->ServerHostName; else if (svptr->LogFormatCombined) { if (!rqptr->rqHeader.RefererPtr || !rqptr->rqHeader.RefererPtr[0]) *vecptr++ = "-"; else *vecptr++ = LoggingQuoted (rqptr, rqptr->rqHeader.RefererPtr); if (!rqptr->rqHeader.UserAgentPtr || !rqptr->rqHeader.UserAgentPtr[0]) *vecptr++ = "-"; else *vecptr++ = LoggingQuoted (rqptr, rqptr->rqHeader.UserAgentPtr); } } else if (!svptr->LogFormatPtr) ErrorExitVmsStatus (SS$_BUGCHECK, ErrorSanityCheck, FI_LI); /*************/ /* sys$fao() */ /*************/ if (svptr->LogFormatCommon) status = sys$faol (&LogFileCommonFaoDsc, &slen, &StringDsc, &FaoVector); else if (svptr->LogFormatCombined) status = sys$faol (&LogFileCombinedFaoDsc, &slen, &StringDsc, &FaoVector); else if (svptr->LogFormatCommonServer) status = sys$faol (&LogFileCommonServerFaoDsc, &slen, &StringDsc, &FaoVector); else if (svptr->LogFormatPtr) status = sys$faol (&LogFileUserFaoDsc, &slen, &StringDsc, &FaoVector); else ErrorExitVmsStatus (SS$_BUGCHECK, ErrorSanityCheck, FI_LI); if (VMSnok (status) || status == SS$_BUFFEROVF) ErrorNoticed (rqptr, status, NULL, FI_LI); String[slen] = '\0'; /**********************************/ /* if only testing the log format */ /**********************************/ if (rqptr == &DummyRequest) return (SS$_NORMAL); /********************/ /* write the record */ /********************/ if (WATCH_CAT && WatchThisOne) { if (LoggingPerService) { WatchThis (WATCHITM(rqptr), WATCH_LOG, "ENTRY !AZ !UL bytes", svptr->LogFileName, slen); WatchData (String, slen); } else { WatchThis (WATCHITM(rqptr), WATCH_LOG, "ENTRY !UL bytes", slen); WatchData (String, slen); } } if (LoggingSysOutput) { fprintf (stdout, "%s\n", String); status = SS$_NORMAL; } else { svptr->LogFileRab.rab$l_rbf = String; svptr->LogFileRab.rab$w_rsz = slen; if (VMSnok (status = sys$put (&svptr->LogFileRab, 0, 0))) { if (WATCH_CAT && WatchThisOne) WatchThis (WATCHITM(rqptr), WATCH_LOG, "PUT !AZ !&S", svptr->LogFileName, status); if (!svptr->LogFileError) { svptr->LogFileError = LoggingFileError = true; FaoToStdout ("%HTTPD-W-LOG, file write error\n-!&M\n \\!AZ\\\n", status, svptr->LogFileName); } } else svptr->LogFileError = LoggingFileError = false; } return (status); } /*****************************************************************************/ /* Specialised access log user-defined items usually for particular sites/clients. They may or may not have any broader application. The 'XX' item results in a call to this function where the required function is further decoded and implemented. The result is a pointer to string to be included in the access log (so \q\q may be necessary) or a NULL. The format pointer is adjusted to the first white-space character following the custom item. */ char* LoggingCustom ( REQUEST_STRUCT *rqptr, char **FormatPtrPtr ) { int incr; char *fptr, *rptr; /*********/ /* begin */ /*********/ fptr = *FormatPtrPtr; if (WATCH_MODULE(WATCH_MOD__OTHER)) WatchThis (NULL, FI_LI, WATCH_MOD__OTHER, "LoggingCustom() !AZ", fptr); rptr = NULL; if (strsame (fptr, "XX:conc-auth", incr = 12)) rptr = LoggingCustomConcAuth (rqptr); else if (strsame (fptr, "XX:blb", incr = 6)) rptr = ""; else if (strsame (fptr, "XX:timeout", incr = 10)) rptr = LoggingCustomTimeout (rqptr); else if (strsame (fptr, "XX:quotas", incr = 9)) rptr = LoggingCustomQuotas (rqptr); else incr = 2; *FormatPtrPtr = fptr + incr; return (rptr); } /*****************************************************************************/ /* Return the concurrent number of requests using the same authorisation. There can be zero (when no authorisation) and a minimum of one (itself). (compinia.de) */ char* LoggingCustomConcAuth (REQUEST_STRUCT *rqptr) { static char buf [16]; int cnt; LIST_ENTRY *leptr; REQUEST_STRUCT *rqeptr; /*********/ /* begin */ /*********/ if (WATCH_MODULE(WATCH_MOD__OTHER)) WatchThis (NULL, FI_LI, WATCH_MOD__OTHER, "LoggingCustomConcAuth()"); if (!rqptr->rqAuth.RealmPtr || !rqptr->RemoteUser[0]) return ("0"); cnt = 1; for (leptr = RequestList.HeadPtr; leptr; leptr = leptr->NextPtr) { rqeptr = (REQUEST_STRUCT*)leptr; if (rqeptr == rqptr) continue; if (!rqeptr->rqAuth.RealmPtr) continue; if (!strsame (rqeptr->rqAuth.RealmPtr, rqptr->rqAuth.RealmPtr, -1)) continue; if (!rqeptr->RemoteUser[0]) continue; if (!strsame (rqeptr->RemoteUser, rqptr->RemoteUser, -1)) continue; cnt++; } sprintf (buf, "%d", cnt); return (buf); } /*****************************************************************************/ /* Return data on server process quotas used and limits. Trouble-shooting only. */ char* LoggingCustomQuotas (REQUEST_STRUCT *rqptr) { static ulong JpiAstCnt, JpiAstLm, JpiBioCnt, JpiBytLm, JpiBytCnt, JpiBioLm, JpiCpuTime, JpiDioCnt, JpiDioLm, JpiEnqCnt, JpiEnqLm, JpiFilCnt, JpiFilLm, JpiPageFlts, JpiPagFilCnt, JpiPgFlQuota, JpiPrcCnt, JpiPrcLm, JpiTqCnt, JpiTqLm, JpiVirtPeak, JpiWsSize, JpiWsPeak; static VMS_ITEM_LIST3 JpiItems [] = { { sizeof(JpiAstCnt), JPI$_ASTCNT, &JpiAstCnt, 0 }, { sizeof(JpiAstLm), JPI$_ASTLM, &JpiAstLm, 0 }, { sizeof(JpiBioCnt), JPI$_BIOCNT, &JpiBioCnt, 0 }, { sizeof(JpiBioLm), JPI$_BIOLM, &JpiBioLm, 0 }, { sizeof(JpiBytCnt), JPI$_BYTCNT, &JpiBytCnt, 0 }, { sizeof(JpiBytLm), JPI$_BYTLM, &JpiBytLm, 0 }, { sizeof(JpiDioCnt), JPI$_DIOCNT, &JpiDioCnt, 0 }, { sizeof(JpiDioLm), JPI$_DIOLM, &JpiDioLm, 0 }, { sizeof(JpiEnqCnt), JPI$_ENQCNT, &JpiEnqCnt, 0 }, { sizeof(JpiEnqLm), JPI$_ENQLM, &JpiEnqLm, 0 }, { sizeof(JpiFilCnt), JPI$_FILCNT, &JpiFilCnt, 0 }, { sizeof(JpiFilLm), JPI$_FILLM, &JpiFilLm, 0 }, { sizeof(JpiPageFlts), JPI$_PAGEFLTS, &JpiPageFlts, 0 }, { sizeof(JpiPagFilCnt), JPI$_PAGFILCNT, &JpiPagFilCnt, 0 }, { sizeof(JpiPgFlQuota), JPI$_PGFLQUOTA, &JpiPgFlQuota, 0 }, { sizeof(JpiPrcCnt), JPI$_PRCCNT, &JpiPrcCnt, 0 }, { sizeof(JpiPrcLm), JPI$_PRCLM, &JpiPrcLm, 0 }, { sizeof(JpiTqCnt), JPI$_TQCNT, &JpiTqCnt, 0 }, { sizeof(JpiTqLm), JPI$_TQLM, &JpiTqLm, 0 }, { sizeof(JpiVirtPeak), JPI$_VIRTPEAK, &JpiVirtPeak, 0 }, { sizeof(JpiWsSize), JPI$_WSSIZE, &JpiWsSize, 0 }, { sizeof(JpiWsPeak), JPI$_WSPEAK, &JpiWsPeak, 0 }, {0,0,0,0} }; static char JpiString [256]; static $DESCRIPTOR (JpiStringDsc, JpiString); static $DESCRIPTOR (StatusFaoDsc, "%X!8XL\0"); static $DESCRIPTOR (JpiFaoDsc, "!UL/!UL,!UL/!UL,!UL/!UL,!UL/!UL,\ !UL/!UL,!UL/!UL,!UL/!UL/!UL,!UL/!UL,!UL/!UL,!UL/!UL/!UL\0"); int status, pid; ulong *vecptr; ulong FaoVector [24]; IO_SB IOsb; /*********/ /* begin */ /*********/ if (WATCH_MODULE(WATCH_MOD__OTHER)) WatchThis (NULL, FI_LI, WATCH_MOD__OTHER, "LoggingCustomMemory()"); pid = 0; status = sys$getjpiw (EfnWait, &pid, 0, &JpiItems, &IOsb, 0, 0); if (VMSok (status)) status = IOsb.Status; if (VMSok (status)) { vecptr = FaoVector; *vecptr++ = JpiAstCnt; *vecptr++ = JpiAstLm; *vecptr++ = JpiBioCnt; *vecptr++ = JpiBioLm; *vecptr++ = JpiBytCnt; *vecptr++ = JpiBytLm; *vecptr++ = JpiDioCnt; *vecptr++ = JpiDioLm; *vecptr++ = JpiEnqCnt; *vecptr++ = JpiEnqLm; *vecptr++ = JpiFilCnt; *vecptr++ = JpiFilLm; *vecptr++ = JpiPageFlts; *vecptr++ = JpiPagFilCnt; *vecptr++ = JpiPgFlQuota; *vecptr++ = JpiPrcCnt; *vecptr++ = JpiPrcLm; *vecptr++ = JpiTqCnt; *vecptr++ = JpiTqLm; *vecptr++ = JpiVirtPeak; *vecptr++ = JpiWsSize; *vecptr++ = JpiWsPeak; status = sys$faol (&JpiFaoDsc, 0, &JpiStringDsc, &FaoVector); } if (VMSnok (status)) sys$fao (&StatusFaoDsc, 0, &JpiStringDsc, status); return (JpiString); } /*****************************************************************************/ /* Return the type of timeout (compinia.de). */ char* LoggingCustomTimeout (REQUEST_STRUCT *rqptr) { /*********/ /* begin */ /*********/ if (WATCH_MODULE(WATCH_MOD__OTHER)) WatchThis (NULL, FI_LI, WATCH_MOD__OTHER, "LoggingCustomTimeout()"); rqptr->ServicePtr->LogTimeoutEvents = true; switch (rqptr->rqTmr.TimeoutType) { case TIMEOUT_INPUT : return ("input"); case TIMEOUT_NONE : return (NULL); case TIMEOUT_NOPROGRESS : return ("no-progress"); case TIMEOUT_OUTPUT : return ("output"); case TIMEOUT_PERSISTENT : return ("persistent"); case TIMEOUT_THROTTLE : return ("throttle"); default : return ("bugcheck"); } } /*****************************************************************************/ /* Insert an empty line into the server access log (visual aid). */ void LoggingBlankLine (SERVICE_STRUCT *svptr) { int status; /*********/ /* begin */ /*********/ if (!LoggingEnabled) return; if (svptr->LogFormatPtr && strstr(svptr->LogFormatPtr,"XX:blb")) { svptr->LogFileRab.rab$l_rbf = "\n"; svptr->LogFileRab.rab$w_rsz = 1; if (VMSnok (status = sys$put (&svptr->LogFileRab, 0, 0))) ErrorNoticed (NULL, status, NULL, FI_LI); } } /*****************************************************************************/ /* Some log entry fields are quoted. Ensure any raw quotes in the data to be put inside those quotes are URI-encoded. If no raw quotes then return a poointer to the original string. If to be encoded allocate dynamic storage, do the encoding into that, and return a pointer to that storage. */ char* LoggingQuoted ( REQUEST_STRUCT *rqptr, char *StringPtr ) { int qcnt; char *aptr, *cptr, *sptr; /*********/ /* begin */ /*********/ if (WATCH_MODULE(WATCH_MOD__OTHER)) WatchThis (WATCHALL, WATCH_MOD__OTHER, "LoggingQuoted()"); for (cptr = StringPtr; *cptr && *cptr != '\"'; cptr++); /* the overwhelming majority will return from here */ if (!*cptr) return (StringPtr); qcnt = 1; for (cptr++; *cptr; cptr++) if (*cptr == '\"') qcnt++; aptr = sptr = VmGetHeap (rqptr, (cptr - StringPtr) + (qcnt * 2)); for (cptr = StringPtr; *cptr; cptr++) { if (*cptr == '\"') { *sptr++ = '%'; *sptr++ = '2'; *sptr++ = '2'; } else *sptr++ = *cptr; } return (aptr); } /*****************************************************************************/ /* "RH:field-name:" returns a pointer to the start of the specified field name value, or pointer to an empty string if not found, or NULL if a directive format error was detected. This is a reasonably expensive search and logging directive! */ char* LoggingRequestHeader ( REQUEST_STRUCT *rqptr, char *DirectivePtr ) { int NameLength; char *cptr, *sptr, *zptr; char FieldName [256]; DICT_ENTRY_STRUCT *denptr; /*********/ /* begin */ /*********/ if (WATCH_MODULE(WATCH_MOD__OTHER)) WatchThis (WATCHALL, WATCH_MOD__OTHER, "LoggingRequestHeader()"); cptr = DirectivePtr + 2; if (*cptr != ':') return (NULL); zptr = (sptr = FieldName) + sizeof(FieldName)-1; for (cptr++; *cptr && *cptr != ':' && sptr < zptr; *sptr++ = *cptr++); if (*cptr != ':') return (NULL); *sptr = '\0'; NameLength = sptr - FieldName; if (denptr = DictLookup (rqptr->rqDictPtr, DICT_TYPE_REQUEST, FieldName, NameLength)) return (DICT_GET_VALUE(denptr)); /* not found */ return (""); } /*****************************************************************************/ /* Fills 'WeeklyTime7Ptr' with the date of the most recent 'LoggingDayWeekBegins' (i.e. the last Monday, Tuesday ... Sunday) */ LoggingWeek ( int64 *Time64Ptr, ushort *Time7Ptr, ushort *WeeklyTime7Ptr ) { static int64 DeltaDaysTime64, ResultTime64; static $DESCRIPTOR (DeltaDaysFaoDsc, "!UL 00:00:00.00"); int status, DeltaDays; ushort slen; char DeltaString [32]; $DESCRIPTOR (DeltaStringDsc, DeltaString); /*********/ /* begin */ /*********/ if (WATCH_MODULE(WATCH_MOD__OTHER)) WatchThis (WATCHALL, WATCH_MOD__OTHER, "LoggingWeek()"); /* monday == 1, tuesday == 2 ... sunday == 7 */ if ((DeltaDays = HttpdDayOfWeek - LoggingDayWeekBegins) < 0) DeltaDays += 7; if (!DeltaDays) { /* same bat-time, same bat-channel */ memcpy (WeeklyTime7Ptr, Time7Ptr, sizeof(ushort)*7); return; } status = sys$fao (&DeltaDaysFaoDsc, &slen, &DeltaStringDsc, DeltaDays); if (VMSnok (status)) ErrorExitVmsStatus (status, NULL, FI_LI); DeltaStringDsc.dsc$w_length = slen; status = sys$bintim (&DeltaStringDsc, &DeltaDaysTime64); if (VMSnok (status)) ErrorExitVmsStatus (status, NULL, FI_LI); ResultTime64 = *(INT64PTR)Time64Ptr + DeltaDaysTime64; /* overwrite the supplied numeric time with the start of week's */ sys$numtim (WeeklyTime7Ptr, &ResultTime64); } /*****************************************************************************/ /* Return a plain text report comprising access records in the last 65kBytes (maximum) of the log associated with the specified service. Not asynchronous but fast (and convenient) enough not to introduce too much granularity. */ LoggingReport ( REQUEST_STRUCT *rqptr, char *ServerHostPort ) { int cnt, status, BufferBlockCount; char *cptr, *zptr, *BufferPtr; struct FAB LogFileFab; struct RAB LogFileRab; struct XABFHC LogFileXabFhc; SERVICE_STRUCT *svptr; /*********/ /* begin */ /*********/ if (WATCH_MODULE(WATCH_MOD__OTHER)) WatchThis (WATCHALL, WATCH_MOD__OTHER, "LoggingReport() !&Z", ServerHostPort); LIST_ITERATE (svptr, &ServiceList) if (strsame (svptr->ServerHostPort, ServerHostPort, -1)) break; if (!svptr) { rqptr->rqResponse.HttpStatus = 404; ErrorGeneral (rqptr, "Service not found.", FI_LI); AdminEnd (rqptr); return; } if (!LoggingPerService) svptr = LIST_GET_HEAD(&ServiceList); if (!svptr->LogFileNameLength) { rqptr->rqResponse.HttpStatus = 404; ErrorGeneral (rqptr, "Log file not defined.", FI_LI); AdminEnd (rqptr); return; } /* make sure we get all the latest access records */ if (svptr->LogFileOpen) sys$flush (&svptr->LogFileRab, 0, 0); LogFileFab = cc$rms_fab; LogFileFab.fab$l_dna = LoggingFileName; LogFileFab.fab$b_dns = LoggingFileNameLength; LogFileFab.fab$l_fna = svptr->LogFileName; LogFileFab.fab$b_fns = svptr->LogFileNameLength; LogFileFab.fab$b_fac = FAB$M_GET | FAB$M_BIO; LogFileFab.fab$b_shr = FAB$M_SHRGET | FAB$M_SHRPUT | FAB$M_UPI; LogFileFab.fab$l_xab = &LogFileXabFhc; LogFileXabFhc = cc$rms_xabfhc; sys$setprv (1, &SysPrvMask, 0, 0); status = sys$open (&LogFileFab, 0, 0); sys$setprv (0, &SysPrvMask, 0, 0); if (VMSok (status)) status = LogFileFab.fab$l_sts; if (VMSnok (status)) { rqptr->rqResponse.ErrorTextPtr = svptr->LogFileName; ErrorVmsStatus (rqptr, status, FI_LI); AdminEnd (rqptr); return; } if (LogFileXabFhc.xab$l_ebk > 127) BufferBlockCount = 127; else BufferBlockCount = LogFileXabFhc.xab$l_ebk; BufferPtr = VmGetHeap (rqptr, BufferBlockCount * 512); LogFileRab = cc$rms_rab; if (BufferBlockCount >= LogFileXabFhc.xab$l_ebk) LogFileRab.rab$l_bkt = 1; else LogFileRab.rab$l_bkt = LogFileXabFhc.xab$l_ebk - BufferBlockCount + 1; LogFileRab.rab$l_fab = &LogFileFab; LogFileRab.rab$l_rop = RAB$M_BIO; LogFileRab.rab$l_ubf = BufferPtr; LogFileRab.rab$w_usz = BufferBlockCount * 512; if (WATCH_MODULE(WATCH_MOD__OTHER)) WatchThis (WATCHALL, WATCH_MOD__OTHER, "XABFHC ebk:!UL ffb:!UL bkt:!UL usz:!UL", LogFileXabFhc.xab$l_ebk, LogFileXabFhc.xab$w_ffb, LogFileRab.rab$l_bkt, LogFileRab.rab$w_usz); status = sys$connect (&LogFileRab, 0, 0); if (VMSok (status)) status = LogFileRab.rab$l_sts; if (VMSnok (status)) { rqptr->rqResponse.ErrorTextPtr = svptr->LogFileName; ErrorVmsStatus (rqptr, status, FI_LI); sys$close (&LogFileFab, 0, 0); AdminEnd (rqptr); return; } status = sys$read (&LogFileRab, 0, 0); if (VMSok (status)) status = LogFileRab.rab$l_sts; if (status == RMS$_EOF) status = SS$_NORMAL; if (VMSnok (status)) { rqptr->rqResponse.ErrorTextPtr = svptr->LogFileName; ErrorVmsStatus (rqptr, status, FI_LI); sys$close (&LogFileFab, 0, 0); AdminEnd (rqptr); return; } status = sys$close (&LogFileFab, 0, 0); if (VMSok (status)) status = LogFileFab.fab$l_sts; if (VMSnok (status)) { rqptr->rqResponse.ErrorTextPtr = svptr->LogFileName; ErrorVmsStatus (rqptr, status, FI_LI); AdminEnd (rqptr); return; } /* whole records only (quite likely to straddle a block boundary) */ zptr = (cptr = BufferPtr) + LogFileRab.rab$w_rsz; while (cptr < zptr && *cptr != '\n') cptr++; cptr++; /* if empty or only the one record */ if (cptr >= zptr) cptr = BufferPtr; cnt = LogFileRab.rab$w_rsz - (cptr - BufferPtr); rqptr->rqResponse.PreExpired = PRE_EXPIRE_ADMIN; ResponseHeader200 (rqptr, "text/plain", NULL); if (cnt) NetWrite (rqptr, AdminEnd, cptr, cnt); else AdminEnd (rqptr); } /*****************************************************************************/