TL;DR (again) Process dumping ensured by reserving two channels.
Connection limit reached now defers further accepts.
New tool; programmatic WatchNow() and /DO=WATCH=NOW.
One particular site I have access to, and allowed to use for beta testing,
experienced another in a series of mysterious failures beginning fifteen
months before. This has not been reported by any other site. These
seemingly occurred at random periods but all had the same exit fingerprint
%HTTPD-F-SOFTWAREID, HTTPd-WASD/12.4.1 OpenVMS/AXP SSL
-HTTPD-F-WHEN, 21-APR-2026 09:53:31.60
-HTTPD-F-WHERE, module:NETIO line:216
-HTTPD-F-WHAT, sys$assign()
%HTTPD-F-EXIT, 21-APR-2026 09:53:32, WASD:80 %X000001B4
AST:2995/4000 BIO:3015/4000 BYT:1526016/4999424 DIO:1999/2000 ENQ:967/1000
↵FIL:593/600 PGFL:199536/500000 PRC:0/100 TQ:993/1000
%SYSTEM-F-NOIOCHAN, no I/O channel available
The referenced code point is within network connection acceptance routines,
where a client network connection has been accepted and has begun request
processing and another socket is created and the next accept queued. The
essence of this processing ...
$DESCRIPTOR (TcpIpDeviceDsc, "UCX$DEVICE");
status = sys$assign (&TcpIpDeviceDsc, &channel, 0, 0);
if (VMSnok (status)) ErrorExitVmsStatus (status, "sys$assign()", FI_LI);
/* queue an accept to the listening socket */
qiofun = IO$_ACCESS | IO$M_ACCEPT;
status = sys$qio (EfnNoWait, svptr->ServerChannel,
qiofun, &ioptr->AcceptIOsb, &NetAcceptAst, ioptr,
0, 0, &clptr->SocketNameItem,
&ioptr->Channel, &TcpIpFullDuplexCloseOption, 0);
WASD considers not being able to assign a channel as required a fatal error
with the best remedy to run down the image.
One consideration with WASD reporting 503 (Service Unavailable, e.g. too
busy) to a client is the connection needs to be accepted and begin processing
before being closed after the 503. Can result in quite a churn.
Initial Response
~~~~~~~~~~~~~~~~
Was of course to bump up the channel count available to processes. Not being
a very busy site with more file serving than script processing the SYSGEN
channel count was set rather low. So it was doubled and the system rebooted
(annoying the system manager :-)
Before long it barfed again with the same fingerprint.
So it was doubled again, reaching 2048 where it stabilised. For a while.
Analysis
~~~~~~~~
I had on occasion used ANALYZE/SYSTEM to check the server process' used
channels. The usual suspects were listed, with the final line being
Total number of open channels : nn.
in a range of 60 to 75 channels. Obviously the channel count was not always
within that range. Of course the indeterminate nature of the failure meant
consumed channels need to be tracked. Sadly (and a notable deficiency) there
are no JPI$_CHNLM and JPI$_CHNCNT items to be interrogated.
At that point I needed some experienced input and posted
https://forum.vmssoftware.com/viewtopic.php?f=9&t=9753
querying how TCP/IP Services manages channel allocation, how to interrogate
it, and whether it is tweak-able. Not being an internals person, I learned
that channels are always allocated from the process' own pool.
This meant I needed a method to track process channel consumption. A lame
effort by myself to log the "number of open channels" using DCL soon gave way
to a far more elegant programmatic approach.
https://forum.vmssoftware.com/viewtopic.php?f=9&t=9753&start=10...
The essentials were integrated into WASD and server process channel
monitoring ensued. Server Statistics quota reporting was revised from
remaining / limit (used%)
to the more intuitive and expanded
current-in-use / maximum-in-use / limit (current%/maximum%)
with an additional (well, substituted) CHAN: item.
Server exit quota reporting now includes the revised data.
AST:133/174/4000 BIO:50/101/16000 BYT:2708992/2775232/500000000
↵CHAN:270/276/512 DIO:39/39/4000 ENQ:36/85/500 FIL:5/21/500
↵PGFL:72848/5000000 PRC:100/100/100 TQ:2/2/500
HTTPDMON has been modified to include channel consumption.
Very quickly the Server Statistics new item "CHAN: 62 / 75 / 2048 (3/3%)"
jumped to "CHAN: 69 / 1492 / 2048 (3/73%)", the 1492 value seemingly
associated with a recently recorded significant spike in the Server Activity
graph. Aggressive harvesters at work. An early suspicion.
This system had a Connect Max: 200 value, meaning 1492 suggested a LOT of
connected/to-be-busied/persistent/http2 idle connections. And really quite
close to the NOIOCHAN hard limit of 2048. But required a longer wait and ...
Further Analysis
~~~~~~~~~~~~~~~~
Many days later I scored a NOIOCHAN and a process dump (see Epilogue below).
The dump certainly showed all (but two) channels in use, most of those
assigned to network (BG) devices. Apart from this it was of little use.
Quotas all Ok. Hmmm. Looks like another tool was required, one that
provided an insight to server processing. Fortunately there is WATCH!
The indeterminate frequency of the NOIOCHAN meant a programmatic WATCH was
necessary, able to be triggered when a condition was present, in this case
such as when 80% of channels consumed (reminder; normal processing is 3-4%).
Therefore, strategically placed in NetIoBegin()
if (MATCH7 (SysInfo.NodeName, "XXXXXX\0"))
{
/**************************************/
/* temporary for XXXXXX investigation */
/**************************************/
HttpdGetChannelInUse();
if (HttpdChannelInUse > HttpdChannel80Use)
WatchNow ("1555,16384");
else
if (HttpdChannelInUse < HttpdChannel80Use)
WatchNow ("");
}
where the "1555,16384" represents the WATCH 'category,module' integer values
to enable the WATCH (and module) items. A bit specialised but when internal
data are required.
The resulting data showed largely what was expected; an overwhelming
succession of connect, queuing of next accept, connect, queuing of next
accept, connect ... interleaved with some request processing.
Remediation
~~~~~~~~~~~
1) Of course we can just keep bumping CHANNELCNT until the issue is no more.
However, aggressive connections are a drain on system resources. Best try to
address the root cause.
2) One approach would be just to drop busy connections. Of course as a
matter of server behaviour this is an extremely impolite way to do business.
3) Another approach considered was to defer queuing connection acceptance
once the busy limit is reached.
4) Yet another considered was to purge a portion of idle connections once
busy was reported. Pruning older idle connections would proactively free up
connection resources.
In the end a combination of 3) and 4) was adopted.
If the busy limit is exceeded connection acceptance is deferred.
At the same time (up to) 20% older idle connections are pruned.
Every second, if no longer exceeding the busy limit, connection accepts are
queued, up until the busy limit. A round-robin of services ensures each will
get a share of the renewed connection accepts.
Summary
~~~~~~~
The site with the modified 503 and process dump code has now been up for 28
days, a recent record, with a server process log reported
%HTTPD-W-BUSY, 15-JUN-2026 15:10:43, 10 connections purged
This suggests the deferred connect accept strategy is working. Of course
having only the one 503 event may also indicate that harvesters currently
have their attention elsewhere.
Epilogue
~~~~~~~~
Though the WASD server startup includes a SET PROCESS/DUMP there were no .DMP
files associated with these error exits. Turns out a process cannot dump
without available channels. NOIOCHAN means no dump. The solution is to
reserve channels during startup which are de-assigned during server exit,
ensuring required channels.
https://forum.vmssoftware.com/viewtopic.php?f=9&t=9753&start=20...
Server Admin page will also now alert when there are .DMP files present.
(I discovered a swag of process dump files on my development system
stretching way back :-)
These changes will be available with the next server release.
Thanks to all Forum contributors. You are a valuable resource.
This item is one of a collection at
https://wasd.vsm.com.au/other/#occasional
|