search

OxalisCommunity / oxalis

Oxalis - PEPPOL Access Point open source implementation - Core component
Other
124 stars 90 forks source link

Unable to detect mode for certificate #474

Closed carher closed 3 years ago

carher commented 4 years ago

We are running Oxalis 4.0.4, which has been stable in our production environment for quite some time. After a restart of one of our outbound nodes today, our PEPPOL PRODUCTION AP certificate runs into trouble:

Unable to detect mode for certificate 'C=NO, O=SpareBank 1 Banksamarbeidet DA, OU=PEPPOL PRODUCTION AP, CN=PNO000287'

This doesn't seem to be a simple glitch, because repeated attempts of restarting gives the same error, and the application halts. While this is happening, our other outbound node keeps running happily, transferring files with no issues. Same code, same environment, same keystore, the difference is that we have not restarted that node yet. Our previous restart of both servers was performed June 2nd, so something externally must have changed after that?

Any theories? What actually does Oxalis do with the certificate when starting up?

This is our environment (which, as mentioned, has been stable for quite some time):

uname -a

Linux 3.10.0-1127.8.2.el7.x86_64 #1 SMP Thu May 7 19:30:37 EDT 2020 x86_64 x86_64 x86_64 GNU/Linux

java -version

openjdk version "1.8.0_252" OpenJDK Runtime Environment (build 1.8.0_252-b09) OpenJDK 64-Bit Server VM (build 25.252-b09, mixed mode)

When starting the application, we get very little information logged. We find a few log statements from a persister module we have created, but other than that, Oxalis logs nothing before this happens:

{ "timestamp":"2020-06-05 15:31:35,111", "log_level":"ERROR","app_name":"ail-oxalis-outbound", "jclass":"no.difi.oxalis.commons.guice.GuiceModuleLoader", "thread":"main", "log_type":"trace", "payload":"Unable to detect mode.", "stacktrace":"n.d.v.p.c.l.PeppolLoadingException: Unable to detect mode for certificate 'C=NO, O=SpareBank 1 Banksamarbeidet DA, OU=PEPPOL PRODUCTION AP, CN=PNO000287'.\n\tat n.d.v.p.s.ModeDetector.detect(ModeDetector.java:56)\n\tat n.d.o.c.m.ModeProvider.get(ModeProvider.java:74)\n\t... 88 common frames omitted\nWrapped by: n.d.o.a.l.OxalisLoadingException: Unable to detect mode.\n\tat n.d.o.c.m.ModeProvider.get(ModeProvider.java:78)\n\tat n.d.o.c.m.ModeProvider.get(ModeProvider.java:47)\n\tat c.g.i.i.ProviderInternalFactory.provision(ProviderInternalFactory.java:85)\n\tat c.g.i.i.BoundProviderFactory.provision(BoundProviderFactory.java:77)\n\tat c.g.i.i.ProviderInternalFactory.circularGet(ProviderInternalFactory.java:59)\n\tat c.g.i.i.BoundProviderFactory.get(BoundProviderFactory.java:61)\n\tat c.g.i.i.ProviderToInternalFactoryAdapter.get(ProviderToInternalFactoryAdapter.java:40)\n\tat c.g.i.i.SingletonScope$1.get(SingletonScope.java:168)\n\tat c.g.i.i.InternalFactoryToProviderAdapter.get(InternalFactoryToProviderAdapter.java:39)\n\tat c.g.i.i.InternalInjectorCreator.loadEagerSingletons(InternalInjectorCreator.java:211)\n\tat c.g.i.i.InternalInjectorCreator.injectDynamically(InternalInjectorCreator.java:182)\n\tat c.g.i.i.InternalInjectorCreator.build(InternalInjectorCreator.java:109)\n\tat c.g.inject.Guice.createInjector(Guice.java:87)\n\tat c.g.inject.Guice.createInjector(Guice.java:69)\n\tat n.d.o.c.g.GuiceModuleLoader.initiate(GuiceModuleLoader.java:66)\n\tat n.d.o.o.OxalisOutboundComponent.(OxalisOutboundComponent.java:45)\n\tat n.d.o.o.OxalisOutboundComponent$$FastClassByGuice$$727f1988.newInstance()\n\tat c.g.i.i.DefaultConstructionProxyFactory$FastClassProxy.newInstance(DefaultConstructionProxyFactory.java:89)\n\tat c.g.i.i.ConstructorInjector.provision(ConstructorInjector.java:114)\n\tat c.g.i.i.ConstructorInjector.construct(ConstructorInjector.java:91)\n\tat c.g.i.i.ConstructorBindingImpl$Factory.get(ConstructorBindingImpl.java:306)\n\tat c.g.i.i.InjectorImpl$1.get(InjectorImpl.java:1050)\n\tat c.g.i.i.InjectorImpl.getInstance(InjectorImpl.java:1086)\n\tat n.s.p.o.AilPersisterHandler.(AilPersisterHandler.java:94)\n\tat n.s.p.o.AilPersisterHandler$$FastClassByGuice$$b2564860.newInstance()\n\tat c.g.i.i.DefaultConstructionProxyFactory$FastClassProxy.newInstance(DefaultConstructionProxyFactory.java:89)\n\tat c.g.i.i.ConstructorInjector.provision(ConstructorInjector.java:114)\n\tat c.g.i.i.ConstructorInjector.construct(ConstructorInjector.java:91)\n\tat c.g.i.i.ConstructorBindingImpl$Factory.get(ConstructorBindingImpl.java:306)\n\tat c.g.i.i.FactoryProxy.get(FactoryProxy.java:62)\n\t... 59 frames truncated\n" }

