Ejabberd: .PEM files can't be read - Windows 18.12.1

[DoCheckor]

Attempted to get from V16 to V18. Upgrading to V17 took a while because I didn't find any record that directory usage had been changed... But after I tried to get the server to V18 I can't get it back running again.

Installed ejabberd-18.12.1-windows.exe

Wouldn't want to use my server .PEM files (which worked well in V17) so I commented the lines I added to "certificates".

Now I still get the same error messages in the logs in regard to the ca pem:

2019-01-01 19:05:31.503 [warning] <0.401.0>@ejabberd_pkix:wildcard:366 Path C:\ProgramData\ejabberd\conf\server.pem is empty, please make sure ejabberd has sufficient rights to read it

The server as started by the desktop link using admin credentials...

Detailed log:

2019-01-01 19:03:57.187 [notice] <0.97.0>@lager_file_backend:152 Changed loghwm of c:/ProgramData/ejabberd/logs/error.log to 100
2019-01-01 19:03:57.203 [notice] <0.97.0>@lager_file_backend:152 Changed loghwm of C:/ProgramData/ejabberd/logs/ejabberd.log to 100
2019-01-01 19:04:06.396 [info] <0.80.0>@ejabberd_config:start:69 Loading configuration from C:/ProgramData/ejabberd/conf/ejabberd.yml
2019-01-01 19:05:31.384 [info] <0.80.0>@ejabberd_app:add_windows_nameservers:108 Adding machine's DNS IPs to Erlang system:
[]
2019-01-01 19:05:31.503 [warning] <0.401.0>@ejabberd_pkix:wildcard:366 Path C:\ProgramData\ejabberd\conf\server.pem is empty, please make sure ejabberd has sufficient rights to read it
2019-01-01 19:05:31.946 [info] <0.376.0>@gen_mod:start_modules:131 Loading modules for descentforum.de
2019-01-01 19:05:31.946 [warning] <0.376.0>@gen_mod:sort_modules:156 Module 'mod_mam' is recommended for module 'mod_muc' but is not found in the config
2019-01-01 19:05:33.866 [info] <0.80.0>@ejabberd_cluster_mnesia:wait_for_sync:123 Waiting for Mnesia synchronization to complete
2019-01-01 19:05:33.950 [error] <0.401.0> gen_server ejabberd_pkix terminated with reason: {{nif_not_loaded,fast_tls},[{erlang,nif_error,[{nif_not_loaded,fast_tls}],[]},{fast_tls,clear_cache_nif,0,[{file,"src/fast_tls.erl"},{line,132}]},{ejabberd_pkix,commit,0,[{file,"src/ejabberd_pkix.erl"},{line,270}]},{ejabberd_pkix,handle_call,3,[{file,"src/ejabberd_pkix.erl"},{line,169}]},{gen_server,try_handle_call,4,[{file,"gen_server.erl"},{line,661}]},{gen_server,handle_msg,6,[{file,"gen_server.erl"},{line,690}]},{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,249}]}]}
2019-01-01 19:05:33.981 [error] <0.401.0> CRASH REPORT Process ejabberd_pkix with 0 neighbours crashed with reason: {{nif_not_loaded,fast_tls},[{erlang,nif_error,[{nif_not_loaded,fast_tls}],[]},{fast_tls,clear_cache_nif,0,[{file,"src/fast_tls.erl"},{line,132}]},{ejabberd_pkix,commit,0,[{file,"src/ejabberd_pkix.erl"},{line,270}]},{ejabberd_pkix,handle_call,3,[{file,"src/ejabberd_pkix.erl"},{line,169}]},{gen_server,try_handle_call,4,[{file,"gen_server.erl"},{line,661}]},{gen_server,handle_msg,6,[{file,"gen_server.erl"},{line,690}]},{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,249}]}]}
2019-01-01 19:05:34.005 [error] <0.80.0>@ejabberd_hooks:safe_apply:384 Hook ejabberd_started crashed when running ejabberd_pkix:ejabberd_started/0:
** Reason = {exit,{{{nif_not_loaded,fast_tls},[{erlang,nif_error,[{nif_not_loaded,fast_tls}],[]},{fast_tls,clear_cache_nif,0,[{file,"src/fast_tls.erl"},{line,132}]},{ejabberd_pkix,commit,0,[{file,"src/ejabberd_pkix.erl"},{line,270}]},{ejabberd_pkix,handle_call,3,[{file,"src/ejabberd_pkix.erl"},{line,169}]},{gen_server,try_handle_call,4,[{file,"gen_server.erl"},{line,661}]},{gen_server,handle_msg,6,[{file,"gen_server.erl"},{line,690}]},{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,249}]}]},{gen_server,call,[ejabberd_pkix,ejabberd_started,60000]}},[{gen_server,call,3,[{file,"gen_server.erl"},{line,223}]},{ejabberd_hooks,safe_apply,4,[{file,"src/ejabberd_hooks.erl"},{line,381}]},{ejabberd_hooks,run1,3,[{file,"src/ejabberd_hooks.erl"},{line,330}]},{ejabberd_app,start,2,[{file,"src/ejabberd_app.erl"},{line,58}]},{application_master,start_it_old,4,[{file,"application_master.erl"},{line,277}]}]}
** Arguments = []
2019-01-01 19:05:34.005 [error] <0.376.0> Supervisor ejabberd_sup had child ejabberd_pkix started with ejabberd_pkix:start_link() at <0.401.0> exit with reason {{nif_not_loaded,fast_tls},[{erlang,nif_error,[{nif_not_loaded,fast_tls}],[]},{fast_tls,clear_cache_nif,0,[{file,"src/fast_tls.erl"},{line,132}]},{ejabberd_pkix,commit,0,[{file,"src/ejabberd_pkix.erl"},{line,270}]},{ejabberd_pkix,handle_call,3,[{file,"src/ejabberd_pkix.erl"},{line,169}]},{gen_server,try_handle_call,4,[{file,"gen_server.erl"},{line,661}]},{gen_server,handle_msg,6,[{file,"gen_server.erl"},{line,690}]},{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,249}]}]} in context child_terminated
2019-01-01 19:05:34.005 [info] <0.80.0>@ejabberd_app:start:60 ejabberd 18.12.1 is started in the node ejabberd@localhost in 98.78s
2019-01-01 19:05:34.021 [warning] <0.525.0>@ejabberd_pkix:wildcard:366 Path C:\ProgramData\ejabberd\conf\server.pem is empty, please make sure ejabberd has sufficient rights to read it
2019-01-01 19:05:34.021 [info] <0.399.0>@ejabberd_listener:init:138 Start accepting TCP connections at 0.0.0.0:5280 for ejabberd_http
2019-01-01 19:05:34.021 [info] <0.398.0>@ejabberd_listener:init:138 Start accepting TCP connections at 0.0.0.0:5269 for ejabberd_s2s_in
2019-01-01 19:05:34.021 [info] <0.397.0>@ejabberd_listener:init:138 Start accepting TCP connections at 0.0.0.0:5222 for ejabberd_c2s
2019-01-01 19:05:34.021 [info] <0.502.0>@ejabberd_listener:init:138 Start accepting TCP connections at 5.175.28.32:7777 for mod_proxy65_stream
2019-01-01 19:05:34.021 [info] <0.400.0>@ejabberd_listener:init:138 Start accepting TCP connections at 0.0.0.0:5443 for ejabberd_http
2019-01-01 19:05:34.034 [info] <0.398.0>@ejabberd_listener:accept:238 (<0.529.0>) Accepted connection 144.76.218.124:35268 -> 46.163.66.145:5269
2019-01-01 19:05:34.608 [info] <0.529.0>@ejabberd_s2s_in:process_closed:131 Closing inbound s2s connection kdetalk.net -> descentforum.de: TLS failed: Failed to find a certificate matching the domain in SNI extension: error:1412E0E2:SSL routines:ssl_parse_clienthello_tlsext:reason(226)
2019-01-01 19:05:34.608 [warning] <0.529.0>@ejabberd_s2s_in:terminate:286 (tls|<0.529.0>) Failed to secure inbound s2s connection: TLS failed: Failed to find a certificate matching the domain in SNI extension: error:1412E0E2:SSL routines:ssl_parse_clienthello_tlsext:reason(226)
2019-01-01 19:05:37.249 [info] <0.398.0>@ejabberd_listener:accept:238 (<0.533.0>) Accepted connection 144.76.218.124:35374 -> 46.163.66.145:5269
2019-01-01 19:05:37.311 [info] <0.533.0>@ejabberd_s2s_in:process_closed:131 Closing inbound s2s connection kdetalk.net -> descentforum.de: TLS failed: Failed to find a certificate matching the domain in SNI extension: error:1412E0E2:SSL routines:ssl_parse_clienthello_tlsext:reason(226)
2019-01-01 19:05:37.311 [warning] <0.533.0>@ejabberd_s2s_in:terminate:286 (tls|<0.533.0>) Failed to secure inbound s2s connection: TLS failed: Failed to find a certificate matching the domain in SNI extension: error:1412E0E2:SSL routines:ssl_parse_clienthello_tlsext:reason(226)
2019-01-01 19:05:41.686 [info] <0.397.0>@ejabberd_listener:accept:238 (<0.534.0>) Accepted connection 77.21.178.157:54779 -> 46.163.66.145:5222
2019-01-01 19:05:42.016 [warning] <0.534.0>@ejabberd_c2s:process_terminated:285 (tls|<0.534.0>) Failed to secure c2s connection: TLS failed: Failed to find a certificate matching the domain in SNI extension: error:1412E0E2:SSL routines:ssl_parse_clienthello_tlsext:reason(226)

