Chapter 12. Troubleshooting

This chapter lists what goes wrong in the order in which you meet it. First the server does not start. Then it starts, but not as the Parmlib member says. Then a client gets no answer, or an answer with the wrong status. Last, a module fails, or a response is slow. Each entry has the symptom, the cause and the cure.

The causes come from the messages and from the behaviour of the server. The HTTPD Reference has them in full: “Messages” lists every message, “Routes and Authentication Policy” lists what each login mode answers, and “HTTP Behaviour and Limits” lists the status codes. This chapter points to them by title.

The console screens and client sessions in this chapter were captured on a test system. The user id is IBMUSER, the host is localhost, and the addresses in the console lines are test addresses.

Where to Look First

Two places tell you what is wrong.

The console. HTTPD writes a message for what an operator can act on. Every message has an id of the form HTTPDnnnX. The last letter is I, W or E for information, warning or error. The letter does not tell you whether the server stops. HTTPD023E and HTTPD026E are errors that let the server start. The Reference lists, for every message, what the server does afterwards. Every message that goes to the console also goes into the Master Trace Table of the system. “Reading the Master Trace Table” shows how to read it without a TSO session.

The response. A request that a client got wrong is answered with a status and a text of one line. It does not go to the console. A wrong password, for example, is not written to the console by HTTPD. So read the status line that the client got, and use curl -i to see it.

The next table sends you to the right section.

Symptom	Section
The job ends and `HTTPD001I` never appears	“A Start That Ends”
The server starts, but the port, the routes or the limits are not the ones in the member	“The Start Goes On, but Not as Intended”
The client cannot connect, or the connection closes without an answer	“The Client Cannot Connect”
The client gets 302, 400, 401, 403, 404, 405, 413, 414, 501 or 505	“The Status Is Not 200”
A user cannot log in, or a changed password has no effect	“Logins”
The client gets 503, or a module works on one system and abends on another	“A Module Does Not Run”
A response of a module takes about five seconds	“A Response Takes Five Seconds”
Requests wait, or a worker abends	“Requests Wait or Workers Abend”
One request takes long, and you want to know where the time goes	“A Request Is Slow”

Table 38. From the symptom to the section

A Start That Ends

A healthy start ends with HTTPD001I ... READY (see Chapter 8, “Operating HTTPD”). Some messages end the start before that. For most of them the server then writes HTTPD098I HTTPD SHUTTING DOWN, HTTPD416I with the statistics and HTTPD099I HTTPD SHUTDOWN COMPLETE, and the step ends with return code 8. The message that names the cause comes before these three. In “A Start That Ends” in “Messages”, the Reference lists all of them.

Message	RC	Cause and cure
`HTTPD037E`	8	Another HTTPD holds the port (“The Port Is Busy”). Stop it, or use another port.
`HTTPD030E`	8	The bind to the port failed (“The Port Is Busy”).
`HTTPD028E`, `HTTPD031E`	8	The call to create the socket or to listen failed. The message shows the return code and the error number of the call.
`HTTPD038E`	8	The server opened the member of the Parmlib and could not read it to the end. Check the data set of the DD `HTTPPRM` and start again.
`HTTPD411E`, `HTTPD419E`, `HTTPD420E`, `HTTPD048E`, `HTTPD427E`	8	A route has no valid policy, or the value of `RES_NOPROFILE` is not valid (“A Route Without a Valid Policy”).
`HTTPD033E`, `HTTPD064E`	8	The socket thread could not be created, or it is not running.
`HTTPD090E`	8	The server could not set up the console interface. It stops at once, and no stop message follows.
`HTTPD014E` to `HTTPD019W`	12	A DD name that the procedure must not have is there, or a DD of the server is missing (“The Procedure Has the Wrong DD Names”). The program ends before the banner.
`HTTPD012E`		The server could not obtain its authorization (“Authorization Fails”). The step ends with the return code of the failed call.

Table 39. The messages that end the start

The Port Is Busy

Symptom. The operator starts a second server, or restarts the first one, and the start ends.

The server takes a lock on the port before it binds. The lock is named HTTPD.PORT.nnnnn, where nnnnn is the port with five digits. When another HTTPD address space holds it, the server writes HTTPD037E and ends at once. It does not try again. A second server on a different port starts. This is the Parmlib member of the second server:

