The WASD server process log, not to be confused with access logs, is the sink
of all sorts of HTTPd run-time data.
It is a timestamped file name created with each server process startup, so
can persist for the lifetime of the process, and record output from multiple
server image startups whether explicitly (e.g. $ httpd/do=restart=now)
%HTTPD-I-IMAGE, HTTPD_SSL 12.3.4 20-OCT-2025 03:51:14.38
↩$10$DKD1:[WASD_ROOT.][IA64]HTTPD_SSL.EXE **
%HTTPD-I-STARTUP, 20-OCT-2025 21:46:44
or implicitly by VMS (from my development bench,
though also can be seen in the wild :-)
%SYSTEM-F-ACCVIO, access violation, reason mask=04, virtual address=0000000000000000,
↩PC=0000000080146503, PS=0000001B **
Improperly handled condition, image exit forced.
Signal arguments: Number = 0000000000000005
** Overly long lines are '↩' wrapped
Single Log File
~~~~~~~~~~~~~~~
Why not a separate error log file (à la Apache)?
Largely for historical reasons. Although it is intended to provide
human-interpretable, non-fixed format data, catching all manner of explicit
events (those detected and reported by the executing server), and events
implicit to the process context (those reported by VMS to SYS$OUTPUT).
Server-detected Events
~~~~~~~~~~~~~~~~~~~~~~
• general (e.g. startup) messages
%HTTPD-I-SOFTWAREID, HTTPd-WASD/12.3.4 OpenVMS/IA64 SSL
WASD VMS Web Services, Copyright (C) 1996-2024 Mark G.Daniel.
Licensed under the Apache License, Version 2.0 (the "License").
Software under the License is distributed on an "AS IS" BASIS,
WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
See http://www.apache.org/licenses/LICENSE-2.0
%HTTPD-I-IMAGE, HTTPD_SSL 12.3.4 20-OCT-2025 03:51:14.38 $10$DKD1:[WASD_ROOT.][IA64]HTTPD_SSL.EXE
%HTTPD-I-STARTUP, 25-OCT-2025 21:46:44
%HTTPD-I-ALIGN, start collecting alignment faults (64kB,128,0xFFFFFFFF)
%HTTPD-I-WASD_ROOT, $10$DKD1:[WASD_ROOT]
%HTTPD-I-ENVIRONMENT, 1
%HTTPD-I-SYSTEM, HP rx2660 (1.40GHz/6.0MB) VMS V8.4-2L3
%HTTPD-I-BUILD, 19-OCT-2025 18:06:30.89 VMS 8.4-2L3 DECC 70490001 WASD_VMS_V0
%HTTPD-I-TCPIP, Multinet UCX$IPC_SHR V56A-001 (03-APR-2025 11:02:48.23)
8< snip 8<
%HTTPD-I-DURATION, 00:00:08.91
%HTTPD-I-BEGIN, 25-OCT-2025 21:46:53, WASD:80 accepting requests
• server control messages
%HTTPD-I-CONTROL, 30-SEP-2025 15:10:23, 0000042E X86VMS SYSTEM "FTA2_SYSTEM", 'restart=now'
%HTTPD-I-EXIT, 30-SEP-2025 15:10:23, WASD:80 %X00000001
-SYSTEM-S-NORMAL, normal successful completion
AST:3977/4000 BIO:15988/16000 BYT:49864640/49999296 DIO:3997/4000 ENQ:473/500 FIL:496/500
↩PGFL:444448/512000 PRC:0/100 TQ:98/100
• request provides a header with illegal syntax
%HTTPD-W-NOTICED, 25-OCT-2025 22:32:24, HTTP/1, REQUEST:2711, CHAR \x03 at 0 of 47
-NOTICED-I-SERVICE, http://haven.xxx.xxx.xxx:80
-NOTICED-I-CLIENT, 91.238.181.92
-NOTICED-I-HTTP, 1
-NOTICED-I-RXTX, err:0/0 raw:47/0 net:47/0
0300002F 2AE00000 00000043 6F6F6B69 653A206D 73747368 6173683D 41646D69 .../*......Cookie: mstshash=Admi
6E697374 720D0A01 00080003 000000 nistr..........
%HTTPD-W-NOTICED, 20-OCT-2025 23:20:50, HTTP/1, REQUEST:2711, CHAR \x00 at 6 of 173
-NOTICED-I-SERVICE, http://www.xxx.xxx.xxx:80
-NOTICED-I-CLIENT, 66.240.205.34
-NOTICED-I-HTTP, 1
-NOTICED-I-RXTX, err:0/0 raw:173/0 net:173/0
47683073 74AD0000 00E00000 00789C4B 53606098 C3C0C0C0 06C48C40 BC519681 Gh0st........x.KS``........@.Q.. <=
81094807 A7169565 26A72A04 2426672B 183294F6 B03030AC A8726300 0111A082 ..H....e&.*.$&g+.2...00..rc.....
1F5C6026 83C74B37 8619E56E 0C39956E 0C3B840F 33ACE873 6368A85E CF34274A .\`&..K7...n.9.n.;..3..sch.^.4'J
97A982E3 30C39168 5D2690F8 CE9753CB 41344C3F 323DE1C4 92860B40 F5600C54 ....0..h]&....S.A4L?2=.....@.`.T
1FAEAF5D 0A720B03 23A3DC02 7E068603 2B186DC2 3DFD7443 2C43FD4C 3C3C3D3D ...].r..#...~...+.m.=.tC,C.L<<==
5C9D1988 00E52002 0054F52B 5C \..... ..T.+\
• script provides an unexpected response (i.e. non-CGI)
%HTTPD-W-NOTICED, 20-OCT-2025 10:10:12, HTTP/1, CGI:2323, not a strict CGI response
-NOTICED-I-SERVICE, https://www.saflyfishers.xxx.xxx:443
-NOTICED-I-CLIENT, 45.235.119.120
-NOTICED-I-HTTP, 1
-NOTICED-I-URI, GET (63 bytes) /phpbb3/ucp.php?mode=terms&sid=dd1cdc3f8591ac24877289271c91ca5c
-NOTICED-I-SCRIPT, /phpbb3/ucp.php saffa_root:[phpbb3]ucp.php ($cgi-bin:[000000]phpwasd.exe)
↩SAFFA_ROOT:[phpBB3]ucp.php
-NOTICED-I-CGI, 4F7574206F66206D656D6F72790D0A (15 bytes) Out of memory..
-NOTICED-I-RXTX, err:0/0 raw:934/0 net:315/0
%HTTPD-W-NOTICED, 19-AUG-2025 15:24:20, HTTP/1, CGI:2322, not a strict CGI response
-NOTICED-I-SERVICE, http://x86vms.lan:80
-NOTICED-I-CLIENT, 212.bl.bot.semrush.com (85.208.96.212)
-NOTICED-I-HTTP, 1
-NOTICED-I-URI, GET (132 bytes) /cgiplus-bin/conan/sys$common/syshlp/krb$user_help.hlb?
↩key=me&referer&title=Library%20%2Fsys%24common%2Fsyshlp%2Fkrb%24user_help.hlb
-NOTICED-I-SCRIPT, /cgiplus-bin/conan CGI-BIN:[000000]CONAN () CGI-BIN:[000000]conan.com
-NOTICED-I-CGI, 2553595354454D2D462D41434356494F2C20616363657373 (118 bytes)
%SYSTEM-F-ACCVIO, access violation, reason mask=05, virtual address=000000007ACDE000,
↩PC=FFFF830006BCB2CB, PS=0000001B
-NOTICED-I-RXTX, err:0/0 raw:423/0 net:423/0
• notable conditions
%HTTPD-W-NOTICED, 07-SEP-2025 06:54:17, WATCH:3840, <=30%:BYT; AST:3779/4000
↩BIO:3787/4000 BYT:1405312/4999424 DIO:1996/2000 ENQ:935/1000 FIL:382/400
↩PGFL:289152/500000 PRC:0/100 TQ:498/500 %X00000018
-SYSTEM-W-EXQUOTA, process quota exceeded
This one indicates a quota has reached a threshold value (30% or logical name
WASD_ALERT_QUOTAS), in this case BYTLM triggered the report, with all quotas
listing their current value following. This is also indicated on the Server
Admin main page as a red alert "07-SEP 06:54 <=30%:BYT".
• miscellaneous notes of interest
%HTTPD-I-REJECT, 19-OCT-2025 19:37:47, 2, *.amazonbot.* 52-54-15-103.crawl.amazonbot.amazon
↩52.54.15.103 www.xxx.xxx.xxx:80
%HTTPD-I-REJECT, 19-OCT-2025 19:43:40, 2, 418 ec2-47-128-97-124.ap-southeast-1.compute.amazonaws.com
↩47.128.97.124 www.sherlock.xxx.xxx:80
%HTTPD-I-REJECT, 19-OCT-2025 19:55:33, 1, *.ru 95-24-169-87.broadband.corbina.ru
↩95.24.169.87 mail.xxx.xxx.xxx:443
%HTTPD-I-REJECT, 19-OCT-2025 20:14:00, 3, *.yandex.com 87-250-224-5.spider.yandex.com
↩87.250.224.5 www.xxx.xxx.xxx:80
%HTTPD-I-REJECT, 19-OCT-2025 20:20:02, 3, *.ru 145.255.22.154.dynamic.o56.ru
↩145.255.22.154 mail.xxx.xxx.xxx:443
%HTTPD-I-REJECT, 19-OCT-2025 20:30:19, 2, *.yandex.com 95-108-213-123.spider.yandex.com
↩95.108.213.123 www.xxx.xxx.xxx:80
%HTTPD-I-REJECT, 19-OCT-2025 20:30:56, 5, *.ru 176.125.23.31.donpac.ru
↩31.23.125.176 mail.xxx.xxx.xxx:443
• classic unrecoverable condition
%SYSTEM-F-ACCVIO, access violation, reason mask=04, virtual address=0000000000000000,
↩PC=0000000080146503, PS=0000001B
Improperly handled condition, image exit forced.
Signal arguments: Number = 0000000000000005
Name = 000000000000000C
0000000000000004
0000000000000000
0000000080146503
000000000000001B
Register dump:
RAX = 0000000000526DBC RDI = 0000000000526DF0 RSI = 0000000000000000
RDX = 0000000000526E0F RCX = 0000000000526DF0 R8 = 000000000000001B
R9 = 000000000016CB10 RBX = 0000000000526290 RBP = 000000007ACE26C0
R10 = 000000007ACE27E0 R11 = FFFFFFFF8AC0451E R12 = 000000020B9090A7
R13 = 0000000000000018 R14 = 0000000000000000 R15 = 0000000000526290
RIP = 0000000080146503 RSP = 000000007ACE2660 SS = 000000000000001B
%HTTPD-F-EXIT, 30-JUN-2024 08:31:59, WASD:80 %X1000000C
-HTTPD-F-TRACE, FFFF8300079CE445
-HTTPD-F-TRACE, FFFF8300081FBF0F
8< snip 8<
-HTTPD-F-TRACE, FFFF83000990B2DD
-HTTPD-F-TRACE, FFFF8300098CC317
C001 37 https://x86vms.xxx.xxx:443 connected HTTP/0 30-JUN-2024 08:31:56.06 3.470s 0(0) 0(0)
↩crawl-66-249-66-205.googlebot.com [null] 000
C002 26 https://x86vms.xxx.xxx:443 persist HTTP/0 30-JUN-2024 08:30:59.09 00:01:00 0(0) 0(0)
↩crawl-66-249-66-205.googlebot.com [persistent:2] 000
8< snip 8<
H006 8 https://x86vms.xxx.xxx:443 ending HTTP/2 30-JUN-2024 08:29:16.74 10.0ms 135 974
↩proxy-ca003-ext2.a.ahrefs.com GET /wasdoc/html_clean.com?httpd=content&type=text/plain 200
H007 1 https://x86vms.xxx.xxx:443 ending HTTP/1 30-JUN-2024 08:28:53.19 320ms 1188 6814
↩crawl-66-249-66-205.googlebot.com GET /cgiplus-bin/conan?key=Sys_Parameters~DEFMBXMXMSG&title=VMS
-HTTPD-F-ADIEU, ...
If you haven't seen something like this over the years you're doing very well!
VMS-detected Events
~~~~~~~~~~~~~~~~~~~
No point in trying to continue if you can't deliver asynchronously ...
%SYSTEM-F-EXASTLM, exceeded AST quota
𝑏𝑜𝑜𝑚! or perhaps more accurately 𝑤𝘩𝑒𝑒𝑧𝑒...
$ HTTPD /PRIORITY=4 /SYSUAF=(ID,SSL,PROXY) /PERSONA=RELAXED /PROFILE
%HTTPD-I-SOFTWAREID, HTTPd-WASD/12.3.2 OpenVMS/X86 SSL
Accessing Process Logs
~~~~~~~~~~~~~~~~~~~~~~
At the command-line using
$ directory wasd_server_logs:*.log
$ directory wasd_server_logs:<server-name>_*.log
$ directory wasd_server_logs:*.log /since=<date-time>
$ search wasd_server_logs:*.log /since=<date-time> "<whatever>"
etc.
Without a server-name it may also pick up other log files (e.g. wuCME).
Using the Server Admin menu
```````````````````````````
https://wasd.vsm.com.au/wasd_root/wasdoc/features/admin.png
in the top-left | Report | column there is a〔Log∇ϟ⁞⁞〕button. It
has one 'Log' and three other action icons, '∇', 'ϟ' and '⁞⁞'.
The 'Log' section opens the current server log as plain-text.
The '∇' icon opens the current log in "filter" mode, where only non-error,
non-warning text in the log file displayed, with excluded content "8< snipped 8<".
The 'ϟ' icon (Greek koppa character, which I mistook for a lightning symbol :-)
opens the log in "noticed" mode, showing all errors, warnings, etc., with
excluded content "8< snipped 8<".
The '⁞⁞' icon lists all files in the WASD_SERVER_LOGS directory, allowing
individual (and historical) files to be selected and displayed.
Using these non-filtered and filtered listings makes it simpler to evaluate
server events.
This item is one of a collection at
https://wasd.vsm.com.au/other/#occasional
|