Inaccessible server private or public key may result in server crash on startup

Product:	IMiS/ARChive
Release:	All until 10.1.2010 SP2
Date:	06/20/2022

Case:

When server private key is not accessible on server startup, and secure configuration is enabled in server configuration file, server startup fails. In this article we describe why this happens and how to fix the issue.

Description:

When server private key is not accessible on server startup, and secure configuration is enabled in server configuration file, server startup fails. Server log may contain additional information about failed start, like stacktrace or other warnings and errors. In this example, IMiS ARChive server was installed on default location "/opt/IS/imisarc" and is run by default user "iarc". Next example demonstrates server stactrace and warnings related to the described issue:

06/06/22 13:40:02.871 [iarcd:6428:7f7e0be69740] CRIT[2] Signal SIGSEGV/SIGABRT occurred. Process will shut down...
06/06/22 13:40:02.871 [iarcd:6428:7f7e0be69740] CRIT[2] -->si_signo=6, si_errno=0
06/06/22 13:40:02.871 [iarcd:6428:7f7e0be69740] CRIT[2] -->si_code=-6(*unknown*), si_addr=0x3e80000191c
06/06/22 13:40:02.871 [iarcd:6428:7f7e0be69740] CRIT[2] -->General registers (23):
06/06/22 13:40:02.871 [iarcd:6428:7f7e0be69740] CRIT[2] ---->reg[00]: 00000000
06/06/22 13:40:02.871 [iarcd:6428:7f7e0be69740] CRIT[2] ---->reg[01]: b0284c00
06/06/22 13:40:02.871 [iarcd:6428:7f7e0be69740] CRIT[2] ---->reg[02]: 00000008
06/06/22 13:40:02.871 [iarcd:6428:7f7e0be69740] CRIT[2] ---->reg[03]: 00000246
06/06/22 13:40:02.871 [iarcd:6428:7f7e0be69740] CRIT[2] ---->reg[04]: 049f2ae0
06/06/22 13:40:02.871 [iarcd:6428:7f7e0be69740] CRIT[2] ---->reg[05]: 03bce270
06/06/22 13:40:02.871 [iarcd:6428:7f7e0be69740] CRIT[2] ---->reg[06]: 049e4ef0
06/06/22 13:40:02.871 [iarcd:6428:7f7e0be69740] CRIT[2] ---->reg[07]: 030aba10
06/06/22 13:40:02.871 [iarcd:6428:7f7e0be69740] CRIT[2] ---->reg[08]: 00000002
06/06/22 13:40:02.871 [iarcd:6428:7f7e0be69740] CRIT[2] ---->reg[09]: b0284c00
06/06/22 13:40:02.871 [iarcd:6428:7f7e0be69740] CRIT[2] ---->reg[10]: 015bf4a0
06/06/22 13:40:02.871 [iarcd:6428:7f7e0be69740] CRIT[2] ---->reg[11]: 00000006
06/06/22 13:40:02.871 [iarcd:6428:7f7e0be69740] CRIT[2] ---->reg[12]: 00000000
06/06/22 13:40:02.871 [iarcd:6428:7f7e0be69740] CRIT[2] ---->reg[13]: 00000000
06/06/22 13:40:02.871 [iarcd:6428:7f7e0be69740] CRIT[2] ---->reg[14]: 0507437f
06/06/22 13:40:02.871 [iarcd:6428:7f7e0be69740] CRIT[2] ---->reg[15]: b0284c00
06/06/22 13:40:02.871 [iarcd:6428:7f7e0be69740] CRIT[2] ---->reg[16]: 0507437f
06/06/22 13:40:02.871 [iarcd:6428:7f7e0be69740] CRIT[2] ---->reg[17]: 00000246
06/06/22 13:40:02.871 [iarcd:6428:7f7e0be69740] CRIT[2] ---->reg[18]: 00000033
06/06/22 13:40:02.871 [iarcd:6428:7f7e0be69740] CRIT[2] ---->reg[19]: 00000004
06/06/22 13:40:02.871 [iarcd:6428:7f7e0be69740] CRIT[2] ---->reg[20]: 0000000e
06/06/22 13:40:02.871 [iarcd:6428:7f7e0be69740] CRIT[2] ---->reg[21]: 00000004
06/06/22 13:40:02.871 [iarcd:6428:7f7e0be69740] CRIT[2] ---->reg[22]: 00000000
06/06/22 13:40:02.871 [iarcd:6428:7f7e0be69740] CRIT[2] --------> End of SIGSEGV dump <--------
06/06/22 13:40:02.871 [iarcd:6428:7f7e0be69740] CRIT[2] --------> Stack backtrace <--------
06/06/22 13:40:04.427 [iarcd:6428:7f7e0be69740] CRIT[2] [ip=0x00abab1c] iarcd.0265:ProcessStack::Unwind(ProcessStack::tUnwindOptions, void*) (ProcessStack.cpp:188)
06/06/22 13:40:04.793 [iarcd:6428:7f7e0be69740] CRIT[2] [ip=0x00cf69bc] iarcd.0265:log_sigsegv(siginfo_t*, void*) (iaserver.cc:231)
06/06/22 13:40:04.794 [iarcd:6428:7f7e0be69740] CRIT[2] [ip=0x00cf6a96] iarcd.0265:signal_sigsegv_handler(int, siginfo_t*, void*) (iaserver.cc:245)
06/06/22 13:40:04.796 [iarcd:6428:7f7e0be69740] CRIT[2] [ip=0x7f7e0b846b20] libpthread-2.28.so:__restore_rt (sigaction.c:0)
06/06/22 13:40:04.801 [iarcd:6428:7f7e0be69740] CRIT[2] [ip=0x7f7e0507437f] libc-2.28.so:__GI_raise (?:0)
06/06/22 13:40:04.801 [iarcd:6428:7f7e0be69740] CRIT[2] [ip=0x7f7e0505edb5] libc-2.28.so:__GI_abort (?:0)
06/06/22 13:40:04.802 [iarcd:6428:7f7e0be69740] CRIT[2] [ip=0x7f7e05a2c09b] libstdc++.so.6.0.25:+0x7f7e05a2c09b (?:0)
06/06/22 13:40:04.802 [iarcd:6428:7f7e0be69740] CRIT[2] [ip=0x7f7e05a3253c] libstdc++.so.6.0.25:+0x7f7e05a3253c (?:0)
06/06/22 13:40:04.802 [iarcd:6428:7f7e0be69740] CRIT[2] [ip=0x7f7e05a32597] libstdc++.so.6.0.25:+0x7f7e05a32597 (?:0)
06/06/22 13:40:04.802 [iarcd:6428:7f7e0be69740] CRIT[2] [ip=0x7f7e05a327f8] libstdc++.so.6.0.25:+0x7f7e05a327f8 (?:0)
06/06/22 13:40:05.093 [iarcd:6428:7f7e0be69740] CRIT[2] [ip=0x00640ec0] iarcd.0265:void boost::throw_exception<boost::system::system_error>(boost::system::system_error const&) (throw_exception.hpp:69)
06/06/22 13:40:05.095 [iarcd:6428:7f7e0be69740] CRIT[2] [ip=0x0063beb0] iarcd.0265:boost::asio::detail::do_throw_error(boost::system::error_code const&, char const*) (throw_error.ipp:38)
06/06/22 13:40:05.096 [iarcd:6428:7f7e0be69740] CRIT[2] [ip=0x0063bc01] iarcd.0265:boost::asio::detail::throw_error(boost::system::error_code const&, char const*) (throw_error.hpp:43)
06/06/22 13:40:05.098 [iarcd:6428:7f7e0be69740] CRIT[2] [ip=0x00d03bc2] iarcd.0265:boost::asio::ssl::context::use_private_key_file(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, boost::asio::ssl::context_base::file_format) (context.ipp:845)
06/06/22 13:40:05.099 [iarcd:6428:7f7e0be69740] CRIT[2] [ip=0x00d04edb] iarcd.0265:TCPSecureListenerEvents::TCPSecureListenerEvents(TCPSecureListenerEvents::tProtocol, TCPSecureListenerEvents::tInitOptions const&, Crypto::CertificateStore*) (TCPSecureListenerEvents.h:128)
06/06/22 13:40:05.100 [iarcd:6428:7f7e0be69740] CRIT[2] [ip=0x00d09f23] iarcd.0265:HttpsListenerEvents::HttpsListenerEvents(TCPSecureListenerEvents::tProtocol, TCPSecureListenerEvents::tInitOptions const&, HttpHandlers&, unsigned long, Crypto::CertificateStore*) (HttpsListenerEvents.h:29)
06/06/22 13:40:05.101 [iarcd:6428:7f7e0be69740] CRIT[2] [ip=0x00cfb28c] iarcd.0265:IAServer::Serve() (iaserver.cc:914)
06/06/22 13:40:05.105 [iarcd:6428:7f7e0be69740] CRIT[2] [ip=0x00cef917] iarcd.0265:main (iarcd.cc:370)
06/06/22 13:40:05.106 [iarcd:6428:7f7e0be69740] CRIT[2] [ip=0x7f7e05060493] libc-2.28.so:__libc_start_main+0xf3 (?:0)
06/06/22 13:40:05.111 [iarcd:6428:7f7e0be69740] CRIT[2] [ip=0x0043825e] iarcd.0265:+0x43825e (?:0)

