Conflict between basicauth and handle_errors

1. Caddy version (caddy version):

2.2.1

2. How I run Caddy:

Systemd, with “/path/to/caddy run /path/to/Caddyfile”

a. System environment:

Centos 8, with SELinux disabled (running in a Hyper-V 2019 VM). All current updates installed. Using systemd.

b. Command:

as above

c. Service/unit/compose file:

# caddy.service
#
# For using Caddy with a config file.
#
# Make sure the ExecStart and ExecReload commands are correct
# for your installation.
#
# See https://caddyserver.com/docs/install for instructions.
#
# WARNING: This service does not use the --resume flag, so if you
# use the API to make changes, they will be overwritten by the
# Caddyfile next time the service is restarted. If you intend to
# use Caddy's API to configure it, add the --resume flag to the
# `caddy run` command or use the caddy-api.service file instead.

[Unit]
Description=Caddy
Documentation=https://caddyserver.com/docs/
After=network.target network-online.target
Requires=network-online.target

[Service]
User=caddy
#User=root
Group=caddy
#Group=root
ExecStart=/usr/bin/caddy run --environ --config /etc/caddy/Caddyfile
ExecReload=/usr/bin/caddy reload --config /etc/caddy/Caddyfile
TimeoutStopSec=5s
LimitNOFILE=1048576
LimitNPROC=512
#PrivateTmp=true
#ProtectSystem=full
AmbientCapabilities=CAP_NET_BIND_SERVICE

[Install]
WantedBy=multi-user.target

d. My complete Caddyfile or JSON config:

####################################################################################
# Test Caddyfile
####################################################################################

{
	debug
	email pwh@cassland.org
}

####################################################################################
# Sites
####################################################################################