Any idea?

[licaon-kter]

So you have a cert there and it can be read by the app user? If yes, what if you move that cert somewhere else and modify config to read it?

Or you mean you want to run without a cert?

[DoCheckor]

I tried to add the cert (a merge of the chain) i used in V17, but it did not work because of the error "....pem is empty, please make sure ejabberd has sufficient rights to read it".

Then I tried to add the chain (same dir / same permissions) and the pkey - same error.

So i copied all the certs to /ProgramData/conf - same error.

So I diabled the custom cert lines and found out that the server not even appears to be able to use its own / default server.pem and the ca.pem file neither...

I edited the Windows ACL (ntfs permissions) to allow EVERYONE, ANONYMOUS, Anyone -- read access. Nothing works...

[zinid]

There is also a problem with fast_tls library, ejabberd definitely doesn't see it and it's a much bigger problem which I suggest to fix first.

[DoCheckor]

Sounds good! That error was there directly after installing new from scratch so I guess it is a bug in the installer?

[zinid]

Maybe, I personally don't build the installer, probably @cromain can help.

[DoCheckor]

File fast_tls.erl can't be found anywhere on the server - not even the backups - so I guess I need to wait for cromain on that.

But still: This thread was to resolve the issue with the .PEM files ... As this error msg appears prior to the .erl file messages: Do you think it is related?

