Won't Start From Service But Will From CLI -- "decoding certificate metadata: unexpected end of JSON input"

stiobhart · January 17, 2020, 10:44pm

1. My Caddy version (`caddy -version`):

caddy -version
Caddy v1.0.4 (h1:wwuGSkUHo6RZ3oMpeTt7J09WBB87X5o+IZN4dKehcQE=)

2. How I run Caddy:

From a service with sudo service caddy start

a. System environment:

NAME=“Ubuntu”
VERSION=“18.04.3 LTS (Bionic Beaver)”

b. Command:

sudo service caddy start

c. Service/unit/compose file:

[Unit]
Description=Caddy Server
#start after networking stuff has loaded
After=network.target

[Service]
User=madra
Group=www-data
WorkingDirectory=/var/www
#max file dscriptor [equivalent of ulimit in terminal]
LimitNOFILE=8192
PIDFile=/var/run/caddy/caddy.pid
#script to run
ExecStart=/usr/local/bin/caddy -agree -email xxx@xxx.net -pidfile=/var/run/caddy/caddy.pid
#respawn if it crashes
Restart=on-failure
#wait 10 mins to reboot. if it crashes constantly
StartLimitInterval=600

[Install]
#target we want it included with [??? whatever that means]
WantedBy=multi-user.target

#don't forget to enable it: sudo systemctl enable caddy

d. My complete Caddyfile:

# Initial version: 2016-09-26


#||||||||||| domain01.net ||||||||||||||

#redirect www
www.domain01.net {
  	redir https://domain01.net{uri}
}

domain01.net {

    	root /www/domain01.net/public
    	log /www/loganna/domain01.net.access.log
    	errors /www/loganna/domain01.net.error.log
	#compression on    	
	gzip
	#custom server ID
	header / -Server
	header / Server "madraserver 0,1"

}

# |||||||||| domain02.net ||||||||||||||


#redirect www
www.domain02.net {
    	redir https://domain02.net{uri}
}

domain02.net {

    	root /www/domain02.net/public
    	log /www/loganna/domain02.net.access.log
    	errors /www/loganna/domain02.net.error.log
    	#compression on    	
	gzip
	#custom server ID
	header / -Server
	header / Server "madraserver 0,1"

    #Isso Comments
    proxy /isso 127.0.0.1:8080 {
    without /isso
    transparent
    header_upstream X-Script-Name /isso
    }
}

#||||||||||| domain03.net ||||||||||||||

#redirect www
www.domain03.net {
    	redir https://domain03.net{uri}
}

domain03.net {

    	root /www/domain03.net/public
    	log /www/loganna/domain03.net.access.log
    	errors /www/loganna/domain03.net.error.log
  	#compression on    	
	gzip
	#custom server ID
	header / -Server
	header / Server "madraserver 0,1"

    #Isso Comments
    proxy /isso 127.0.0.1:8080 {
    without /isso
    transparent
    header_upstream X-Script-Name /isso
    }
}

#||||||||||| domain04.net ||||||||||||||

#redirect www
www.domain04.net {
    	redir https://domain04.net{uri}
}

domain04.net {

    	root /www/domain04.net/public
    	log /www/loganna/domain04.net.access.log
    	errors /www/loganna/domain04.net.error.log
    	#compression on    	
	gzip
	#custom server ID
	header / -Server
	header / Server "madraserver 0,1"

    #Isso Comments
    proxy /isso 127.0.0.1:8080 {
    without /isso
    transparent
    header_upstream X-Script-Name /isso
    }
}

#||||||||||| domain05.net ||||||||||||||

#redirect www
www.domain05.net {
  	redir https://domain05.net{uri}
}

domain05.net {

    	root /www/domain05.net/public
    	log /www/loganna/domain05.net.access.log
    	errors /www/loganna/domain05.net.error.log
	#compression on    	
	gzip
	#custom server ID
	header / -Server
	header / Server "madraserver 0,1"

}

3. The problem I’m having:

As per others with similar problems. Caddy has been running fine for me for the past three or four years. Earlier this week, I upgraded Caddy to current version. [see above] and now Caddy will no longer start using sudo service caddy start. The Caddyfile validates:

cd /var/www
caddy -validate
Caddyfile is valid

and I can start Caddy from the command line: sudo caddy -conf /var/www/Caddyfile &

[starts and runs fine]

But, when I try sudo service caddy start, I get the following:

sudo service caddy start
Job for caddy.service failed because the control process exited with error code.
See "systemctl status caddy.service" and "journalctl -xe" for details.

4. Error messages and/or full log output:

sudo service caddy status returns the following:

Jan 17 22:25:09 sputnik systemd[1]: caddy.service: Failed with result 'exit-code'.
Jan 17 22:25:09 sputnik systemd[1]: caddy.service: Service hold-off time over, scheduling restart.
Jan 17 22:25:09 sputnik systemd[1]: caddy.service: Scheduled restart job, restart counter is at 5.
Jan 17 22:25:09 sputnik systemd[1]: Stopped Caddy Server.
Jan 17 22:25:09 sputnik systemd[1]: caddy.service: Start request repeated too quickly.
Jan 17 22:25:09 sputnik systemd[1]: caddy.service: Failed with result 'exit-code'.
Jan 17 22:25:09 sputnik systemd[1]: Failed to start Caddy Server.
Jan 17 22:30:43 sputnik systemd[1]: caddy.service: Start request repeated too quickly.
Jan 17 22:30:43 sputnik systemd[1]: caddy.service: Failed with result 'exit-code'.
Jan 17 22:30:43 sputnik systemd[1]: Failed to start Caddy Server.

and journalctl -xe gives me the following error, repeated over and over again:

sputnik caddy[1111]: Activating privacy features... 2020/01/15 21:41:21 decoding certificate metadata: unexpected end of JSON input
Jan 17 20:49:40 sputnik caddy[8608]: Activating privacy features... 2020/01/17 20:49:40 decoding certificate metadata: unexpected end of JSON input
Jan 17 20:49:41 sputnik caddy[8668]: Activating privacy features... 2020/01/17 20:49:41 decoding certificate metadata: unexpected end of JSON input
Jan 17 20:49:41 sputnik caddy[8672]: Activating privacy features... 2020/01/17 20:49:41 decoding certificate metadata: unexpected end of JSON input
Jan 17 20:49:41 sputnik caddy[8676]: Activating privacy features... 2020/01/17 20:49:41 decoding certificate metadata: unexpected end of JSON input
Jan 17 20:49:41 sputnik caddy[8680]: Activating privacy features... 2020/01/17 20:49:41 decoding certificate metadata: unexpected end of JSON input
Jan 17 21:16:28 sputnik caddy[10364]: Activating privacy features... 2020/01/17 21:16:28 decoding certificate metadata: unexpected end of JSON input
Jan 17 21:16:29 sputnik caddy[10423]: Activating privacy features... 2020/01/17 21:16:29 decoding certificate metadata: unexpected end of JSON input
Jan 17 21:16:29 sputnik caddy[10427]: Activating privacy features... 2020/01/17 21:16:29 decoding certificate metadata: unexpected end of JSON input
Jan 17 21:16:29 sputnik caddy[10431]: Activating privacy features... 2020/01/17 21:16:29 decoding certificate metadata: unexpected end of JSON input
Jan 17 21:16:29 sputnik caddy[10435]: Activating privacy features... 2020/01/17 21:16:29 decoding certificate metadata: unexpected end of JSON input
Jan 17 21:25:10 sputnik caddy[12356]: Activating privacy features... 2020/01/17 21:25:10 decoding certificate metadata: unexpected end of JSON input
Jan 17 21:25:10 sputnik caddy[12417]: Activating privacy features... 2020/01/17 21:25:10 decoding certificate metadata: unexpected end of JSON input
Jan 17 21:25:10 sputnik caddy[12421]: Activating privacy features... 2020/01/17 21:25:10 decoding certificate metadata: unexpected end of JSON input
Jan 17 21:25:10 sputnik caddy[12425]: Activating privacy features... 2020/01/17 21:25:10 decoding certificate metadata: unexpected end of JSON input
Jan 17 21:25:10 sputnik caddy[12429]: Activating privacy features... 2020/01/17 21:25:10 decoding certificate metadata: unexpected end of JSON input
Jan 17 21:38:47 sputnik caddy[15243]: Activating privacy features... 2020/01/17 21:38:47 decoding certificate metadata: unexpected end of JSON input
Jan 17 21:38:47 sputnik caddy[15302]: Activating privacy features... 2020/01/17 21:38:47 decoding certificate metadata: unexpected end of JSON input
Jan 17 21:38:48 sputnik caddy[15305]: Activating privacy features... 2020/01/17 21:38:48 decoding certificate metadata: unexpected end of JSON input
Jan 17 21:38:48 sputnik caddy[15309]: Activating privacy features... 2020/01/17 21:38:48 decoding certificate metadata: unexpected end of JSON input
Jan 17 21:38:48 sputnik caddy[15313]: Activating privacy features... 2020/01/17 21:38:48 decoding certificate metadata: unexpected end of JSON input
Jan 17 21:49:45 sputnik caddy[16420]: Activating privacy features... 2020/01/17 21:49:45 decoding certificate metadata: unexpected end of JSON input
Jan 17 21:49:45 sputnik caddy[16482]: Activating privacy features... 2020/01/17 21:49:45 decoding certificate metadata: unexpected end of JSON input
Jan 17 21:49:45 sputnik caddy[16486]: Activating privacy features... 2020/01/17 21:49:45 decoding certificate metadata: unexpected end of JSON input
Jan 17 21:49:46 sputnik caddy[16490]: Activating privacy features... 2020/01/17 21:49:46 decoding certificate metadata: unexpected end of JSON input
Jan 17 21:49:46 sputnik caddy[16493]: Activating privacy features... 2020/01/17 21:49:46 decoding certificate metadata: unexpected end of JSON input
Jan 17 21:50:08 sputnik caddy[16634]: Activating privacy features... 2020/01/17 21:50:08 decoding certificate metadata: unexpected end of JSON input
Jan 17 21:50:08 sputnik caddy[16692]: Activating privacy features... 2020/01/17 21:50:08 decoding certificate metadata: unexpected end of JSON input
Jan 17 21:50:08 sputnik caddy[16696]: Activating privacy features... 2020/01/17 21:50:08 decoding certificate metadata: unexpected end of JSON input
Jan 17 21:50:08 sputnik caddy[16700]: Activating privacy features... 2020/01/17 21:50:08 decoding certificate metadata: unexpected end of JSON input
Jan 17 21:50:09 sputnik caddy[16704]: Activating privacy features... 2020/01/17 21:50:09 decoding certificate metadata: unexpected end of JSON input

