What steps will reproduce the problem?
1. Put password protected private key and the corresponding certificate in place (certs folder)
2. Create vhost and add ssl definition to it including the password
3. Power the server off and on again
What is the expected output?
Prosody should find and load the ssl certificate
What do you see instead?
"No certificate/key found for <vhost>"
What version of the product are you using? On what operating system?
0.11.5
Please provide any additional information below.
Starting prosody manually with "prosodyctl start" is working.
Anon Ymus
on
Defining ssl in the global section helped me with this one. Issue can be closed. Thanks
Zash
on
Hey. What exactly did you put in your config? Per-host `ssl` sections are supposed to work.
Zash
on
Hey. What exactly did you put in your config? Per-vhost `ssl` sections are supposed to work.
Changes
tags Status-NeedInfo
Anon Ymus
on
Hello, I put it like this:
ssl = {
key = "/path/to/key.pem";
certificate = "/path/to/cert.pem";
password = "passwordforkey";
}
Anon Ymus
on
Update: it seems my issue is not resolved different to what I stated earlier. Any ideas what could be wrong? I am not sure anymore about the cause of the problem (Prosody does not autostart on Debian although installed through repository like so https://prosody.im/download/package_repository).
Zash
on
This is not enough information to go on. Please provide the full config file.
Have you tested whether TLS works?
Could you paste the full log line and some surrounding lines please.
Anon Ymus
on
I am using the default, don´t know if it is TLS.
On the first start of the machine there is only this in the logs:
startup info Hello and welcome to Prosody version 0.11.5
stats debug Statistics disabled
and that´s it.
I changed the config slightly, save it shutdown and start the machine again and the log looks like this:
startup info Hello and welcome to Prosody version 0.11.5
stats debug Statistics disabled
certmanager debug Searching /etc/prosody/certs for a key and certificate for client_https...
certmanager debug No certificate/key found for client_https
startup info Prosody is using the select backend for connection handling
hostmanager debug Activated host: localhost
usermanager debug Host 'localhost' now set to use user provider 'internal_hashed'
storagemanager debug map storage driver unavailable, using shim on top of keyval store.
storagemanager debug map storage driver unavailable, using shim on top of keyval store.
modulemanager debug pep is already loaded for localhost, so not loading again
localhost:tls debug Creating context for c2s
certmanager debug Searching /etc/prosody/certs for a key and certificate for localhost...
certmanager debug Selecting certificate /etc/prosody/certs/localhost.crt with key /etc/prosody/certs/localhost.key for localhost
localhost:tls debug Creating context for s2sout
certmanager debug Searching /etc/prosody/certs for a key and certificate for localhost...
certmanager debug Selecting certificate /etc/prosody/certs/localhost.crt with key /etc/prosody/certs/localhost.key for localhost
localhost:tls debug Creating context for s2sin
certmanager debug Searching /etc/prosody/certs for a key and certificate for localhost...
certmanager debug Selecting certificate /etc/prosody/certs/localhost.crt with key /etc/prosody/certs/localhost.key for localhost
portmanager debug No active service for c2s, activating...
socket debug server.lua: new server listener on '[*]:5222'
portmanager debug Added listening service c2s to [*]:5222
socket debug server.lua: new server listener on '[::]:5222'
portmanager debug Added listening service c2s to [::]:5222
portmanager info Activated service 'c2s' on [*]:5222, [::]:5222
portmanager debug No active service for legacy_ssl, activating...
portmanager info Activated service 'legacy_ssl' on no ports
hostmanager debug Activated host: my-server.domain.tld
usermanager debug Host 'my-server.domain.tld' now set to use user provider 'internal_hashed'
storagemanager debug map storage driver unavailable, using shim on top of keyval store.
storagemanager debug map storage driver unavailable, using shim on top of keyval store.
modulemanager debug pep is already loaded for my-server.domain.tld, so not loading again
my-server.domain.tld:tls debug Creating context for c2s
certmanager debug Searching /etc/prosody/certs for a key and certificate for my-server.domain.tld...
certmanager debug No certificate/key found for my-server.domain.tld
certmanager debug Searching /etc/prosody/certs for a key and certificate for domain.tld...
certmanager debug No certificate/key found for domain.tld
certmanager debug Searching /etc/prosody/certs for a key and certificate for de...
certmanager debug No certificate/key found for de
my-server.domain.tld:tls debug Creating context for s2sout
certmanager debug Searching /etc/prosody/certs for a key and certificate for my.domain.tld...
certmanager debug No certificate/key found for my-server.domain.tld
certmanager debug Searching /etc/prosody/certs for a key and certificate for domain.tld...
certmanager debug No certificate/key found for domain.tld
certmanager debug Searching /etc/prosody/certs for a key and certificate for de...
certmanager debug No certificate/key found for de
my-server.domain.tld:tls debug Creating context for s2sin
certmanager debug Searching /etc/prosody/certs for a key and certificate for my-server.domain.tld...
certmanager debug No certificate/key found for my-server.domain.tld
certmanager debug Searching /etc/prosody/certs for a key and certificate for domain.tld...
certmanager debug No certificate/key found for domain.tld
certmanager debug Searching /etc/prosody/certs for a key and certificate for de...
certmanager debug No certificate/key found for de
socket debug server.lua: accepted new client connection from ###.###.###.###:#### to 5222
a1b2c3d4e5f6g7 info Client connected
a1b2c3d4e5f6g7 debug Client sent opening <stream:stream> to my-server.domain.tld
a1b2c3d4e5f6g7 debug Sending[c2s_unauthed]: <?xml version='1.0'?>
a1b2c3d4e5f6g7 debug Sending[c2s_unauthed]: <stream:stream version='1.0' from='my-server.domain.tld' id='#######' xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' xml:lang='en'>
a1b2c3d4e5f6g7 debug Sent reply <stream:stream> to client
a1b2c3d4e5f6g7 debug Not offering authentication on insecure connection
a1b2c3d4e5f6g7 debug Sending[c2s_unauthed]: <stream:features>
runner####### debug creating new coroutine
a1b2c3d4e5f6g7 debug Received[c2s_unauthed]: <starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'>
a1b2c3d4e5f6g7 debug Sending[c2s_unauthed]: <proceed xmlns='urn:ietf:params:xml:ns:xmpp-tls'>
socket debug server.lua: we need to do tls, but delaying until send buffer empty
a1b2c3d4e5f6g7 debug TLS negotiation started for c2s_unauthed...
socket debug server.lua: attempting to start tls on tcp{client}: #######
socket debug server.lua: ssl handshake done
a1b2c3d4e5f6g7 debug Client sent opening <stream:stream> to my-server.domain.tld
a1b2c3d4e5f6g7 debug Sending[c2s_unauthed]: <?xml version='1.0'?>
a1b2c3d4e5f6g7 debug Sending[c2s_unauthed]: <stream:stream version='1.0' from='my-server.domain.tld' id='#######' xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' xml:lang='en'>
a1b2c3d4e5f6g7 debug Sent reply <stream:stream> to client
a1b2c3d4e5f6g7 info Stream encrypted (TLSv1.2 with ECDHE-RSA-AES256-GCM-SHA384)
a1b2c3d4e5f6g7 debug Offering mechanism PLAIN
a1b2c3d4e5f6g7 debug Offering mechanism SCRAM-SHA-1-PLUS
a1b2c3d4e5f6g7 debug Offering mechanism SCRAM-SHA-1
a1b2c3d4e5f6g7 debug Sending[c2s_unauthed]: <stream:features>
a1b2c3d4e5f6g7 debug Received[c2s_unauthed]: <auth xmlns='urn:ietf:params:xml:ns:xmpp-sasl' mechanism='SCRAM-SHA-1'>
my-server.domain.tld:saslauth debug sasl reply: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>#######=</challenge>
a1b2c3d4e5f6g7 debug Sending[c2s_unauthed]: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>
a1b2c3d4e5f6g7 debug Received[c2s_unauthed]: <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>
a1b2c3d4e5f6g7 info Authenticated as client@my-server.domain.tld
my-server.domain.tld:saslauth debug sasl reply: <success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>#######</success>
a1b2c3d4e5f6g7 debug Sending[c2s_unbound]: <success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>
a1b2c3d4e5f6g7 debug Client sent opening <stream:stream> to my-server.domain.tld
a1b2c3d4e5f6g7 debug Sending[c2s_unbound]: <?xml version='1.0'?>
a1b2c3d4e5f6g7 debug Sending[c2s_unbound]: <stream:stream version='1.0' from='my-server.domain.tld' id='#######' xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' xml:lang='en'>
a1b2c3d4e5f6g7 debug Sent reply <stream:stream> to client
a1b2c3d4e5f6g7 debug Sending[c2s_unbound]: <stream:features>
a1b2c3d4e5f6g7 debug Received[c2s_unbound]: <iq type='set' id='#######'>
rostermanager debug load_roster: asked for: client@my-server.domain.tld
rostermanager debug load_roster: loading for new user: client@my-server.domain.tld
a1b2c3d4e5f6g7 debug No legacy vCard to migrate or already migrated
a1b2c3d4e5f6g7 debug Sending[c2s]: <iq type='result' id='#######'>
a1b2c3d4e5f6g7 debug Resource bound: client@my-server.domain.tld/clientapp
a1b2c3d4e5f6g7 debug Received[c2s]: <iq type='get' id='#######'>
a1b2c3d4e5f6g7 debug Sending[c2s]: <iq type='result' to='client@my-server.domain.tld/clientapp' id='#######'>
a1b2c3d4e5f6g7 debug Received[c2s]: <iq type='get' id='#######'>
my-server.domain.tld:pep debug get_pep_service("client")
my-server.domain.tld:pep debug Creating new persistent item store for user client, node "#######"
my-server.domain.tld:pep debug Creation of itemstore for node ####### with config table: #######
my-server.domain.tld:pep debug Creating new persistent item store for user client, node "#######"
my-server.domain.tld:pep debug Creation of itemstore for node ####### with config table: #######
my-server.domain.tld:pep debug Restoring nodes for user client
my-server.domain.tld:pep debug Restoring node "#######"
my-server.domain.tld:pep debug Restoring node "#######"
a1b2c3d4e5f6g7 debug Sending[c2s]: <iq type='result' to='client@my-server.domain.tld/clientapp' id='#######'>
a1b2c3d4e5f6g7 debug Received[c2s]: <presence id='#######'>
my-server.domain.tld:pep debug get_pep_service("client")
a1b2c3d4e5f6g7 debug Sending[c2s]: <iq type='get' to='client@my-server.domain.tld/clientapp' from='client@my-server.domain.tld' id='disco'>
a1b2c3d4e5f6g7 debug Sending[c2s]: <presence from='client@my-server.domain.tld/clientapp' id='#######'>
my-server.domain.tld:pep debug get_pep_service("client")
a1b2c3d4e5f6g7 debug Sending[c2s]: <iq type='get' to='client@my-server.domain.tld/clientapp' from='client1@my-server.domain.tld' id='disco'>
my-server.domain.tld:presence debug outbound presence probe from client@my-server.domain.tld for client1@my-server.domain.tld
my-server.domain.tld:presence debug inbound presence probe from client@my-server.domain.tld for client1@my-server.domain.tld
my-server.domain.tld:presence debug broadcasted presence of 0 resources from client1@my-server.domain.tld to client@my-server.domain.tld/clientapp
a1b2c3d4e5f6g7 debug Sending[c2s]: <presence type='unavailable' from='client1@my-server.domain.tld' to='client@my-server.domain.tld/clientapp'>
datamanager debug Removing empty offline datastore for user client@my-server.domain.tld
a1b2c3d4e5f6g7 debug Received[c2s]: <presence id='#######'>
my-server.domain.tld:pep debug get_pep_service("client")
a1b2c3d4e5f6g7 debug Sending[c2s]: <iq type='get' to='client@my-server.domain.tld/clientapp' from='client@my-server.domain.tld' id='disco'>
a1b2c3d4e5f6g7 debug Sending[c2s]: <presence from='client@my-server.domain.tld/clientapp' id='#######'>
my-server.domain.tld:pep debug get_pep_service("client")
a1b2c3d4e5f6g7 debug Sending[c2s]: <iq type='get' to='client@my-server.domain.tld/clientapp' from='client1@my-server.domain.tld' id='disco'>
a1b2c3d4e5f6g7 debug Received[c2s]: <iq type='result' to='client@my-server.domain.tld' id='disco'>
stanzarouter debug Discarding iq from c2s of type: result
a1b2c3d4e5f6g7 debug Received[c2s]: <iq type='get' to='client@my-server.domain.tld' id='#######'>
my-server.domain.tld:pep debug get_pep_service("client")
a1b2c3d4e5f6g7 debug Sending[c2s]: <iq type='result' to='client@my-server.domain.tld/clientapp' id='#######'>
a1b2c3d4e5f6g7 debug Received[c2s]: <presence id='#######'>
my-server.domain.tld:pep debug get_pep_service("client")
a1b2c3d4e5f6g7 debug Sending[c2s]: <iq type='get' to='client@my-server.domain.tld/clientapp' from='client@my-server.domain.tld' id='disco'>
a1b2c3d4e5f6g7 debug Sending[c2s]: <presence from='client@my-server.domain.tld/clientapp' id='#######'>
my-server.domain.tld:pep debug get_pep_service("client")
a1b2c3d4e5f6g7 debug Sending[c2s]: <iq type='get' to='client@my-server.domain.tld/clientapp' from='client1@my-server.domain.tld' id='disco'>
a1b2c3d4e5f6g7 debug Received[c2s]: <iq type='result' to='client1@my-server.domain.tld' id='disco'>
stanzarouter debug Discarding iq from c2s of type: result
a1b2c3d4e5f6g7 debug Received[c2s]: <presence id='#######'>
my-server.domain.tld:pep debug get_pep_service("client")
a1b2c3d4e5f6g7 debug Sending[c2s]: <iq type='get' to='client@my-server.domain.tld/clientapp' from='client@my-server.domain.tld' id='disco'>
a1b2c3d4e5f6g7 debug Sending[c2s]: <presence from='client@my-server.domain.tld/clientapp' id='#######'>
my-server.domain.tld:pep debug get_pep_service("client")
a1b2c3d4e5f6g7 debug Sending[c2s]: <iq type='get' to='client@my-server.domain.tld/clientapp' from='client1@my-server.domain.tld' id='disco'>
a1b2c3d4e5f6g7 debug Received[c2s]: <iq type='result' to='client@my-server.domain.tld' id='disco'>
stanzarouter debug Discarding iq from c2s of type: result
a1b2c3d4e5f6g7 debug Received[c2s]: <iq type='result' to='client1@my-server.domain.tld' id='disco'>
stanzarouter debug Discarding iq from c2s of type: result
a1b2c3d4e5f6g7 debug Received[c2s]: <iq type='set' id='#######'>
my-server.domain.tld:carbons debug client@my-server.domain.tld/clientapp enabled carbons
a1b2c3d4e5f6g7 debug Sending[c2s]: <iq type='result' to='client@my-server.domain.tld/clientapp' id='#######'>
a1b2c3d4e5f6g7 debug Received[c2s]: <iq type='get' to='my-server.domain.tld' id='#######'>
a1b2c3d4e5f6g7 debug Sending[c2s]: <iq type='result' from='my-server.domain.tld' to='client@my-server.domain.tld/clientapp' id='#######'>
a1b2c3d4e5f6g7 debug Received[c2s]: <iq type='result' to='client@my-server.domain.tld' id='disco'>
stanzarouter debug Discarding iq from c2s of type: result
a1b2c3d4e5f6g7 debug Received[c2s]: <iq type='result' to='client1@my-server.domain.tld' id='disco'>
stanzarouter debug Discarding iq from c2s of type: result
a1b2c3d4e5f6g7 debug Received[c2s]: <iq type='result' to='client@my-server.domain.tld' id='disco'>
stanzarouter debug Discarding iq from c2s of type: result
a1b2c3d4e5f6g7 debug Received[c2s]: <iq type='result' to='client1@my-server.domain.tld' id='disco'>
stanzarouter debug Discarding iq from c2s of type: result
a1b2c3d4e5f6g7 debug Received[c2s]: <iq type='get' to='my-server.domain.tld' id='#######'>
stanzarouter debug Unhandled c2s stanza: iq; xmlns=http://jabber.org/protocol/jinglenodes
a1b2c3d4e5f6g7 debug Sending[c2s]: <iq type='error' from='my-server.domain.tld' to='client@my-server.domain.tld/clientapp' id='#######'>
Zash
on
What you reported are debug messages, not errors. The solution is to disable debug logging and stop worrying. Your log shows TLS enabled successfully, so the configured certificate must be working.
Those are completely harmless, Prosody is looking for certs as per automatic zero-config certificate location. This happens before adding settings from the config. Ignore it.
Changes
tags Status-Invalid
Anon Ymus
on
I am not sure if you understood the issue. When the machine starts the very first time prosody does not start automatically although enabled within systemd on Debian. I have to login and start it manually. The log I posted is after I shut down the machine after the very first boot and started it again. So the question is why isn´t prosody start at the very first time.
Zash
on
Ok, sorry. I was confused by mention of certificate things.
After it just stops, what does systemd report as its status? Are there any traces in syslog or the journal?
Changes
tagsStatus-Invalid Status-NeedInfo
Anon Ymus
on
Here is an syslog-excerpt of the very first start:
systemd: Started Login Service.
systemd: Starting Raise network interfaces...
systemd: Started Raise network interfaces.
systemd: Reached target Network.
systemd: Starting Permit User Sessions...
systemd: Starting OpenBSD Secure Shell server...
systemd: Reached target Network is Online.
systemd: Started Prosody XMPP Server.
systemd: Starting Daily apt download activities...
systemd: Started Permit User Sessions.
systemd: Started Getty on tty1.
systemd: Reached target Login Prompts.
systemd: Reloading Prosody XMPP Server.
systemd: Reloaded Prosody XMPP Server.
systemd: prosody.service: Main process exited, code=killed, status=1/HUP
systemd: prosody.service: Succeeded.
rsyslogd: rsyslogd was HUPed
rsyslogd: rsyslogd was HUPed
systemd: logrotate.service: Succeeded.
After shutting down and starting again the reloading part is not shown again. Only "Started Prosody XMPP Server".
Zash
on
That's weird. So, it's being sent the reload signal before it has set up signal handling, which results in the default signal action of being killed.
Changes
tags Status-Accepted
Anon Ymus
on
I´m glad we narrowed it down.
Anon Ymus
on
Any progress on this one? Have you been able to reproduce/find the reason for this issue?
Zash
on
No progress, sorry.
Anon Ymus
on
I solved this issue by changing the following parameter of the prosody service file found under /lib/systemd/system/prosody.service:
Restart=on-abnormal
changed to
Restart=always
With this change prosody will not fail to start anymore.
Anon Ymus
on
I want to revert my previous comment because this issue might be caused by the definition of the pid-file in prosody.cfg.lua. I commented it out and it is working fine so far even without changing anything in the prosody.service file mentioned above.
What steps will reproduce the problem? 1. Put password protected private key and the corresponding certificate in place (certs folder) 2. Create vhost and add ssl definition to it including the password 3. Power the server off and on again What is the expected output? Prosody should find and load the ssl certificate What do you see instead? "No certificate/key found for <vhost>" What version of the product are you using? On what operating system? 0.11.5 Please provide any additional information below. Starting prosody manually with "prosodyctl start" is working.
Defining ssl in the global section helped me with this one. Issue can be closed. Thanks
Hey. What exactly did you put in your config? Per-host `ssl` sections are supposed to work.
Hey. What exactly did you put in your config? Per-vhost `ssl` sections are supposed to work.
ChangesHello, I put it like this: ssl = { key = "/path/to/key.pem"; certificate = "/path/to/cert.pem"; password = "passwordforkey"; }
Update: it seems my issue is not resolved different to what I stated earlier. Any ideas what could be wrong? I am not sure anymore about the cause of the problem (Prosody does not autostart on Debian although installed through repository like so https://prosody.im/download/package_repository).
This is not enough information to go on. Please provide the full config file.
The config looks like this: admins = { } modules_enabled = { "roster"; "saslauth"; "tls"; "dialback"; "disco"; "carbons"; "pep"; "private"; "vcard4"; "vcard_legacy"; "version"; "uptime"; "time"; "ping"; "register"; "admin_adhoc"; } modules_disabled = { "s2s"; } allow_registration = false ssl = { key = "/etc/prosody/certs/key.pem"; certificate = "/etc/prosody/certs/cert.pem"; password = "############"; } c2s_require_encryption = true s2s_require_encryption = true s2s_secure_auth = true pidfile = "prosody.pid" authentication = "internal_hashed" archive_expires_after = "1w" log = { debug = "/var/log/prosody/prosody.log"; error = "/var/log/prosody/prosody.err"; } certificates = "certs" VirtualHost "localhost" VirtualHost "my-server.domain.tld" enabled = true ssl = { key = "/etc/prosody/certs/key.pem"; certificate = "/etc/prosody/certs/cert.pem"; password = "############"; }
Have you tested whether TLS works? Could you paste the full log line and some surrounding lines please.
I am using the default, don´t know if it is TLS. On the first start of the machine there is only this in the logs: startup info Hello and welcome to Prosody version 0.11.5 stats debug Statistics disabled and that´s it. I changed the config slightly, save it shutdown and start the machine again and the log looks like this: startup info Hello and welcome to Prosody version 0.11.5 stats debug Statistics disabled certmanager debug Searching /etc/prosody/certs for a key and certificate for client_https... certmanager debug No certificate/key found for client_https startup info Prosody is using the select backend for connection handling hostmanager debug Activated host: localhost usermanager debug Host 'localhost' now set to use user provider 'internal_hashed' storagemanager debug map storage driver unavailable, using shim on top of keyval store. storagemanager debug map storage driver unavailable, using shim on top of keyval store. modulemanager debug pep is already loaded for localhost, so not loading again localhost:tls debug Creating context for c2s certmanager debug Searching /etc/prosody/certs for a key and certificate for localhost... certmanager debug Selecting certificate /etc/prosody/certs/localhost.crt with key /etc/prosody/certs/localhost.key for localhost localhost:tls debug Creating context for s2sout certmanager debug Searching /etc/prosody/certs for a key and certificate for localhost... certmanager debug Selecting certificate /etc/prosody/certs/localhost.crt with key /etc/prosody/certs/localhost.key for localhost localhost:tls debug Creating context for s2sin certmanager debug Searching /etc/prosody/certs for a key and certificate for localhost... certmanager debug Selecting certificate /etc/prosody/certs/localhost.crt with key /etc/prosody/certs/localhost.key for localhost portmanager debug No active service for c2s, activating... socket debug server.lua: new server listener on '[*]:5222' portmanager debug Added listening service c2s to [*]:5222 socket debug server.lua: new server listener on '[::]:5222' portmanager debug Added listening service c2s to [::]:5222 portmanager info Activated service 'c2s' on [*]:5222, [::]:5222 portmanager debug No active service for legacy_ssl, activating... portmanager info Activated service 'legacy_ssl' on no ports hostmanager debug Activated host: my-server.domain.tld usermanager debug Host 'my-server.domain.tld' now set to use user provider 'internal_hashed' storagemanager debug map storage driver unavailable, using shim on top of keyval store. storagemanager debug map storage driver unavailable, using shim on top of keyval store. modulemanager debug pep is already loaded for my-server.domain.tld, so not loading again my-server.domain.tld:tls debug Creating context for c2s certmanager debug Searching /etc/prosody/certs for a key and certificate for my-server.domain.tld... certmanager debug No certificate/key found for my-server.domain.tld certmanager debug Searching /etc/prosody/certs for a key and certificate for domain.tld... certmanager debug No certificate/key found for domain.tld certmanager debug Searching /etc/prosody/certs for a key and certificate for de... certmanager debug No certificate/key found for de my-server.domain.tld:tls debug Creating context for s2sout certmanager debug Searching /etc/prosody/certs for a key and certificate for my.domain.tld... certmanager debug No certificate/key found for my-server.domain.tld certmanager debug Searching /etc/prosody/certs for a key and certificate for domain.tld... certmanager debug No certificate/key found for domain.tld certmanager debug Searching /etc/prosody/certs for a key and certificate for de... certmanager debug No certificate/key found for de my-server.domain.tld:tls debug Creating context for s2sin certmanager debug Searching /etc/prosody/certs for a key and certificate for my-server.domain.tld... certmanager debug No certificate/key found for my-server.domain.tld certmanager debug Searching /etc/prosody/certs for a key and certificate for domain.tld... certmanager debug No certificate/key found for domain.tld certmanager debug Searching /etc/prosody/certs for a key and certificate for de... certmanager debug No certificate/key found for de socket debug server.lua: accepted new client connection from ###.###.###.###:#### to 5222 a1b2c3d4e5f6g7 info Client connected a1b2c3d4e5f6g7 debug Client sent opening <stream:stream> to my-server.domain.tld a1b2c3d4e5f6g7 debug Sending[c2s_unauthed]: <?xml version='1.0'?> a1b2c3d4e5f6g7 debug Sending[c2s_unauthed]: <stream:stream version='1.0' from='my-server.domain.tld' id='#######' xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' xml:lang='en'> a1b2c3d4e5f6g7 debug Sent reply <stream:stream> to client a1b2c3d4e5f6g7 debug Not offering authentication on insecure connection a1b2c3d4e5f6g7 debug Sending[c2s_unauthed]: <stream:features> runner####### debug creating new coroutine a1b2c3d4e5f6g7 debug Received[c2s_unauthed]: <starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'> a1b2c3d4e5f6g7 debug Sending[c2s_unauthed]: <proceed xmlns='urn:ietf:params:xml:ns:xmpp-tls'> socket debug server.lua: we need to do tls, but delaying until send buffer empty a1b2c3d4e5f6g7 debug TLS negotiation started for c2s_unauthed... socket debug server.lua: attempting to start tls on tcp{client}: ####### socket debug server.lua: ssl handshake done a1b2c3d4e5f6g7 debug Client sent opening <stream:stream> to my-server.domain.tld a1b2c3d4e5f6g7 debug Sending[c2s_unauthed]: <?xml version='1.0'?> a1b2c3d4e5f6g7 debug Sending[c2s_unauthed]: <stream:stream version='1.0' from='my-server.domain.tld' id='#######' xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' xml:lang='en'> a1b2c3d4e5f6g7 debug Sent reply <stream:stream> to client a1b2c3d4e5f6g7 info Stream encrypted (TLSv1.2 with ECDHE-RSA-AES256-GCM-SHA384) a1b2c3d4e5f6g7 debug Offering mechanism PLAIN a1b2c3d4e5f6g7 debug Offering mechanism SCRAM-SHA-1-PLUS a1b2c3d4e5f6g7 debug Offering mechanism SCRAM-SHA-1 a1b2c3d4e5f6g7 debug Sending[c2s_unauthed]: <stream:features> a1b2c3d4e5f6g7 debug Received[c2s_unauthed]: <auth xmlns='urn:ietf:params:xml:ns:xmpp-sasl' mechanism='SCRAM-SHA-1'> my-server.domain.tld:saslauth debug sasl reply: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>#######=</challenge> a1b2c3d4e5f6g7 debug Sending[c2s_unauthed]: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'> a1b2c3d4e5f6g7 debug Received[c2s_unauthed]: <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'> a1b2c3d4e5f6g7 info Authenticated as client@my-server.domain.tld my-server.domain.tld:saslauth debug sasl reply: <success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>#######</success> a1b2c3d4e5f6g7 debug Sending[c2s_unbound]: <success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'> a1b2c3d4e5f6g7 debug Client sent opening <stream:stream> to my-server.domain.tld a1b2c3d4e5f6g7 debug Sending[c2s_unbound]: <?xml version='1.0'?> a1b2c3d4e5f6g7 debug Sending[c2s_unbound]: <stream:stream version='1.0' from='my-server.domain.tld' id='#######' xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' xml:lang='en'> a1b2c3d4e5f6g7 debug Sent reply <stream:stream> to client a1b2c3d4e5f6g7 debug Sending[c2s_unbound]: <stream:features> a1b2c3d4e5f6g7 debug Received[c2s_unbound]: <iq type='set' id='#######'> rostermanager debug load_roster: asked for: client@my-server.domain.tld rostermanager debug load_roster: loading for new user: client@my-server.domain.tld a1b2c3d4e5f6g7 debug No legacy vCard to migrate or already migrated a1b2c3d4e5f6g7 debug Sending[c2s]: <iq type='result' id='#######'> a1b2c3d4e5f6g7 debug Resource bound: client@my-server.domain.tld/clientapp a1b2c3d4e5f6g7 debug Received[c2s]: <iq type='get' id='#######'> a1b2c3d4e5f6g7 debug Sending[c2s]: <iq type='result' to='client@my-server.domain.tld/clientapp' id='#######'> a1b2c3d4e5f6g7 debug Received[c2s]: <iq type='get' id='#######'> my-server.domain.tld:pep debug get_pep_service("client") my-server.domain.tld:pep debug Creating new persistent item store for user client, node "#######" my-server.domain.tld:pep debug Creation of itemstore for node ####### with config table: ####### my-server.domain.tld:pep debug Creating new persistent item store for user client, node "#######" my-server.domain.tld:pep debug Creation of itemstore for node ####### with config table: ####### my-server.domain.tld:pep debug Restoring nodes for user client my-server.domain.tld:pep debug Restoring node "#######" my-server.domain.tld:pep debug Restoring node "#######" a1b2c3d4e5f6g7 debug Sending[c2s]: <iq type='result' to='client@my-server.domain.tld/clientapp' id='#######'> a1b2c3d4e5f6g7 debug Received[c2s]: <presence id='#######'> my-server.domain.tld:pep debug get_pep_service("client") a1b2c3d4e5f6g7 debug Sending[c2s]: <iq type='get' to='client@my-server.domain.tld/clientapp' from='client@my-server.domain.tld' id='disco'> a1b2c3d4e5f6g7 debug Sending[c2s]: <presence from='client@my-server.domain.tld/clientapp' id='#######'> my-server.domain.tld:pep debug get_pep_service("client") a1b2c3d4e5f6g7 debug Sending[c2s]: <iq type='get' to='client@my-server.domain.tld/clientapp' from='client1@my-server.domain.tld' id='disco'> my-server.domain.tld:presence debug outbound presence probe from client@my-server.domain.tld for client1@my-server.domain.tld my-server.domain.tld:presence debug inbound presence probe from client@my-server.domain.tld for client1@my-server.domain.tld my-server.domain.tld:presence debug broadcasted presence of 0 resources from client1@my-server.domain.tld to client@my-server.domain.tld/clientapp a1b2c3d4e5f6g7 debug Sending[c2s]: <presence type='unavailable' from='client1@my-server.domain.tld' to='client@my-server.domain.tld/clientapp'> datamanager debug Removing empty offline datastore for user client@my-server.domain.tld a1b2c3d4e5f6g7 debug Received[c2s]: <presence id='#######'> my-server.domain.tld:pep debug get_pep_service("client") a1b2c3d4e5f6g7 debug Sending[c2s]: <iq type='get' to='client@my-server.domain.tld/clientapp' from='client@my-server.domain.tld' id='disco'> a1b2c3d4e5f6g7 debug Sending[c2s]: <presence from='client@my-server.domain.tld/clientapp' id='#######'> my-server.domain.tld:pep debug get_pep_service("client") a1b2c3d4e5f6g7 debug Sending[c2s]: <iq type='get' to='client@my-server.domain.tld/clientapp' from='client1@my-server.domain.tld' id='disco'> a1b2c3d4e5f6g7 debug Received[c2s]: <iq type='result' to='client@my-server.domain.tld' id='disco'> stanzarouter debug Discarding iq from c2s of type: result a1b2c3d4e5f6g7 debug Received[c2s]: <iq type='get' to='client@my-server.domain.tld' id='#######'> my-server.domain.tld:pep debug get_pep_service("client") a1b2c3d4e5f6g7 debug Sending[c2s]: <iq type='result' to='client@my-server.domain.tld/clientapp' id='#######'> a1b2c3d4e5f6g7 debug Received[c2s]: <presence id='#######'> my-server.domain.tld:pep debug get_pep_service("client") a1b2c3d4e5f6g7 debug Sending[c2s]: <iq type='get' to='client@my-server.domain.tld/clientapp' from='client@my-server.domain.tld' id='disco'> a1b2c3d4e5f6g7 debug Sending[c2s]: <presence from='client@my-server.domain.tld/clientapp' id='#######'> my-server.domain.tld:pep debug get_pep_service("client") a1b2c3d4e5f6g7 debug Sending[c2s]: <iq type='get' to='client@my-server.domain.tld/clientapp' from='client1@my-server.domain.tld' id='disco'> a1b2c3d4e5f6g7 debug Received[c2s]: <iq type='result' to='client1@my-server.domain.tld' id='disco'> stanzarouter debug Discarding iq from c2s of type: result a1b2c3d4e5f6g7 debug Received[c2s]: <presence id='#######'> my-server.domain.tld:pep debug get_pep_service("client") a1b2c3d4e5f6g7 debug Sending[c2s]: <iq type='get' to='client@my-server.domain.tld/clientapp' from='client@my-server.domain.tld' id='disco'> a1b2c3d4e5f6g7 debug Sending[c2s]: <presence from='client@my-server.domain.tld/clientapp' id='#######'> my-server.domain.tld:pep debug get_pep_service("client") a1b2c3d4e5f6g7 debug Sending[c2s]: <iq type='get' to='client@my-server.domain.tld/clientapp' from='client1@my-server.domain.tld' id='disco'> a1b2c3d4e5f6g7 debug Received[c2s]: <iq type='result' to='client@my-server.domain.tld' id='disco'> stanzarouter debug Discarding iq from c2s of type: result a1b2c3d4e5f6g7 debug Received[c2s]: <iq type='result' to='client1@my-server.domain.tld' id='disco'> stanzarouter debug Discarding iq from c2s of type: result a1b2c3d4e5f6g7 debug Received[c2s]: <iq type='set' id='#######'> my-server.domain.tld:carbons debug client@my-server.domain.tld/clientapp enabled carbons a1b2c3d4e5f6g7 debug Sending[c2s]: <iq type='result' to='client@my-server.domain.tld/clientapp' id='#######'> a1b2c3d4e5f6g7 debug Received[c2s]: <iq type='get' to='my-server.domain.tld' id='#######'> a1b2c3d4e5f6g7 debug Sending[c2s]: <iq type='result' from='my-server.domain.tld' to='client@my-server.domain.tld/clientapp' id='#######'> a1b2c3d4e5f6g7 debug Received[c2s]: <iq type='result' to='client@my-server.domain.tld' id='disco'> stanzarouter debug Discarding iq from c2s of type: result a1b2c3d4e5f6g7 debug Received[c2s]: <iq type='result' to='client1@my-server.domain.tld' id='disco'> stanzarouter debug Discarding iq from c2s of type: result a1b2c3d4e5f6g7 debug Received[c2s]: <iq type='result' to='client@my-server.domain.tld' id='disco'> stanzarouter debug Discarding iq from c2s of type: result a1b2c3d4e5f6g7 debug Received[c2s]: <iq type='result' to='client1@my-server.domain.tld' id='disco'> stanzarouter debug Discarding iq from c2s of type: result a1b2c3d4e5f6g7 debug Received[c2s]: <iq type='get' to='my-server.domain.tld' id='#######'> stanzarouter debug Unhandled c2s stanza: iq; xmlns=http://jabber.org/protocol/jinglenodes a1b2c3d4e5f6g7 debug Sending[c2s]: <iq type='error' from='my-server.domain.tld' to='client@my-server.domain.tld/clientapp' id='#######'>
What you reported are debug messages, not errors. The solution is to disable debug logging and stop worrying. Your log shows TLS enabled successfully, so the configured certificate must be working. Those are completely harmless, Prosody is looking for certs as per automatic zero-config certificate location. This happens before adding settings from the config. Ignore it.
ChangesI am not sure if you understood the issue. When the machine starts the very first time prosody does not start automatically although enabled within systemd on Debian. I have to login and start it manually. The log I posted is after I shut down the machine after the very first boot and started it again. So the question is why isn´t prosody start at the very first time.
Ok, sorry. I was confused by mention of certificate things. After it just stops, what does systemd report as its status? Are there any traces in syslog or the journal?
ChangesStatus-InvalidStatus-NeedInfoHere is an syslog-excerpt of the very first start: systemd: Started Login Service. systemd: Starting Raise network interfaces... systemd: Started Raise network interfaces. systemd: Reached target Network. systemd: Starting Permit User Sessions... systemd: Starting OpenBSD Secure Shell server... systemd: Reached target Network is Online. systemd: Started Prosody XMPP Server. systemd: Starting Daily apt download activities... systemd: Started Permit User Sessions. systemd: Started Getty on tty1. systemd: Reached target Login Prompts. systemd: Reloading Prosody XMPP Server. systemd: Reloaded Prosody XMPP Server. systemd: prosody.service: Main process exited, code=killed, status=1/HUP systemd: prosody.service: Succeeded. rsyslogd: rsyslogd was HUPed rsyslogd: rsyslogd was HUPed systemd: logrotate.service: Succeeded. After shutting down and starting again the reloading part is not shown again. Only "Started Prosody XMPP Server".
That's weird. So, it's being sent the reload signal before it has set up signal handling, which results in the default signal action of being killed.
ChangesI´m glad we narrowed it down.
Any progress on this one? Have you been able to reproduce/find the reason for this issue?
No progress, sorry.
I solved this issue by changing the following parameter of the prosody service file found under /lib/systemd/system/prosody.service: Restart=on-abnormal changed to Restart=always With this change prosody will not fail to start anymore.
I want to revert my previous comment because this issue might be caused by the definition of the pid-file in prosody.cfg.lua. I commented it out and it is working fine so far even without changing anything in the prosody.service file mentioned above.