PORT=8081
BIND_TRIES=2
BIND_SLEEP=2
DOCROOT=/www
MOD=MVSMF /zosmf/*  AUTH=TOKEN

The first server serves the port 8081 already. This is the start of the second:

S HTTPD,M=PRMPORT
$HASP100 HTTPD    ON STCINRDR
$HASP373 HTTPD    STARTED
IEF403I HTTPD - STARTED - TIME=05.31.14
HTTPD000I HTTPD 4.5.1 (nnnnnnn) STARTING
HTTPD005I LIBC370 2.26.0 (3AA3B28)
HTTPD002I AUTHORIZED BY SVC (MODULE KEY 8)
HTTPD004I STC IDENTITY SET TO HTTPD/USER VIA RACINIT
RAKF0004 INVALID ATTEMPT TO ACCESS SYSTEM:  USER:HTTPPRB
HTTPD036I MODULE MVSMF REGISTERED FOR /zosmf/*
HTTPD037E HTTPD IS ALREADY ACTIVE ON PORT 8081, THIS INSTANCE ENDS
HTTPD098I HTTPD SHUTTING DOWN
HTTPD416I STATS: 0 REQUESTS, 0 ERRORS, 0 BYTES
HTTPD099I HTTPD SHUTDOWN COMPLETE
IEF404I HTTPD - ENDED - TIME=05.31.14
$HASP395 HTTPD    ENDED

Read the capture from the top. The server logged on and registered its route (HTTPD036I) before it came to the port. Then HTTPD037E named the port, and the three stop messages followed. The cure is in the message: stop the other server, or give this one another PORT.

When the lock is free and the bind still fails, the server writes HTTPD030E with the return code and the error number of the call. If the error is EADDRINUSE, for example after a quick restart, the server waits and tries again. Each try gives HTTPD030I EADDRINUSE, WAITING FOR TCPIP TO RELEASE HTTP PORT n. The keywords BIND_TRIES and BIND_SLEEP set the number of tries and the seconds between them. When no try works, the server writes HTTPD030E a second time and the start ends. Any other error of the bind ends the start with the second HTTPD030E and no try. Chapter 4, “Configuring HTTPD” shows how to change the port. “The HTTPPRM Keywords” in the HTTPD Reference has the two keywords and their ranges.

A Route Without a Valid Policy

Symptom. The server writes HTTPD420E ... HTTPD WILL NOT START and ends.

A route that has no AUTH= is public. A route that loses its policy by a mistake would become public, so the server refuses to start instead. Three mistakes cause it. The first is a mode that is not one of the four. This member has a typing error in the mode:

PORT=8080
DOCROOT=/www
LOC=/pub/*  AUTH=BASC

The start ends with three messages:

S HTTPD,M=PRMAUTH
$HASP100 HTTPD    ON STCINRDR
$HASP373 HTTPD    STARTED
IEF403I HTTPD - STARTED - TIME=05.28.50
HTTPD000I HTTPD 4.5.1 (nnnnnnn) STARTING
HTTPD005I LIBC370 2.26.0 (3AA3B28)
HTTPD002I AUTHORIZED BY SVC (MODULE KEY 8)
HTTPD004I STC IDENTITY SET TO HTTPD/USER VIA RACINIT
RAKF0004 INVALID ATTEMPT TO ACCESS SYSTEM:  USER:HTTPPRB
HTTPD411E UNKNOWN AUTH MODE 'BASC' -- USE NONE, FORM, BASIC OR TOKEN
HTTPD419E LOC=/pub/* COULD NOT BE REGISTERED -- ITS AUTH POLICY IS LOST
HTTPD420E ROUTE AUTHORIZATION POLICY INCOMPLETE -- HTTPD WILL NOT START
HTTPD098I HTTPD SHUTTING DOWN
HTTPD416I STATS: 0 REQUESTS, 0 ERRORS, 0 BYTES
HTTPD099I HTTPD SHUTDOWN COMPLETE
IEF404I HTTPD - ENDED - TIME=05.28.50
$HASP395 HTTPD    ENDED

HTTPD411E names the wrong value and the four right ones. HTTPD419E names the route that could not be registered. HTTPD420E is written at the end of the member and ends the start. Write NONE, FORM, BASIC or TOKEN and start again.

The second mistake is the old keyword LOGIN with an operand that asked for a login. The keyword is retired. A member with LOGIN=BASIC would make every route without AUTH= public, so the server stops:

PORT=8080
DOCROOT=/www
LOGIN=BASIC

S HTTPD,M=PRMLOGB
$HASP100 HTTPD    ON STCINRDR
$HASP373 HTTPD    STARTED
IEF403I HTTPD - STARTED - TIME=05.27.44
HTTPD000I HTTPD 4.5.1 (nnnnnnn) STARTING
HTTPD005I LIBC370 2.26.0 (3AA3B28)
HTTPD002I AUTHORIZED BY SVC (MODULE KEY 8)
HTTPD004I STC IDENTITY SET TO HTTPD/USER VIA RACINIT
RAKF0004 INVALID ATTEMPT TO ACCESS SYSTEM:  USER:HTTPPRB
HTTPD048E LOGIN BASIC IS RETIRED -- ROUTES WITHOUT AUTH= WOULD BECOME PUBLIC
HTTPD420E ROUTE AUTHORIZATION POLICY INCOMPLETE -- HTTPD WILL NOT START
HTTPD098I HTTPD SHUTTING DOWN
HTTPD416I STATS: 0 REQUESTS, 0 ERRORS, 0 BYTES
HTTPD099I HTTPD SHUTDOWN COMPLETE
IEF404I HTTPD - ENDED - TIME=05.27.44
$HASP395 HTTPD    ENDED

Remove the LOGIN line and write AUTH= on each route. Chapter 5, “Routes and Server Modules” shows the four modes. A LOGIN line with no operand, or with NONE, gives only the warning HTTPD048W (“The Start Goes On, but Not as Intended”).

The third mistake is a value of RES_NOPROFILE that is neither ALLOW nor DENY. The keyword exists to close a gate. If the server read a misspelled value as ALLOW, the gate would stay open without a word, so it stops. The lines of the member that matter:

RES_NOPROFILE=DENNY
LOC=/pub/*  AUTH=BASIC RES=FACILITY:HTTPD.TESTRES

The start ends with this console, the JES lines left out:

HTTPD000I HTTPD 4.5.1 (nnnnnnn) STARTING
HTTPD005I LIBC370 2.26.0 (3AA3B28)
HTTPD002I AUTHORIZED BY SVC (MODULE KEY 8)
HTTPD004I STC IDENTITY SET TO HTTPD/USER VIA RACINIT
RAKF0004 INVALID ATTEMPT TO ACCESS SYSTEM:  USER:HTTPPRB
HTTPD427E INVALID RES_NOPROFILE VALUE "DENNY" (ALLOW|DENY)
HTTPD417I LOCATION /pub/* REGISTERED
HTTPD420E ROUTE AUTHORIZATION POLICY INCOMPLETE -- HTTPD WILL NOT START
HTTPD098I HTTPD SHUTTING DOWN
HTTPD416I STATS: 0 REQUESTS, 0 ERRORS, 0 BYTES
HTTPD099I HTTPD SHUTDOWN COMPLETE

HTTPD427E shows the value, cut after 16 characters. The text of HTTPD420E is the same for every cause, so the cause is in the message before it. Write ALLOW or DENY and start again.

The Procedure Has the Wrong DD Names

Symptom. A message from HTTPD014E to HTTPD019W appears, there is no banner, and the step ends with return code 12.

The server uses the DD names HTTPDOUT, HTTPDERR and HTTPDIN for its standard streams. The procedure must not have the DD names SYSPRINT, SYSTERM or SYSIN. The routine in front of the server tests for them first, and it ends the program when it finds one (HTTPD014E, HTTPD015E, HTTPD016E). Then it opens the three DDs of the server. A DD that cannot be opened gives HTTPD017W, HTTPD018W or HTTPD019W, and the letter W does not save the start: all six conditions end the program. Compare your procedure with the sample member. The Reference has it in “The Started Task and the Package”.

Authorization Fails

Symptom. The console shows HTTPD012E name UNABLE TO DYNAMICALLY OBTAIN APF AUTHORIZATION first. The banner and the C library line follow, each with a leading plus sign because the step is not authorized, and there is no HTTPD002I. The step ends.

The server needs to be authorized. At the entry it tests whether the step is authorized. If it is not, the server asks for the authorization with SVC 244, and tests again. The message says that the step is still not authorized. The profile SVC244 in the class FACILITY gates the SVC. The account that counts is the one the task has when it starts, before the server logs on as STCUSER. Check the permissions of that account. “Authorization” in “The Started Task and the Package” in the HTTPD Reference describes the call.

When the start works, HTTPD002I tells how the step was authorized.

Message	Meaning
`HTTPD002I AUTHORIZED BY LIBRARY (MODULE KEY 0)`	The step was authorized at the entry, by the APF authorization of its library. The system fetches the modules with the protection key 0.
`HTTPD002I AUTHORIZED BY SVC (MODULE KEY 8)`	The step was not authorized at the entry. The server authorized the task itself. The system fetched the modules with the key 8.

Table 40. The two forms of HTTPD002I

Both forms are a good start. They differ for the modules that the server runs (“A Module Abends with S0C4”). If you expected the first form and got the second, check the APF list for the libraries of the STEPLIB.

The Start Goes On, but Not as Intended

A warning does not stop the start. The server skips the bad line or keeps the default, and goes on. Read the console from the banner down to HTTPD001I after every change of the member. The next table lists the common ones.

Message	Meaning and cure
`HTTPD020W`	The DD `HTTPPRM` cannot be opened. The server starts on its defaults: port 8080, 3 to 9 workers, the document root `/www` and no routes. Add the DD, or correct the member name (“The Member Is Not There”).
`HTTPD023E`	The value of `PORT` is not a number from 1 to The server keeps the earlier value or the default.
`HTTPD026W`	A line is not a comment and has no equals sign. The server skips it.
`HTTPD029W`	The keyword is not known. The server skips the line. A typing error in a keyword gives this message.
`HTTPD026E`, `HTTPD032E`	The idle time or the maximum age of a login is not longer than `CLIENT_TIMEOUT`. The letter is E, but it is a warning. Raise `SESSION_TIMEOUT` or `SESSION_MAXAGE`.
`HTTPD048W`	The retired keyword `LOGIN` has no effect. Remove it and write `AUTH=` on each route.
`HTTPD412W`, `HTTPD413W`, `HTTPD414W`	A route option is malformed (`HTTPD412W`), unknown (`HTTPD413W`), or given on a public route (`HTTPD414W`). The server ignores the option.
`HTTPD425W`	The resource of `RES=` has no profile. The route is served with no gate (“Logins”).
`HTTPD426W`	The same, with `RES_NOPROFILE=DENY` in the member. The route answers every request with 403 until the profile exists (“403, the Resource Is Denied”).
`HTTPD440W`, `HTTPD441W`, `HTTPD442W`	The module of a route could not be held at the start. The route works. The module is fetched for each request (“A Module Does Not Run”).
`HTTPD003W`, `HTTPD004W`	The server could not log on as `STCUSER`. It runs with the identity the task inherited (“Logins”).
`HTTPD042W`	The security product accepts any user ID. The server refuses all logins until it is started again (“Every Login Is Refused, HTTPD042W”).
`HTTPD444W`	The value of `TRACE` is not 0 and not a number from 16 to 1024. The request trace stays off (“The Request Trace”).
`HTTPD067W`	The server could not get the storage for the request trace. It runs without it (“The Request Trace”).
`HTTPD044W`	The server could not create its handle to the file system. It serves no static files (“Static Files Are Not Served”).
`HTTPD047E`	The server could not set up its credential key. Logins do not work.
`HTTPD034W`	The server could not create the worker threads. The routes that run programs are disabled.

Table 41. Messages that let the start go on

The Member Is Not There

Symptom. The server answers on port 8080 although the member says another port, and it has none of your routes.

The start below used the member name NOSUCH on the S command. The server could not open the DD, wrote HTTPD020W, and started on its defaults:

S HTTPD,M=NOSUCH
$HASP100 HTTPD    ON STCINRDR
$HASP373 HTTPD    STARTED
IEF403I HTTPD - STARTED - TIME=05.48.26
HTTPD000I HTTPD 4.5.1 (nnnnnnn) STARTING
HTTPD005I LIBC370 2.26.0 (3AA3B28)
HTTPD002I AUTHORIZED BY SVC (MODULE KEY 8)
HTTPD004I STC IDENTITY SET TO HTTPD/USER VIA RACINIT
RAKF0004 INVALID ATTEMPT TO ACCESS SYSTEM:  USER:HTTPPRB
HTTPD020W CANNOT OPEN DD:HTTPPRM -- USING DEFAULTS
HTTPD054I LISTENING ON ANY PORT 8080
HTTPD061I STARTING SOCKET THREAD    TCB(9CDB00) TASK(100FC8) STACKSIZE(32768)
HTTPD061I STARTING WORKER(0DD1A8)   TCB(9CD410) TASK(114FC8) STACKSIZE(65536)
HTTPD061I STARTING WORKER(0DD0A8)   TCB(9CD0E0) TASK(125FC8) STACKSIZE(65536)
HTTPD061I STARTING WORKER(0DD028)   TCB(9BBCF8) TASK(136FC8) STACKSIZE(65536)
HTTPD001I HTTPD 4.5.1 READY - SERVING /www

The server listened on 8080 and had no routes. Static files from the document root are all that it served. The cure is to start with the right member, or to add the missing DD to the procedure. The file name of the capture says “refuse”, but the server did not refuse: a missing member is not an error for HTTPD.

Lines the Server Skips

A keyword that HTTPD does not know is skipped with HTTPD029W, and the keyword is shown in upper case:

S HTTPD,M=PRMKEY
$HASP100 HTTPD    ON STCINRDR
$HASP373 HTTPD    STARTED
IEF403I HTTPD - STARTED - TIME=05.26.28
HTTPD000I HTTPD 4.5.1 (nnnnnnn) STARTING
HTTPD005I LIBC370 2.26.0 (3AA3B28)
HTTPD002I AUTHORIZED BY SVC (MODULE KEY 8)
HTTPD004I STC IDENTITY SET TO HTTPD/USER VIA RACINIT
RAKF0004 INVALID ATTEMPT TO ACCESS SYSTEM:  USER:HTTPPRB
HTTPD029W UNKNOWN CONFIGURATION KEYWORD: COLOUR
HTTPD054I LISTENING ON ANY PORT 8080
HTTPD061I STARTING SOCKET THREAD    TCB(9CDB00) TASK(100FC8) STACKSIZE(32768)
HTTPD061I STARTING WORKER(0DD1A8)   TCB(9CD410) TASK(114FC8) STACKSIZE(65536)
HTTPD061I STARTING WORKER(0DD0A8)   TCB(9CD0E0) TASK(125FC8) STACKSIZE(65536)
HTTPD061I STARTING WORKER(0DD028)   TCB(9BBCF8) TASK(136FC8) STACKSIZE(65536)
HTTPD001I HTTPD 4.5.1 READY - SERVING /www

A line without an equals sign gives HTTPD026W with the first 40 characters of the line:

S HTTPD,M=PRMLINE
$HASP100 HTTPD    ON STCINRDR
$HASP373 HTTPD    STARTED
IEF403I HTTPD - STARTED - TIME=05.26.43
HTTPD000I HTTPD 4.5.1 (nnnnnnn) STARTING
HTTPD005I LIBC370 2.26.0 (3AA3B28)
HTTPD002I AUTHORIZED BY SVC (MODULE KEY 8)
HTTPD004I STC IDENTITY SET TO HTTPD/USER VIA RACINIT
RAKF0004 INVALID ATTEMPT TO ACCESS SYSTEM:  USER:HTTPPRB
HTTPD026W UNRECOGNIZED CONFIGURATION LINE: this line has no equals sign
HTTPD054I LISTENING ON ANY PORT 8080
HTTPD061I STARTING SOCKET THREAD    TCB(9CDB00) TASK(100FC8) STACKSIZE(32768)
HTTPD061I STARTING WORKER(0DD1A8)   TCB(9CD410) TASK(114FC8) STACKSIZE(65536)
HTTPD061I STARTING WORKER(0DD0A8)   TCB(9CD0E0) TASK(125FC8) STACKSIZE(65536)
HTTPD061I STARTING WORKER(0DD028)   TCB(9BBCF8) TASK(136FC8) STACKSIZE(65536)
HTTPD001I HTTPD 4.5.1 READY - SERVING /www

In both cases the server went on. The setting that you meant to make is not made, so a keyword with a typing error leaves the default in force. The line PORT=0 is the same kind of case:

S HTTPD,M=PRMBADP
$HASP100 HTTPD    ON STCINRDR
$HASP373 HTTPD    STARTED
IEF403I HTTPD - STARTED - TIME=05.26.58
HTTPD000I HTTPD 4.5.1 (nnnnnnn) STARTING
HTTPD005I LIBC370 2.26.0 (3AA3B28)
HTTPD002I AUTHORIZED BY SVC (MODULE KEY 8)
HTTPD004I STC IDENTITY SET TO HTTPD/USER VIA RACINIT
RAKF0004 INVALID ATTEMPT TO ACCESS SYSTEM:  USER:HTTPPRB
HTTPD023E INVALID PORT VALUE (0)
HTTPD054I LISTENING ON ANY PORT 8080
HTTPD061I STARTING SOCKET THREAD    TCB(9CDB00) TASK(100FC8) STACKSIZE(32768)
HTTPD061I STARTING WORKER(0DD1A8)   TCB(9CD410) TASK(114FC8) STACKSIZE(65536)
HTTPD061I STARTING WORKER(0DD0A8)   TCB(9CD0E0) TASK(125FC8) STACKSIZE(65536)
HTTPD061I STARTING WORKER(0DD028)   TCB(9BBCF8) TASK(136FC8) STACKSIZE(65536)
HTTPD001I HTTPD 4.5.1 READY - SERVING /www

The server wrote HTTPD023E and went on, and the capture shows that it listened on the default 8080. The message has the letter E, and the server still started. Chapter 4, “Configuring HTTPD” describes what a bad line or value does.

The same happens with the options of a route. This member has one of each mistake, and the next capture shows what the server said:

PORT=8080
DOCROOT=/www
RESIDENT=MAYBE
MOD=NOSUCH /nosuch/*            AUTH=NONE
LOC=/a/*                        AUTH=NONE RES=FACILITY:HTTPD.ADMIN
LOC=/b/*                        AUTH=BASIC RES=NOCOLON
LOC=/c/*                        AUTH=NONE BOGUS=1
LOC=/d/*                        RES=FACILITY:HTTPD.NOPROFILE

S HTTPD,M=PRMRTE
$HASP100 HTTPD    ON STCINRDR
$HASP373 HTTPD    STARTED
IEF403I HTTPD - STARTED - TIME=05.35.14
HTTPD000I HTTPD 4.5.1 (nnnnnnn) STARTING
HTTPD005I LIBC370 2.26.0 (3AA3B28)
HTTPD002I AUTHORIZED BY SVC (MODULE KEY 8)
HTTPD004I STC IDENTITY SET TO HTTPD/USER VIA RACINIT
RAKF0004 INVALID ATTEMPT TO ACCESS SYSTEM:  USER:HTTPPRB
HTTPD443W INVALID RESIDENT VALUE "MAYBE" (YES|NO)
HTTPD036I MODULE NOSUCH REGISTERED FOR /nosuch/*
HTTPD414W AUTH=NONE IGNORES RES=FACILITY:HTTPD.ADMIN (PUBLIC ROUTE)
HTTPD417I LOCATION /a/* REGISTERED
HTTPD412W IGNORING MALFORMED RES= 'NOCOLON' (NEED CLASS:RESOURCE)
HTTPD417I LOCATION /b/* REGISTERED
HTTPD413W IGNORING UNKNOWN ROUTE OPTION 'BOGUS=1'
HTTPD417I LOCATION /c/* REGISTERED
HTTPD417I LOCATION /d/* REGISTERED
HTTPD054I LISTENING ON ANY PORT 8080
HTTPD425W NO PROFILE FOR FACILITY:HTTPD.NOPROFILE -- /d/* NOT GATED
HTTPD440W MODULE NOSUCH NOT FOUND AT STARTUP, NOT HELD
HTTPD061I STARTING SOCKET THREAD    TCB(9CDB00) TASK(100FC8) STACKSIZE(32768)
HTTPD061I STARTING WORKER(0DD188)   TCB(9CD410) TASK(114FC8) STACKSIZE(65536)
HTTPD061I STARTING WORKER(0DD088)   TCB(9CD0E0) TASK(125FC8) STACKSIZE(65536)
HTTPD061I STARTING WORKER(0DD008)   TCB(9BBCF8) TASK(136FC8) STACKSIZE(65536)
HTTPD001I HTTPD 4.5.1 READY - SERVING /www

The first route (MOD=NOSUCH) is the one of “A Module Does Not Run”. Then follow HTTPD414W (a resource on a public route is ignored), HTTPD412W (the resource has no colon), HTTPD413W (an option that does not exist) and HTTPD425W (the profile does not exist, so the route is not gated; with RES_NOPROFILE=DENY it is HTTPD426W and the route refuses every request). The server registered all four routes in the end, and it did not stop.

Sessions That Are Too Short

The server compares the idle time and the maximum age of a login with CLIENT_TIMEOUT at the end of the start. A login that a request is still using must not be dropped. This member sets both values below the client time-out:

PORT=8080
DOCROOT=/www
CLIENT_TIMEOUT=120
SESSION_TIMEOUT=1
SESSION_MAXAGE=2

S HTTPD,M=PRMSESS
$HASP100 HTTPD    ON STCINRDR
$HASP373 HTTPD    STARTED
IEF403I HTTPD - STARTED - TIME=05.30.24
HTTPD000I HTTPD 4.5.1 (nnnnnnn) STARTING
HTTPD005I LIBC370 2.26.0 (3AA3B28)
HTTPD002I AUTHORIZED BY SVC (MODULE KEY 8)
HTTPD004I STC IDENTITY SET TO HTTPD/USER VIA RACINIT
RAKF0004 INVALID ATTEMPT TO ACCESS SYSTEM:  USER:HTTPPRB
HTTPD054I LISTENING ON ANY PORT 8080
HTTPD026E SESSION_TIMEOUT (1 MIN) <= CLIENT_TIMEOUT (120 SEC), RAISE IT
HTTPD032E SESSION_MAXAGE (2 MIN) <= CLIENT_TIMEOUT (120 SEC), RAISE IT
HTTPD061I STARTING SOCKET THREAD    TCB(9CDB00) TASK(100FC8) STACKSIZE(32768)
HTTPD061I STARTING WORKER(0DD1A8)   TCB(9CD410) TASK(114FC8) STACKSIZE(65536)
HTTPD061I STARTING WORKER(0DD0A8)   TCB(9CD0E0) TASK(125FC8) STACKSIZE(65536)
HTTPD061I STARTING WORKER(0DD028)   TCB(9BBCF8) TASK(136FC8) STACKSIZE(65536)
HTTPD001I HTTPD 4.5.1 READY - SERVING /www

Both messages are warnings, and the server started. The messages show the idle time and the maximum age in minutes and the client time-out in seconds. Raise SESSION_TIMEOUT and SESSION_MAXAGE, or lower CLIENT_TIMEOUT.

The Client Cannot Connect

The connection is refused or does not open. The server is not running, it did not reach HTTPD001I, or the client uses another port. Look on the console for HTTPD054I LISTENING ON ANY PORT n. The command F HTTPD,D P shows the port that the server serves:

F HTTPD,D P
HTTPD100I CONS(0) "D P"
HTTPD102I HTTPD IS LISTENING ON PORT 8080

The server binds to all interfaces of the host. If the port is right and the connection still fails, the cause is outside HTTPD.

The connection closes and the client gets no answer. The server closes a connection without a response when a time-out ends. The limit is CLIENT_TIMEOUT seconds (default 10) for the first request of a connection and KEEPALIVE_TIMEOUT seconds (default 5) for each later one. A client that sends part of a request line and then waits is closed. If CLIENT_TIMEOUT_MSG is on, which is the default, and the server has received at least one character, it writes a line to the console. The line has no message id. The next screens use a time-out of 3 seconds. The client sends 13 characters of a request line and waits:

$ exec 3<>/dev/tcp/localhost/8080
$ printf 'GET /hello.tx' >&3
$ sleep 6
$ exec 3>&-

client 00144FC8 on socket 1 timed out after 3 seconds
Dump of 00145028 "Receive Buffer" (13 bytes)
+00000 C7C5E340 61888593 93964BA3 A7       :GET /hello.tx   :

The line names the client block and the socket, and the dump shows what the server had received. A client that reuses a connection after more than the keep-alive time finds it closed. That is not a fault of the server. Send the next request on a new connection.

The client waits for the data and the connection ends. When the client does not take data, the server tries again every 0.1 second. After 100 tries without progress, that is 10 seconds, it gives up on the client and writes HTTPD065W. This holds for a chunked response and for the body of a static file. The server does not use the connection again, and the worker is free. It writes this message at most once in 60 seconds. If the server cannot read a file from the file system in the middle of a response, it writes HTTPD045E, cuts the response and closes the connection. It writes this message at most once in 60 seconds, and a count at its end says how many errors it held back. A client that sees a response that stops in the middle should look for these two messages.

The Status Is Not 200

The error responses of the server have a text body of one line. The next table lists the status codes and where to read on. “Status Codes” in “HTTP Behaviour and Limits” in the HTTPD Reference has the full list.

Code	Cause
302	A route with form login and no session. This is the login form working (“302, the Login Form”).
400	The request is malformed: a bad request line, header or parameter.
401	The route needs a login, and the request has none or a wrong one (“401, the Route Needs a Login”).
403	The user is known, but the resource check of the route denies the access (“403, the Resource Is Denied”).
404	There is no file for the path (“404, There Is No File”).
405	The method is not one that the server knows (“405 and 501, the Method”).
413	The body of a POST is larger than 3999 bytes, and the route has no program. A module route gets such a body unread.
414	The request line is longer than 3998 characters.
500	The server cannot build the response, or a module asked for a status code that the server does not know. The server then writes `HTTPD909E` to the console.
501	POST, PUT or DELETE for a static file (“405 and 501, the Method”).
503	A module does not run (“A Module Does Not Run”).
505	The version of the request is not HTTP/1.0 and not HTTP/1.1.

Table 42. The status codes that point to a problem

401, the Route Needs a Login

A route with AUTH=BASIC answers a request without credentials with 401 and a challenge. The header WWW-Authenticate carries the realm, which is the value of REALM:

$ curl -i http://localhost:8080/private/secret.txt
HTTP/1.1 401 Unauthorized
Date: Tue, 27 Oct 2026 05:52:44 GMT
Server: HTTPD Server
X-Powered-By: MVSLOVERS
Connection: keep-alive
WWW-Authenticate: Basic realm="MVS.EXAMPLE"
Cache-Control: no-store
Content-Type: text/plain
Transfer-Encoding: chunked

401 Unauthorized

A route with AUTH=TOKEN answers with 401 and no challenge:

$ curl -i http://localhost:8080/token/api.txt
HTTP/1.1 401 Unauthorized
Date: Tue, 27 Oct 2026 05:52:48 GMT
Server: HTTPD Server
X-Powered-By: MVSLOVERS
Connection: keep-alive
Cache-Control: no-store
Content-Type: text/plain
Transfer-Encoding: chunked

401 Unauthorized

The server never sends the header for a token route, whatever the request holds. A browser then shows no password dialog. The same is true for a request that has the header X-CSRF-ZOSMF-HEADER, also on a Basic route: the browser would open its own dialog, so the server leaves the header out. This is the answer of the mvsMF route, which is a token route, to a request with no login:

$ curl -i http://localhost:8080/zosmf/restfiles/ds?dslevel=SYS1.PARMLIB
HTTP/1.1 401 Unauthorized
Date: Tue, 27 Oct 2026 05:53:01 GMT
Server: HTTPD Server
X-Powered-By: MVSLOVERS
Connection: keep-alive
Cache-Control: no-store
Content-Type: text/plain
Transfer-Encoding: chunked

401 Unauthorized

A 401 does not say why. A user that does not exist and a user with a wrong password get the same answer as a request with no credentials:

$ curl -i -u NOSUCH:wrongpw http://localhost:8080/private/secret.txt
HTTP/1.1 401 Unauthorized
Date: Tue, 27 Oct 2026 05:52:44 GMT
Server: HTTPD Server
X-Powered-By: MVSLOVERS
Connection: keep-alive
WWW-Authenticate: Basic realm="MVS.EXAMPLE"
Cache-Control: no-store
Content-Type: text/plain
Transfer-Encoding: chunked

401 Unauthorized

$ curl -i -u IBMUSER:wrongpw http://localhost:8080/private/secret.txt
HTTP/1.1 401 Unauthorized
Date: Tue, 27 Oct 2026 05:52:44 GMT
Server: HTTPD Server
X-Powered-By: MVSLOVERS
Connection: keep-alive
WWW-Authenticate: Basic realm="MVS.EXAMPLE"
Cache-Control: no-store
Content-Type: text/plain
Transfer-Encoding: chunked

401 Unauthorized

So the status line cannot tell the three apart. These are the causes to check.

No credential. The server looks for the login in this order: the cookie Sec-Token, the cookie LtpaToken2, a Bearer token, and Basic credentials. A client that sends none of them gets the 401.
The user is not known, or the password is wrong. An unknown user leaves a line from the security product on the console. HTTPD writes none. The next screen shows the lines that one session left on the test system: the security product refused the user NOSUCH, then a login and a logout of IBMUSER were recorded.
```
HTTPD001I HTTPD 4.5.1 READY - SERVING /www
RAKF0004 INVALID ATTEMPT TO ACCESS SYSTEM:  USER:NOSUCH
HTTPD007I USER IBMUSER  IP 192.0.2.17 LOGIN SUCCESSFUL ACEE(9BB190)
HTTPD008I USER IBMUSER  IP 192.0.2.17 LOGOUT SUCCESSFUL
```
A wrong password for a known user does not appear on the console. The password of the client is not logged.
The client has another address. The login is bound to the address of the client. A user that logged in from another address does not count. A client behind a proxy or a gateway that changes the address between two requests loses its login.
The login has ended. HTTPD drops a login that is idle for SESSION_TIMEOUT minutes (default 30), and one that is older than SESSION_MAXAGE minutes (default 480). A client that sends user and password with every request does not notice this. A client with a cookie or a token must log in again. F HTTPD,D L shows who is logged in:
```
F HTTPD,D L
HTTPD100I CONS(0) "D L"
HTTPD121I USERS LOGGED IN: 1
HTTPD122I USER IBMUSER  IP 192.0.2.17 ACEE(9BA1E0)
```

Chapter 6, “Authentication and Security” describes the four modes and the sources of a login.

302, the Login Form

A route with AUTH=FORM answers a GET without a login with 302 and Location: /login. It also sets the cookie Sec-Uri, which holds the address of the request, so that the form can send the user back:

$ curl -i http://localhost:8080/form/page.html
HTTP/1.1 302 Moved Temporarily
Date: Tue, 27 Oct 2026 05:52:48 GMT
Server: HTTPD Server
X-Powered-By: MVSLOVERS
Connection: keep-alive
Cache-Control: no-store
Location: /login
Set-Cookie: Sec-Uri=YYaWmZRhl4GHhUuIo5ST; path=/
Transfer-Encoding: chunked

This is not a fault. The client is meant to follow the redirect and show the form. A request to a form route with a method other than GET and POST gets status 200 and the text Invalid REQUEST_METHOD, because the server cannot send such a request to a form.

403, the Resource Is Denied

The route has RES=class:resource. The user is logged in, but the security product does not give the user READ access to the resource. The answer is 403 with the body 403 Forbidden:

$ curl -i -u IBMUSER:****** http://localhost:8080/denied/data.txt
HTTP/1.1 403 Forbidden
Date: Tue, 27 Oct 2026 05:52:48 GMT
Server: HTTPD Server
X-Powered-By: MVSLOVERS
Connection: keep-alive
Cache-Control: no-store
Content-Type: text/plain
Transfer-Encoding: chunked

403 Forbidden

The resource of this route is a profile that nobody may read. To cure a 403, permit the user to read the profile. Then activate the change. A profile that you define or permit is not in force until RAKF has read it. The tool that defines the profiles says so, in its own words, “Run RAKFPROF to activate the changes”. The started task RAKFPROF does it:

S RAKFPROF
$HASP100 RAKFPROF ON STCINRDR
RAKF0010I STC RAKFPROF STARTED USING DEFAULT STC ACCOUNT
$HASP373 RAKFPROF STARTED
IEF403I RAKFPROF - STARTED - TIME=00.40.36
RAKFPROF7  RAKF PROFILES UPDATED
$HASP395 RAKFPROF ENDED
IEF404I RAKFPROF - ENDED - TIME=00.40.36

The opposite fault is silent. Under RAKF a resource that has no profile is not protected, and the product answers that the access is allowed. The route then lets everybody pass. At the start the server tests every route that has RES= and a mode other than NONE, and it writes HTTPD425W NO PROFILE FOR class:resource -- path NOT GATED for each one that has no profile (see the capture in “Lines the Server Skips”). A typing error in the resource name looks the same. A class that RAKF does not define gives the same with RAKF 1.2.x (measured on TK5). RAKF 2.0.0 (MVS/CE) gives the return code 8 instead, with no HTTPD425W, and no user passes. Treat HTTPD425W as an error of your configuration. “What the Server Asks of the Security Product” in the HTTPD Reference describes the check.

With RES_NOPROFILE=DENY in the member, the route is not silent. The start writes HTTPD426W NO PROFILE FOR class:resource -- path REFUSES ALL REQUESTS, and every logged-in user gets 403 with the body 403 Forbidden: no RACF profile protects this resource. That body is the difference from the 403 above: it says that no profile exists, not that the profile does not permit the user. Define the profile and run RAKFPROF. The server needs no restart (“Refusing a Route Whose Profile Is Missing”).

For the console route of mvsMF there is a second answer. mvsMF 1.4.0 and later check READ on the same profile themselves. HTTPD answers 403 first to a user without READ. A user who passes the route when the profile is not defined gets status 500 from mvsMF, with the error category 4, because mvsMF refuses every user until the profile exists. That is the answer with the default RES_NOPROFILE=ALLOW. With RES_NOPROFILE=DENY HTTPD answers 403 with the body above before mvsMF is called. Define the profile.

404, There Is No File

A request for a path that no route claims is served from the document root. A file that is not there, and a file that HTTPD cannot open, get the same answer:

$ curl -i http://localhost:8080/nothere.html
HTTP/1.1 404 Not Found
Date: Tue, 27 Oct 2026 05:41:42 GMT
Server: HTTPD Server
X-Powered-By: MVSLOVERS
Connection: keep-alive
Cache-Control: no-store
Content-Type: text/plain
Transfer-Encoding: chunked

404 document "/nothere.html" not found

The body names the decoded path. If only one file is missing, check the name and the directory in the image. If every request for a file gets a 404, the cause is more likely the file system. “Static Files Are Not Served” has the checks.

405 and 501, the Method

A static file answers GET and HEAD. A POST, PUT or DELETE for a static file gets 501:

$ curl -i -X POST -d x=1 http://localhost:8080/hello.txt
HTTP/1.1 501 Not Implemented
Date: Tue, 27 Oct 2026 05:41:53 GMT
Server: HTTPD Server
X-Powered-By: MVSLOVERS
Connection: close
Cache-Control: no-store
Content-Type: text/plain
Transfer-Encoding: chunked

501 Not Implemented

The answer to the POST says Connection: close. Use GET to read a file.

If curl -I gets 501, the server is HTTPD 4.4.0 or earlier. These releases do not answer a HEAD for a static file with the headers of a GET. The console message HTTPD000I at the start names the version (“What the Console Shows”). HTTPD 4.5.0 answers the HEAD (“What Is Not Supported”).

A method that the server does not know gets 405:

$ curl -i -X OPTIONS http://localhost:8080/hello.txt
HTTP/1.1 405 Method Not Allowed
Date: Tue, 27 Oct 2026 05:41:53 GMT
Server: HTTPD Server
X-Powered-By: MVSLOVERS
Connection: close
Cache-Control: no-store
Content-Type: text/plain
Transfer-Encoding: chunked

405 Method Not Allowed

Chapter 7, “Serving Files” has more on files.

“401, the Route Needs a Login” and “403, the Resource Is Denied” cover what a client sees. Three more faults concern the server and its security product.

The Server Has Not Its Own Identity

Symptom. The console shows HTTPD004W RACINIT ENVIR=CREATE FAILED FOR user/group RC=n at the start.

At the start the server logs on as the user id of STCUSER and the group of STCGROUP, which the procedure passes in the PARM string. When the logon fails, the server writes HTTPD004W and keeps the identity that the task inherited. A cause is that the user id is not defined. The server goes on, and that is the danger: on a standard RAKF profile set the inherited account holds ALTER authority on every data set of the system. Define the user id and the group, then restart. HTTPD003W says that the server could not enter supervisor state and so skipped the logon. “The Identity of the Task” in “The Started Task and the Package” in the HTTPD Reference has the steps. On the healthy start the line is HTTPD004I STC IDENTITY SET TO user/group VIA RACINIT, as the captures in this chapter show.

Every Login Is Refused, HTTPD042W

Symptom. The console shows HTTPD042W SECURITY SYSTEM ACCEPTS ANY USERID, ALL LOGINS REFUSED at the start. Every login gets 401, also for users that are defined and use the right password. The server serves the paths that need no login. Before the message the console shows RAKF0001 and RAKF0002 for the logon of the task and for the user ID HTTPPRB, and RAKF0003 and RAKF0009 if the profile table is missing as well.

Cause. RAKF 1.2.x has no valid user table, for example because the load of SYS1.SECURE.CNTL(USERS) was rejected at the IPL (RAKFUIDS2, RAKFUIDSX). RAKF then accepts every user ID. HTTPD 4.5.1 and later find this at the start and refuse all logins.

Cure. Correct the tables before the next IPL and read the lines of the load in the log. Then restart HTTPD. A running server does not test again, and a server that has written HTTPD042W keeps refusing until it is started again. A good start has RAKF0004 for the user ID HTTPPRB and no HTTPD042W. “A Security System That Accepts Any User ID” has the details.

A Changed Password Does Not Take Effect

Symptom. An administrator changes a password in the security product, or revokes a user. A client that logged in earlier is still accepted with the old password, and the new password works as well.

HTTPD keeps a login in a table in its storage. A request with the same user, password and address finds the entry and is answered from it. The server does not ask the security product again, so the product’s answer at the time of the login is what counts. An entry ends in one of these ways:

It is idle for SESSION_TIMEOUT minutes (default 30).
It is older than SESSION_MAXAGE minutes (default 480), counted from the login. Activity does not renew it. The next request then asks the security product again, and a revoked user or a changed password take effect at that moment.
The client logs out.
The server stops.

The new password is a different key for the table, so a request with it asks the security product and works. Only the old password is served from the table.

To end a login at once, restart the server, or have the user log out. If a shorter life is what the site needs, lower SESSION_TIMEOUT and SESSION_MAXAGE. Keep both above CLIENT_TIMEOUT in seconds, or the server warns (“Sessions That Are Too Short”). Chapter 4, “Configuring HTTPD” shows both keywords.

From HTTPD 4.5 a module that asks for a new session can find that the security product refuses the logon. Then the server marks the entry as stale. It does not answer by password or token from that entry any more, and it frees the entry 600 seconds later. The module answers 401. “Sessions” in “The Server Module Interface” in the HTTPD Reference has the result codes.

A Module Does Not Run

Symptom. The client gets 503 and a line that starts with External program, and the console shows HTTPD908E.

The route names a module, and the server could not run it, or the module ended badly. This is a route to a module that is not in any library:

PORT=8080
DOCROOT=/www
MOD=NOSUCH /nosuch/*            AUTH=NONE

$ curl -i http://localhost:8080/nosuch/x
HTTP/1.1 503 Service Unavailable
Date: Tue, 27 Oct 2026 05:50:25 GMT
Server: HTTPD Server
X-Powered-By: MVSLOVERS
Connection: keep-alive
Content-Type: text/plain
Transfer-Encoding: chunked

External program NOSUCH was not found

The body says External program NOSUCH was not found. The server also wrote HTTPD908E EXTERNAL PROGRAM NOSUCH was not found to the console. The start had already warned about this module with HTTPD440W MODULE NOSUCH NOT FOUND AT STARTUP, NOT HELD (see the capture in “Lines the Server Skips”). The text after the module name is the reason, and it is the same for the client and for the operator.

Text	Cause and cure
was not found	The module is in neither the STEPLIB nor the link list. The completion code is S806. Check the name in the route, and check that the member is in a library of the STEPLIB of the procedure.
could not be loaded	The LINK failed, and the cause is not S806. The module did not run.
was dispatched without a program name	The route has no program name.
could not be started, ESTAE create failed	The server could not set up the error exit for the LINK, so the module did not run.
returned rc n	The module ran and returned a negative code n of its own.
failed with Sxxx ABEND	The module ended with the system abend xxx. Look for the dump (“A Module Abends with S0C4”).
failed with Unnnn ABEND	The module ended with the user abend nnnn, in decimal. `U0801`, with the console line `@@CRT0 - No storage for C stack`, is a region that is too small, see below.

Table 43. The reasons for a failed module

Only the abends leave a dump to look for. The other reasons mean that the module did not run or ended by itself. After the module ended, the server frees its storage. If that fails, it writes HTTPD906W with the module name and the return code, and the storage stays until the server restarts. The worker lives on in every case and serves the next request.

The abend is U0801, and it comes under load. Every request that runs a module takes one block of storage for its stack: about 256 KB for a module that sets nothing, which is the case for REXX and Lua, and about 64 KB for mvsMF. Up to MAXTASK requests run at once. When the region has no free block of that size, the console shows @@CRT0 - No storage for C stack and HTTPD908E EXTERNAL PROGRAM name failed with U0801 ABEND, and the client gets 503. The other requests go on. Raise the REGION of the procedure (16M held in the one run that was measured) before you raise MAXTASK. If 16M is not enough, lower MAXTASK. “The Started Task and the Package” in the HTTPD Reference has the sizes and the measurement.

The module is in a library, and the route still fails. The LINK searches the STEPLIB of the started task first, and then the link list. Check that the library is in the STEPLIB of the procedure that started the server, and that the member has the name in the route. If the member comes from a development library, that library has to be in the concatenation, and it has to come before the production library so that its module wins.

A new build of the module has no effect. By default the server loads each module once at the start and holds it until it stops. The requests use that copy. Stop the task before you replace the load library, and start it again. For development you can switch the holding off with RESIDENT=NO. A module that was not found at the start (HTTPD440W) is not held. It works as soon as it is in the library.

A Module Abends with S0C4

Symptom. The client gets 503 and External program name failed with S0C4 ABEND. The same module worked on the test system.

A module that the system fetches from an APF-authorized library or from the link list lands in storage with the protection key 0. Its code runs with the key 8. The first write to the storage of the module abends with S0C4. The library decides, not the attribute AC(1) and not RENT. The module works when its library is not in the APF list: the system fetches it with the key 8, and the write is allowed. The same load module abends on a system where the library is authorized.

This is why HTTPD002I matters (see “Authorization Fails”). The form BY LIBRARY (MODULE KEY 0) says that the modules are fetched with the key 0, and every write to the static data of a module abends. The form BY SVC (MODULE KEY 8) hides the fault. The key in the message is inferred from the way the step was authorized and not measured.

The cure is in the module, not in the authorization. A module must not write to a variable at file scope or to a static variable of a function, and it must not change a string constant in place. Put the state into a local variable, onto the heap, or into the storage that __wsaget() returns. Read-only data such as tables is fine. The declaration decides for strings that a function translates in place: UCHAR text[] = "..." is a copy on the stack, and UCHAR *text = "..." points to the constant itself. A call of __super() does not help, because a module can be in key 0 without the right to switch. “Storage Rules” in “The Server Module Interface” in the HTTPD Reference has the rules. Chapter 9, “Writing a Server Module” shows a module that follows them. Test a module with its library in the APF list before you call it done.

A Response Takes Five Seconds

Symptom. A module answers 200 with the right body, but the client needs about five seconds before it is done.

Look at the headers of such a response. This is a module that has the pitfall:

$ curl -sv -o /dev/null http://localhost:8080/hello 2>&1 | grep "^< "
< HTTP/1.1 200 OK
< Date: Tue, 27 Oct 2026 05:56:59 GMT
< Server: HTTPD Server
< X-Powered-By: MVSLOVERS
< Connection: keep-alive
< Content-Type: text/plain
<

There is no Content-Length and no Transfer-Encoding, and the header Connection says keep-alive. The client cannot tell where the body ends. It waits until the server closes the connection, and the server does this only when its keep-alive wait ends. The time of the whole request shows it:

$ curl -s -o /dev/null -w "%{http_code} %{time_total}s\n" http://localhost:8080/hello
200 4.632924s

The same module, written correctly, takes this:

$ curl -s -o /dev/null -w "%{http_code} %{time_total}s\n" http://localhost:8080/hello
200 0.069525s

The cause is how the server finds the end of the headers. http_printf watches for a call whose text is exactly "\r\n". When it sees that call, it adds Transfer-Encoding: chunked for an HTTP/1.1 request that has no Content-Length, and it turns chunking on. A blank line that is joined to the last header in one call is not found. The module with the pitfall ends its headers like this:

http_resp(httpc, 200);
http_printf(httpc, "Content-Type: text/plain\r\n\r\n");
http_printf(httpc, "Hello, %s!\n", name);

The right module sends the blank line as a call of its own:

http_resp(httpc, 200);
http_printf(httpc, "Content-Type: text/plain\r\n");
http_printf(httpc, "\r\n");
http_printf(httpc, "Hello, %s!\n", name);

A module can also send a Content-Length header and then it is not chunked. The wait in the capture is close to the default of KEEPALIVE_TIMEOUT, which is 5 seconds. “Chunked Transfer” in “HTTP Behaviour and Limits” in the HTTPD Reference has the rules, and Chapter 9, “Writing a Server Module” shows the complete module.

A Request Is Slow

Symptom. A client says that one request takes long. You want to know whether the time went to the client, to the server, to a module or to the send. The request trace records the time of each phase of every request, so it answers this. It has to be on before the request is made, because the server reads TRACE= only at its start. If it is off, switch it on with the steps in “The Request Trace” and wait for the problem to come again.

The target TRACE of HTTPDSRV shows the table. The parameter min is a number of milliseconds. It leaves out the finished requests that took less. A request that is still running is always in the answer. The first line of the answer holds the totals, and the filter tail -n +2 cuts it. The filter cut keeps the words of interest: the number of the request, its worker, its number on the connection, whether it still runs, the last phase it reached, its age in milliseconds, the times of the request line and of the end of the headers, the number of waits for the client, and the path.

The first capture was made while a client held a request back. The client had sent the request line and no header line, and the readout is from the third second:

$ curl -s -u IBMUSER:****** "http://localhost:8080/.dsrv?target=TRACE&min=1000" | tail -n +2 | cut -d" " -f1,3,7,10,11,13,15,16,27,32
seq=8 w=17FA40 n=0 live=1 last=line1 age=3090 line1=4 req=- polls=7 path=
seq=9 w=17F9C0 n=0 live=1 last=sndl age=33 line1=4 req=10 polls=0 path=/.dsrv

The first line is the request of the slow client. It still runs (live=1). Its last phase is line1: the server read the request line after 4 ms, and since then it has waited for the header lines. The word req is -, because the end of the headers was not reached. The server has gone back to waiting for the client seven times (polls=7), and each wait lasts up to half a second. The time is not the time of the server. The second line is the request that read the trace.

The second capture was made after the client had sent the rest:

$ curl -s -u IBMUSER:****** "http://localhost:8080/.dsrv?target=TRACE&min=1000" | tail -n +2 | cut -d" " -f1,3,7,10,11,13,15,16,27,32
seq=8 w=17FA40 n=0 live=0 last=end age=5537 line1=4 req=5517 polls=11 path=/zosmf/info
seq=11 w=17FB40 n=0 live=1 last=sndl age=24 line1=4 req=10 polls=0 path=/.dsrv

The request ended with last=end after 5,537 ms. The end of the headers came at 5,517 ms, so the server needed 20 ms for everything that follows. The cause of the long request is the client.

When the time is not in the wait for the client, find the largest gap between two phases. The next table says what each gap is. The Reference lists the phases in “The Display Modules” (target TRACE).

Gap	Meaning
accept to `run`	The request waited for a worker. All workers were busy (“Requests Wait or Workers Abend”).
`run` to `req`	The server waited for the client to send the request line and the headers. `polls` counts the waits of half a second.
`req` to `parse`	The server parsed the request. For a POST it also read the body, so a client that sends its body slowly shows up here.
`parse` to `cred`	The server resolved the credential of the request.
`cred` to `route`	The server checked the policy of the route, with the RACF check of `RES=` if the route has one.
`lnk0` to `lnk1`	The module ran. The time includes the load of the module if the server does not hold it in storage (“A Module Does Not Run”).
`snd1` to `sndl`	The server sent the data. `txst` counts the pauses of a tenth of a second in which TCP/IP took no data, for a chunked response and for a static file: the client or the network is slow to receive.

Table 44. Where the time of a request goes

The trace shows what the server did and nothing of the network. A request that is fast in the trace and slow for the client was slow in the client or in the network. On a connection that stays open, the record of the second request starts at the end of the first one, so its line1 includes the time that the client needed to send it. A finished request that took a second or more stays in the table longer than a fast one, so a slow request is still there when you look.

Static Files Are Not Served

Symptom. Every request for a file gets 404, also for files that are in the image.

HTTPD reads files through UFSD. The message HTTPD044W UNABLE TO INITIALIZE FILE SYSTEM says that the server could not create its handle for the file system. It does not say that UFSD is down. A request for a file that HTTPD cannot open gets the 404, whatever the reason. Check in this order:

UFSD runs.
The image is mounted. The operator command F UFSD,MOUNT LIST shows the mounts.
The mount point is the value of DOCROOT. The default is /www.
The file is in the image, with the path of the request.
The Parmlib member does not set UFS=0. The value 0 switches the file system off, and then no file is served.

Chapter 7, “Serving Files” shows the document root and the mount.

Requests Wait or Workers Abend

Requests wait. A worker serves one connection until it is closed. A connection with keep-alive holds its worker, also while the connection is idle, for at most KEEPALIVE_TIMEOUT seconds between two requests. When all workers up to MAXTASK are busy, a further client has to wait for a free worker. Raise MAXTASK with F HTTPD,SET MAXTASK n, but read about the region in “A Module Does Not Run” first, or lower KEEPALIVE_TIMEOUT (Chapter 4, “Configuring HTTPD”). The command F HTTPD,D T shows the threads of the server. If one request is stuck in a module, the module is the cause, and more workers do not cure it. At the stop the server waits up to 10 seconds for the socket thread to end. It writes HTTPD040I while it waits and HTTPD041I when it detaches the task.

A worker abends. An abend in a module does not stop the worker (“A Module Does Not Run”). An abend in the code of the server gives HTTPD062E ABEND code IN WORKER(..) CLIENT(..) SOCKET(n). The code is the abend word in eight hex digits. The server closes the client, and the worker goes on with the next request. HTTPD063E says that the worker could not set up its recovery, and that it dropped the client. A repeated HTTPD062E with the same code points to the server and not to a module. Chapter 8, “Operating HTTPD” describes the recovery.

Reading the Master Trace Table

Every console message goes into the Master Trace Table, and HTTPD writes to the console only what an operator can act on. So the table is where you look after a failure, also when nobody watched the console. The display module HTTPDMTT shows the table over HTTP when a route for it exists (Chapter 8, “Operating HTTPD” shows the route). This request returns the whole table as plain text, and grep picks out the messages of HTTPD:

curl -s -u IBMUSER:password "http://localhost:8080/.dmtt?d=1" | grep HTTPD

With the parameter d=1 the answer is plain text. Without it, the answer is an HTML page. The module does not search or select. The table holds only the recent messages, so a server that has run for a long time may have lost the messages of its start. Read the table soon after a failure. This is the end of the table after the start of the test server. The capture shows the last lines:

$ curl -s -u IBMUSER:****** http://localhost:8080/.dmtt | sed -n "/<pre>/,/<\/pre>/p" | sed -e "s/<[^>]*>//g" | tail -n 4
FFFF  5.33.53 STC   nn  HTTPD061I STARTING WORKER(0FE648)   TCB(9BB328) TASK(1CBFC8) STACKSIZE(65536)
FFFF  5.33.53 STC   nn  HTTPD061I STARTING WORKER(0FE5C8)   TCB(9BAEB8) TASK(1DCFC8) STACKSIZE(65536)
FFFF  5.33.54 STC   nn  HTTPD001I HTTPD 4.5.1 READY - SERVING /www

The table is the whole console log of the system. Protect the route with a login mode, and with a resource check if you can (Chapter 6, “Authentication and Security”).

What to Collect

When a problem stays, collect these items before you ask for help:

the messages of the start, from the banner to HTTPD001I, or the lines of the failure, from the console or from the Master Trace Table
the Parmlib member that the server read
the output of F HTTPD,D V and F HTTPD,D C, which show the version and the configuration that the server runs
the status line and the body of the response, from curl -i
for a module that abended, the name and the abend code from HTTPD908E and the dump, if you have it

Remove passwords and the names of your own systems from what you send.