5. What I already tried:

As per above, starting from service doesn’t work. Starting from command line does. Caddy has previously been running flawlessly for almost four years with the same setup.

Any suggestions?

The error suggests a problem with parsing JSON somehwere along the line but I’m still on version 1,XX and I thought the JSON [Caddyfile?] formatting was something that wasn’t implemented til version 2. So I’m not sure why my previously working setup has suddenly broken with a point upgrade… although, come to think of it, I may have been on a 0,XX version before upgrading.

Was there a breaking change between 0,XX and 1,0 too that I should have known about?

stiobhart · January 17, 2020, 11:03pm

Just another thing to add to the mix. As my caddy.service is set to exec Caddy as madra:www-data I realised that directly running it from the CLI with sudo would be launching Caddy as root.

So I cd'd to my Caddyfile directory and ran caddy -conf /var/www/Caddyfile & [without sudo - I am logged in as user ‘madra’] and got a similar error to trying to start it via the service:

caddy -conf /var/www/Caddyfile &
[1] 21094
Activating privacy features... 2020/01/17 22:54:07 decoding certificate metadata: unexpected end of JSON input
[1]  + 21094 exit 1     caddy -conf /var/www/Caddyfile

Now that makes it looked like a permissions problem somewhere. In which case those JSON errors showing up in the logs seem very spurious. I still can’t work out what’s gone wrong though. Is there a list somewhere of what the various permissions should be on; caddy binary, Caddyfile, linux socket, Letsencrypt certs directories, etc.?

stiobhart · January 18, 2020, 11:35am

Yay! ––solved it.

Seeing as how the whole sudo / non-sudo thing suggested a permissions problem and the [spurious!] error message referred to mal-formed JSON in the certificates files, I decided to take a look at my ~/.caddy directory and check out the permissions on the certificates and associated directories:

cd ~/.caddy && ls -al
total 20
drwx------  5 madra madra    4096 Jan 15 21:16 .
drwxr-xr-x 18 madra madra    4096 Jan 18 11:14 ..
drwx------  4 madra madra    4096 Jan 15 20:54 acme
drwx------  2 madra www-data 4096 Jan 15 21:16 locks
drwx------  2 madra madra    4096 Jan 15 21:16 ocsp

So a couple of the directories weren’t owned by the www-data group under which Caddy runs. I did a quick:

sudo chown -R madra:www-data *

and double-checked:

ls -al
total 20
drwx------  5 madra madra    4096 Jan 15 21:16 .
drwxr-xr-x 18 madra madra    4096 Jan 18 11:21 ..
drwx------  4 madra www-data 4096 Jan 15 20:54 acme
drwx------  2 madra www-data 4096 Jan 15 21:16 locks
drwx------  2 madra www-data 4096 Jan 15 21:16 ocsp

Then ran sudo service caddy start again and my server fired up without a problem.

sudo service caddy start
sudo service caddy status
● caddy.service - Caddy Server
   Loaded: loaded (/etc/systemd/system/caddy.service; enabled; vendor preset: enabled)
   Active: active (running) since Sat 2020-01-18 11:16:36 GMT; 3s ago
 Main PID: 24356 (caddy)
    Tasks: 7 (limit: 1148)
   CGroup: /system.slice/caddy.service
           └─24356 /usr/local/bin/caddy -agree -email xxxx@xxxx.net -pidfile=/var/run/caddy/caddy.pid

<snip>

So, for anyone else who runs into this unexpected end of JSON input error. Take a look and see if the user Caddy is running under can actually access the various files and directories in ~/.caddy.

And @Caddy Devs –you might want to take a look at that error message and see if it’s possible to make a distinction between a certificate containing malformed JSON and Caddy being unable to access the certificate in the first place. The current error message is pretty unhelpful and misleading.

matt · January 18, 2020, 4:23pm

Thanks for the investigation!

I’m not sure how we can get the message more helpful: apparently the OS is reporting that the file was successfully opened, otherwise we would report that error. It seems that the actual Read calls are failing, hence “unexpected end of input” as opposed to “permissions error”.

system · April 17, 2020, 4:23pm

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.