Hi,
On Thu, Apr 11, 2024 at 6:02 PM Orion Poplawski <orion(a)nwra.com> wrote:
On 4/11/24 09:03, Florence Blanc-Renaud wrote:
> Hi,
>
> On Thu, Apr 11, 2024 at 12:34 AM Orion Poplawski via FreeIPA-users
> <freeipa-users(a)lists.fedorahosted.org
> <mailto:freeipa-users@lists.fedorahosted.org>> wrote:
>
> I've just added an EL9 IPA replica into our domain. I seems to
generally be
> working fine, but trying to download the MasterCRL.bin fails:
>
> ==> /var/log/httpd/access_log <==
> 10.20.0.37 - - [10/Apr/2024:14:13:17 -0700] "GET
/ipa/crl/MasterCRL.bin
> HTTP/1.1" 301 293 "-" "curl/7.76.1"
>
> ==> /var/log/httpd/error_log <==
> [Wed Apr 10 14:14:17.830119 2024] [proxy_ajp:error] [pid 28001:tid
28040]
> (70007)The timeout specified has expired: AH01030:
ajp_ilink_receive() can't
> receive header
> [Wed Apr 10 14:14:17.830249 2024] [proxy_ajp:error] [pid 28001:tid
28040]
> [client 10.20.0.37:35124 <
http://10.20.0.37:35124>] AH00992:
> ajp_read_header: ajp_ilink_receive failed
> [Wed Apr 10 14:14:17.830261 2024] [proxy_ajp:error] [pid 28001:tid
28040]
> (70007)The timeout specified has expired: [client 10.20.0.37:35124
> <
http://10.20.0.37:35124>] AH00878:
> read response failed from [::1]:8009 (localhost:8009)
>
> ==> /var/log/httpd/access_log <==
> 10.20.0.37 - - [10/Apr/2024:14:13:17 -0700] "GET
> /ca/ee/ca/getCRL?op=getCRL&crlIssuingPoint=MasterCRL HTTP/1.1" 500
527 "-"
> "curl/7.76.1"
>
> I'm not sure where else to look for logs.
>
>
> If you are requesting the MasterCRL.bin file on a replica that is not
the CRL
> generation master, the URL is transferred to the local CA server
> at
http://replica.ipa.test/ca/ee/ca/getCRL?op=getCRL&crlIssuingPoint=Mas...
> <
http://replica.ipa.test/ca/ee/ca/getCRL?op=getCRL&crlIssuingPoint=Mas...
>
> (this is configured in /etc/httpd/conf.d/ipa-pki-proxy.conf).
>
> Then the calls to /ca/ee/ca/getCRL are handled by an AJP connector
> (LocationMatch defined in /etc/httpd/conf.d/ipa-pki-proxy.conf using
> ajp://localhost:8009). The AJP connector is defined
> in /etc/pki/pki-tomcat/server.xml and should be using the loopback
address.
> There can be issues if your /etc/hosts does not contain the following
lines:
> 127.0.0.1 localhost localhost.localdomain localhost4
localhost4.localdomain4
> ::1 localhost localhost.localdomain localhost6
localhost6.localdomain6
>
> You can have a look
in /var/log/pki/pki-tomcat/localhost_access_log.$DATE.txt
> and check if the request really reached the PKI server. Then check logs
> in /var/log/pki/pki-tomcat/ca/debug.$DATE.log
The machine in question is not the CRL generator. We are getting
redirected
to /ca/ee/ca/getCRL?op=getCRL&crlIssuingPoint=MasterCRL on that machine.
But
it is that request that is timing out.
Looks like the tomcat server may be hosed:
Apr 05 00:01:00 server[5758]: java.util.logging.ErrorManager: 1:
FileHandler
is closed or not yet initialized, unable to log [2024-04-05 00:01:00
[Timer-0]
INFO: SessionTimer: checking security domain sessions
Apr 05 00:01:00 server[5758]: ]
Apr 05 00:01:02 server[5758]: java.util.logging.ErrorManager: 1:
FileHandler
is closed or not yet initialized, unable to log [2024-04-05 00:01:02
[pool-1-thread-1] SEVERE: Unable to run maintenance task: access denied
("java.io.FilePermission" "/var/lib/pki/pki-tomcat/logs/acme"
"read")
Apr 05 00:01:02 server[5758]: java.security.AccessControlException: access
denied ("java.io.FilePermission" "/var/lib/pki/pki-tomcat/logs/acme"
"read")
Apr 05 00:01:02 server[5758]: at
java.base/java.security.AccessControlContext.checkPermission(AccessControlContext.java:485)
Apr 06 00:01:13 server[16841]: java.util.logging.ErrorManager: 1:
FileHandler
is closed or not yet initialized, unable to log [2024-04-06 00:01:13
[pool-1-thread-1] SEVERE: Unable to run maintenance task: access denied
("java.io.FilePermission" "/var/lib/pki/pki-tomcat/logs/acme"
"read")
Apr 06 00:01:13 server[16841]: java.security.AccessControlException: access
denied ("java.io.FilePermission" "/var/lib/pki/pki-tomcat/logs/acme"
"read")
Apr 06 00:01:13 server[16841]: at
java.base/java.security.AccessControlContext.checkPermis
Apr 06 00:01:14 server[16841]: java.util.logging.ErrorManager: 1:
FileHandler
is closed or not yet initialized, unable to log [2024-04-06 00:01:14
[KeyStatusUpdateTask] WARNING: Repository: Unable to check next range:
access
denied ("java.io.FilePermission" "/var/lib/pki/pki-tomcat/logs/kra"
"read")
Apr 06 00:01:14 server[16841]: java.security.AccessControlException: access
denied ("java.io.FilePermission" "/var/lib/pki/pki-tomcat/logs/kra"
"read")
Apr 06 00:01:14 server[16841]: at
java.base/java.security.AccessControlContext.checkPermission(AccessControlContext.java:485)
Apr 06 00:01:14 server[16841]: at
java.base/java.security.AccessController.checkPermission(AccessController.java:1068)
Based on your logs and the 00:01:xx timestamp, I believe you are hitting
After the logs are rotated, pki often has problems accessing its log files.
Can you add your problem to the above ticket? It will help prioritize the
problem.
Thanks,
flo
And that's where logging ends.
Rebooted and everything is fine now. We had some IO lockups on that
machine
and I guess that put things into a bad state.
Thanks for the pointers.
--
Orion Poplawski
he/him/his - surely the least important thing about me
Manager of IT Systems 720-772-5637
NWRA, Boulder/CoRA Office FAX: 303-415-9702
3380 Mitchell Lane orion(a)nwra.com
Boulder, CO 80301
https://www.nwra.com/