pen2.cassland.org {

	root * /var/www/html/cassland_org

	basicauth /Nic/* {   # directory is browsed
		NBH JDJhJDE0JHo5WGN5eGZ6SkNiRlEwYmtaZjlMMWVMeE1rVWIwZjNCNGhDdXJvRGRjVWRxQ1I5V3ozcWpH # something
	}

	@browsedirs {
		path /Nic
		path /Nic/*  #basicauth required
	}
	file_server @browsedirs browse
	file_server

	handle_errors {
		@404 {
			expression {http.error.status_code} == "404"
		}
		rewrite @404 /404.html  # /404.html or /New404.html
		file_server
	}

	log {
		output file /var/log/caddy/CLaccess.log
		format single_field common_log
	}
}

3. The problem I’m having:

I have a directory, which is browsed, and which is protected by basicauth. If I add a handle_errors directive, the basicauth fails to send the correct status back to the client, which therefore does not proceed to ask for credentials - in the error case, instead of the expected 401 the status returned is logged as 0 but shown by curl as 200.

4. Error messages and/or full log output:

Without handle_errors:

Log:

192.168.1.74 - - [18/Nov/2020:12:12:37 +0000] "GET /Nic/ HTTP/1.1" 401 0

Curl:

C:\Users\paul.CASS>curl -v https://pen2.cassland.org/Nic/
*   Trying 192.168.1.86...
* TCP_NODELAY set
* Connected to pen2.cassland.org (192.168.1.86) port 443 (#0)
* schannel: SSL/TLS connection with pen2.cassland.org port 443 (step 1/3)
* schannel: checking server certificate revocation
* schannel: sending initial handshake data: sending 188 bytes...
* schannel: sent initial handshake data: sent 188 bytes
* schannel: SSL/TLS connection with pen2.cassland.org port 443 (step 2/3)
* schannel: encrypted data got 3100
* schannel: encrypted data buffer: offset 3100 length 4096
* schannel: sending next handshake data: sending 93 bytes...
* schannel: SSL/TLS connection with pen2.cassland.org port 443 (step 2/3)
* schannel: encrypted data got 186
* schannel: encrypted data buffer: offset 186 length 4096
* schannel: SSL/TLS handshake complete
* schannel: SSL/TLS connection with pen2.cassland.org port 443 (step 3/3)
* schannel: stored credential handle in session cache
> GET /Nic/ HTTP/1.1
> Host: pen2.cassland.org
> User-Agent: curl/7.55.1
> Accept: */*
>
* schannel: client wants to read 102400 bytes
* schannel: encdata_buffer resized 103424
* schannel: encrypted data buffer: offset 0 length 103424
* schannel: encrypted data got 173
* schannel: encrypted data buffer: offset 173 length 103424
* schannel: decrypted data length: 144
* schannel: decrypted data added: 144
* schannel: decrypted data cached: offset 144 length 102400
* schannel: encrypted data buffer: offset 0 length 103424
* schannel: decrypted data buffer: offset 144 length 102400
* schannel: schannel_recv cleanup
* schannel: decrypted data returned 144
* schannel: decrypted data buffer: offset 0 length 102400
< HTTP/1.1 401 Unauthorized
< Server: Caddy
< Www-Authenticate: Basic realm="restricted"
< Date: Wed, 18 Nov 2020 12:12:37 GMT
< Content-Length: 0
<
* Connection #0 to host pen2.cassland.org left intact

But when handle_errors is added to the Caddyfile I get the following:

Log:

192.168.1.74 - - [18/Nov/2020:12:13:31 +0000] "GET /Nic/ HTTP/1.1" 0 0

Curl:

C:\Users\paul.CASS>curl -v https://pen2.cassland.org/Nic/
*   Trying 192.168.1.86...
* TCP_NODELAY set
* Connected to pen2.cassland.org (192.168.1.86) port 443 (#0)
* schannel: SSL/TLS connection with pen2.cassland.org port 443 (step 1/3)
* schannel: checking server certificate revocation
* schannel: sending initial handshake data: sending 188 bytes...
* schannel: sent initial handshake data: sent 188 bytes
* schannel: SSL/TLS connection with pen2.cassland.org port 443 (step 2/3)
* schannel: encrypted data got 3101
* schannel: encrypted data buffer: offset 3101 length 4096
* schannel: sending next handshake data: sending 93 bytes...
* schannel: SSL/TLS connection with pen2.cassland.org port 443 (step 2/3)
* schannel: encrypted data got 186
* schannel: encrypted data buffer: offset 186 length 4096
* schannel: SSL/TLS handshake complete
* schannel: SSL/TLS connection with pen2.cassland.org port 443 (step 3/3)
* schannel: stored credential handle in session cache
> GET /Nic/ HTTP/1.1
> Host: pen2.cassland.org
> User-Agent: curl/7.55.1
> Accept: */*
>
* schannel: client wants to read 102400 bytes
* schannel: encdata_buffer resized 103424
* schannel: encrypted data buffer: offset 0 length 103424
* schannel: encrypted data got 163
* schannel: encrypted data buffer: offset 163 length 103424
* schannel: decrypted data length: 134
* schannel: decrypted data added: 134
* schannel: decrypted data cached: offset 134 length 102400
* schannel: encrypted data buffer: offset 0 length 103424
* schannel: decrypted data buffer: offset 134 length 102400
* schannel: schannel_recv cleanup
* schannel: decrypted data returned 134
* schannel: decrypted data buffer: offset 0 length 102400
< HTTP/1.1 200 OK
< Server: Caddy
< Www-Authenticate: Basic realm="restricted"
< Date: Wed, 18 Nov 2020 12:13:31 GMT
< Content-Length: 0
<
* Connection #0 to host pen2.cassland.org left intact

Debug log:

{"level":"error","ts":1605703916.8081162,"logger":"http.log.error.log0","msg":"error handling handler error","request":{"remote_addr":"192.168.1.74:1281","proto":"HTTP/1.1","method":"GET","host":"pen2.cassland.org","uri":"/Nic/","headers":{"User-Agent":["curl/7.55.1"],"Accept":["*/*"]},"tls":{"resumed":false,"version":771,"cipher_suite":49196,"proto":"","proto_mutual":true,"server_name":"pen2.cassland.org"}},"duration":0.0001428,"error":"{id=pcd6e6rcx} fileserver.(*FileServer).notFound (staticfiles.go:386): HTTP 404","first_error":{"msg":"not authenticated","status":401,"err_id":"bsz4y89g5","err_trace":"caddyauth.Authentication.ServeHTTP (caddyauth.go:78)"}}
{"level":"info","ts":1605703916.8096578,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_addr":"192.168.1.74:1281","proto":"HTTP/1.1","method":"GET","host":"pen2.cassland.org","uri":"/Nic/","headers":{"User-Agent":["curl/7.55.1"],"Accept":["*/*"]},"tls":{"resumed":false,"version":771,"cipher_suite":49196,"proto":"","proto_mutual":true,"server_name":"pen2.cassland.org"}},"common_log":"192.168.1.74 - - [18/Nov/2020:12:51:56 +0000] \"GET /Nic/ HTTP/1.1\" 0 0","duration":0.0001428,"size":0,"status":0,"resp_headers":{"Server":["Caddy"],"Www-Authenticate":["Basic realm=\"restricted\""]}}

5. What I already tried:

Previously discussed in this thread. The present thread shows the simplest form of the error that I can produce. Not all the problems I discussed before show up in this simple form - in particular, if the protected resource is not browsed and has an index.html file, then in this simple case the problem doesn’t occur.

Paul

Thanks for the simplified report, I’m able to see the same behavior. So basically you are expecting a 401 response right, even with handle_errors used?

If so, then the current config won’t do that, and I can explain why. The basicauth directive is returning an error, so handle_errors is then invoked, and because it’s not a 404 error, it simply runs the file_server directive, which looks for an index file when a directory is required. There is no index file I presume, so it returns a 404.

In hindsight, we could probably do better than return a 200 when handling an error in the error handler :stuck_out_tongue: But I think that’s a separate issue.

Does that answer your question?

Thanks; that explains the behaviour. I have been able to work out a fix (see below), but feel I should explain why it seems a bit half-baked to me.

Now, although I have been a programmer, and independently of that have run a range of webservers for over twenty years I find the idea that adding another directive would break a working authorisation setup non-intuitive, and indeed somewhat bizarre. Presumably I am now expected to know that I have to capture the 401 in any handle_errors section I make, and to know what output to tell it to generate to replicate what it would previously have done for itself; a note in the documentation of both basicauth and handle_errors would seem to be called for.

From my perspective, a 401 to request authorisation is not an “error”, it is part of the design of an authorisation interaction, and so it’s not obvious that putting in a directive to improve actual error reporting should have anything to do with it. Furthermore, combining the same facilities (differently implemented) in Caddy v1 did not do this, so the change in behaviour in this case is unexpected and should therefore perhaps have been warned of and documented in the page about adapting from Caddy v1 to Caddy v2. In Caddy v1 the “errors” directive enabled me to do the same thing as I am trying to do here without generating an undesired interaction with basicauth.

So anyway, what do I need to put in the handle_errors to restore the basicauth function? I suppose I need to match the 401 and use respond to send it on to the client; which would result in:

	handle_errors {
		@401 {
			expression {http.error.status_code} == "401"
		}
		@404 {
			expression {http.error.status_code} == "404"
		}
		route {
			respond @401 401
			rewrite @404 /404.html
			file_server
		}
	}

However, I noted in my tests that for a 404 the client was sent a 404 status without my having to write it in the Caddyfile. So what about codes other than 401 and 404? Maybe I should write this instead so that other statuses get returned to the client and not lost in the handle_errors directive as the 401 was:

	handle_errors {
		@not404 {
			expression {http.error.status_code} != "404"
		}
		route {
			respond @not404 {http.error.status_code} ""
			rewrite * /404.html
			file_server
		}
	}

So I tried that last one, and it worked - everything happened as I expected. But I am sad that Caddy, which used to be simple and intuitive, has in this situation required the kind of extra work that I associate with Apache or nginx. None the less, I still greatly prefer it, and hope that you can continue to develop and improve it!

Paul