06/06/22 13:40:02.871 [iarcd:6428:7f7e049fc700] WARN[4] <stderr>: terminate called after throwing an instance of 'boost::exception_detail::clone_impl<boost::exception_detail::error_info_injector<boost::system::system_error> >'
06/06/22 13:40:02.871 [iarcd:6428:7f7e049fc700] WARN[4] <stderr>: what(): use_private_key_file: Permission denied

Listing server public and private key in installation directory reveals, that user "iarc" does not have read rights on server public and private keys:

[root@iarc-host imisarc]# ls -al /opt/IS/imisarc/cert*
-rw-------. 1 root root 1399 May 7 13:37 /opt/IS/imisarc/cert.crt
-rw-------. 1 root root 1704 May 7 13:37 /opt/IS/imisarc/cert.key

Changing ownership to "iarc" for both keys resolves the issue:

chown iarc:iarc /opt/IS/imisarc/cert*

Since 10.1.2010 SP2, invalid permissions no longer crash server, secure access to server is not possible because server does not listen to secure port "iarcs" due to errors, which are logged in server log. Next example demonstrates server error logs in case when public and private keys are not accessible. "Netstat" command also shows that server does not listen to secure port "iarcs".

Inaccessible server private key:

06/06/22 13:45:38.488 [iarcd:62252:7f9e89b99b80] ERR[3] Error occurred while starting Administration Service. Reason: 'use_private_key_file: Permission denied'
06/06/22 13:45:38.493 [iarcd:62252:7f9e89b99b80] ERR[3] Error occurred while creating secure listener event. Reason: 'use_private_key_file: Permission denied'.