[zinid]

Start ejabberd in live mode and run:

> filelib:wildcard("C:\ProgramData\ejabberd\conf\server.pem").

If the result is empty list [] then there is a problem with read access.

[DoCheckor]

I had to rollback to Version 17.03 to let the users log in again.

So I tried your command on that and indeed get an empty list with V17, too:

(ejabberd@localhost)6> filelib:wildcard("C:\BACKUPS\Descentforum.DE\SSL\LetsEncrypt\descentforum.de-ejabberd.pem"). []
but then again, I don't get any error messages like is empty, please make sure ejabberd has sufficient rights to read it now with V17 and the system seems to work alright according to https://xmpp.net/result.php

Any Windows guy around to have a look?

[zinid]

This means ejabberd is unable to read your PEM file. Please resolve it at OS level. I close the issue.

[DoCheckor]

I set the NTFS permissions of the whole cert directory to be readable to "Everyone" - so that means EVERY user / credentials possible. There is no way to grant any more access. If ejabberd can't read the file from Version 16 to 17 / 18 it seems clear to me that the issue can not to be found on the OS side. If I am wrong I just need anyone to explain what to do.

Repeated: As it seems, a clean ejabberd 18.12.1 installation on Windows comes up with the same error message in the logs using it's own / default .PEM file

So the last thing is to hope @cromain or any server admin on Windows comes up with a good idea on this, as I already spent hours trying to fix the issue with no success...

[zinid]

or any server admin on Windows comes up

You won't find a lot of them here. And this is the main reason why the Windows installer has these issues: a very few people is using ejabberd in Windows.

[zinid]

I will assign @cromain , maybe he will find some time to look at least at fast_tls library issue.

[cromain]

while i can help on fast_tls issue which is packaging issue, i can't help about read permission.
I'll double check that part anyway.

[cromain]

tls driver fixed, and cert read is OK on our test environment, so I can close this now.

[cromain]

just to mention error on reading .pem file is also fixed for the next installer.
as immediate solution: edit ejabberd.yml and replace all '\' in server.pem path by '/'

[DoCheckor]

Thank you very much for taking care of these issues, mate! Much appreciated!

[psahni]

I am facing the same issue. Its not working on windows.

[lock[bot]]

This thread has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.