I am not allowed to access our production certificate, but IT operations could give me this printed information about it:

Certificate: Data: Version: 3 (0x2) Serial Number: 70:ca:fc:50:28:f6:8d:6d:21:21:49:87:e6:e0:8d:ec Signature Algorithm: sha256WithRSAEncryption Issuer: C=BE, O=OpenPEPPOL AISBL, CN=PEPPOL ACCESS POINT CA - G2 Validity Not Before: Oct 31 00:00:00 2019 GMT Not After : Oct 20 23:59:59 2021 GMT Subject: CN=PNO000287, OU=PEPPOL PRODUCTION AP, O=SpareBank 1 Banksamarbeidet DA, C=NO Subject Public Key Info: Public Key Algorithm: rsaEncryption Public-Key: (2048 bit) Modulus: 00:d8:da:e3:ec:9d:7e:10:69:89:5e:d3:12:8b:3b: 39:dd:21:c4:4e:af:96:5a:5f:b9:f6:91:e6:b3:53: 6c:f4:a6:e1:4b:6f:a1:1b:cd:53:08:3d:66:39:12: 60:4b:f7:39:df:71:a8:4f:a6:ba:63:ea:17:30:02: bc:19:d7:ee:b2:52:68:ae:5c:de:5a:84:b0:af:af: a3:a8:09:b9:1b:51:6e:6f:a6:bf:76:8b:08:4c:e5: 73:40:62:35:66:d1:07:18:e5:8d:50:82:5b:12:4c: b0:91:d5:33:98:0e:4e:17:dc:69:76:c6:3c:68:d4: 8b:d4:97:08:e1:6b:c6:64:fb:ac:37:c9:78:4d:c0: 9e:a9:ab:ae:cf:1b:ba:7a:1d:f8:c5:90:4f:f7:eb: 03:7f:1f:97:48:ad:86:d5:9a:57:66:30:75:9c:a4: 5d:94:ee:f3:d1:51:fb:81:7d:1a:59:85:89:81:5d: 70:a0:c0:41:72:33:e2:59:51:41:9a:ca:5f:0f:9f: 60:2c:2f:4d:4a:9b:e0:e7:47:0d:c8:a7:25:8e:eb: 6e:20:81:16:1e:00:14:80:f7:45:e3:4c:67:9f:cd: 12:c8:81:4f:6c:51:1e:db:36:9f:69:72:7b:cd:0d: c8:89:de:0a:e1:1f:fe:27:cb:d1:48:a8:66:cc:dd: 7f:e5 Exponent: 65537 (0x10001) X509v3 extensions: X509v3 Basic Constraints: critical CA:FALSE X509v3 Key Usage: critical Digital Signature, Key Encipherment, Key Agreement X509v3 Extended Key Usage: critical TLS Web Client Authentication X509v3 Subject Key Identifier: E0:47:98:7B:A9:68:F4:9A:8C:BB:E2:3D:EC:24:19:32:36:5A:6E:60 X509v3 CRL Distribution Points: Full Name: URI:http://pki-crl.symauth.com/ca_7bedcbcc4f724efe30d5006dda681ba0/LatestCRL.crl Authority Information Access: OCSP - URI:http://pki-ocsp.symauth.com X509v3 Authority Key Identifier: keyid:87:25:DF:5B:23:A6:C4:3B:F9:9F:DF:1B:A5:20:91:DD:E4:F4:3C:81 2.16.840.1.113733.1.16.3: 0...`.H...E...........6..957608 2.16.840.1.113733.1.16.5: 0)....$aHR0cHM6Ly9wa2ktcmEuc3ltYXV0aC5jb20= Signature Algorithm: sha256WithRSAEncryption ba:61:e4:e9:30:02:be:fb:b4:86:c6:98:9a:75:d7:53:e7:91: d8:69:a9:fe:2e:ae:80:59:9e:1e:8a:9c:73:cb:f8:35:36:5f: 13:d4:07:93:76:dd:0d:c3:56:68:9c:d5:bd:b6:29:df:77:03: 12:cf:f9:d6:f0:42:b4:dd:b8:e1:e4:9e:21:53:19:e6:53:95: 3d:0d:c2:0a:f5:d6:30:f6:56:fb:86:85:bf:f0:a7:33:9e:08: eb:a9:39:a4:b0:2a:23:14:ae:d6:36:02:de:36:a8:ae:fa:13: cb:6b:1f:1c:32:f4:57:0d:fa:29:d2:87:e9:6e:73:80:f8:fd: d2:26:3c:e4:3a:d3:b2:e6:0e:1b:2c:5b:e0:fa:54:aa:e6:5b: 7b:72:42:6e:59:ba:5b:11:ac:b5:5b:8d:2c:f4:ec:88:b1:71: 43:99:a7:fc:a7:1b:32:32:5c:d9:a6:1b:99:85:82:6e:20:54: 7a:b7:48:27:73:76:c1:7b:92:35:51:c5:91:40:44:19:66:d9: c2:1a:62:55:c7:ce:04:af:87:f1:fb:de:c3:45:b5:2b:0e:32: 59:e9:cd:dd:35:ce:fb:83:9e:00:bb:97:e2:1f:70:4f:0e:3c: c1:da:32:60:16:2e:32:92:94:62:21:7c:dc:4d:c6:4e:6c:54: 66:95:5a:b4:1b:8e:bc:82:34:3c:1f:b4:2f:26:82:9c:f0:a7: 54:75:04:1f:47:3c:b4:c0:a6:fd:a0:c1:84:fa:8e:af:74:56: 29:51:7b:a3:d9:42:95:9c:8d:4c:3f:d4:48:81:54:78:3f:61: 34:21:ed:06:7b:23:13:04:ff:6e:5a:6d:42:09:62:cb:2d:68: 9b:d3:56:1c:74:d9:bb:45:5c:8a:9f:09:1d:32:08:86:ff:6a: 7c:84:59:53:10:0b:c3:08:96:f8:75:4b:f0:1a:8b:59:2c:c7: ee:e5:17:4e:86:cb:73:0e:61:1a:4f:d7:21:0f:2a:17:71:c0: 41:1d:d3:22:61:2b:6d:ab:56:b5:f5:57:1a:c0:04:03:49:a8: e0:ba:c5:1e:58:4e:00:46:c8:64:a6:04:f9:d8:4e:93:d4:ee: c8:ae:93:8e:fd:6f:4d:0b:33:3d:69:76:15:38:6a:63:5a:08: 78:8f:d8:a5:11:1b:37:8f:86:66:73:76:9b:b3:5d:36:70:9c: dd:42:e1:0a:bc:f2:f2:1e:0c:a2:cf:46:cd:3b:9e:4e:73:c7: 95:c9:ec:1d:7f:03:8b:3b:26:2b:7a:4f:24:b4:07:63:2b:b8: 96:83:53:b0:38:fe:92:21:e1:8c:79:aa:c9:ca:10:e3:4e:18: 84:00:d4:78:6d:51:b6:69

carher commented 4 years ago

Update: After some hours, the problem simply wasn't there anymore. We did nothing on our side. But we still wonder what could have been the cause of this, what should we investigate/improve on our side?

We had a theory about OCSP being more dynamic than expected, and that we for a few hours were routed to an address that was not open in our firewall. But at the same time, we cannot see any blocked outgoing requests.

Suggestions for how to investigate this, and avoid future problems?

kukel commented 4 years ago

Could be very well the cause. Oxalis is not the best in reporting the real issues. Often you get very generic or what seem to be unrelated error.