Inaccessible server public key:

06/06/22 13:47:29.151 [iarcd:62521:7ffa4e363b80] ERR[3] Error occurred while starting Administration Service. Reason: 'use_certificate_chain_file: Permission denied'
06/06/22 13:47:29.156 [iarcd:62521:7ffa4e363b80] ERR[3] Error occurred while creating secure listener event. Reason: 'use_certificate_chain_file: Permission denied'.

[root@iarc-host imisarc]# netstat -l | grep iarc
tcp 0 0 0.0.0.0:iarc 0.0.0.0:* LISTEN
tcp6 0 0 [::]:iarc [::]:* LISTEN

When server listens on all ports, "netstat" output should look like this:

[root@iarc-host imisarc]# netstat -l | grep iarc
tcp 0 0 0.0.0.0:iarcs 0.0.0.0:* LISTEN
tcp 0 0 0.0.0.0:iarc 0.0.0.0:* LISTEN
tcp 0 0 0.0.0.0:iarcadmin 0.0.0.0:* LISTEN
tcp6 0 0 [::]:iarcs [::]:* LISTEN
tcp6 0 0 [::]:iarc [::]:* LISTEN
tcp6 0 0 [::]:iarcadmin [::]:* LISTEN

IMiS ARChive ports can be seen in "/etc/services":

[root@iarc-host imisarc]# grep iarc /etc/services
iarcs 16806/tcp # IMiS/ARChive Storage Server Secure Service
iarc 16807/tcp # IMiS/ARChive Storage Server Service
iarcadmin 16808/tcp # IMiS/ARChive Storage Server Administration Service

Related Documents:

| Back | Main view