Hi, I moved a Centos 8 server running Oxalis 5.3.0 on Tomcat to Almalinux 9.2. I had to upgrade Oxalis to version 6.0.0-RC3 to get it to work (probably because of Java 11).

The access point is running but we get an error in the end when trying to send an invoice with: java -classpath ".:bin/:as4/" eu.sendregning.oxalis.Main -f /data/www/vhosts/ilge.eu/httpdocs/_peppol/_peppol_out/B19196.xml -r 0106:41020244 -s 0106:34205288 -e /data/www/vhosts/ilge.eu/_peppol_evp

Message failed : Combination of receiver (iso6523-actorid-upis::0106:41020244) and document type identifier (busdox-docid-qns::urn:oasis:names:specification:ubl:schema:xsd:Invoice-2::Invoice##urn:cen.eu:en16931:2017#compliant#urn:fdc:peppol.eu:2017:poacc:billing:3.0::2.1) is not supported.

Total time spent: 1s Attempted to send 0 files Failed transmissions: 1

Also the status page of Oxalis shows 'mode: FRTEST' while it should show PRODUCTION. I think the FRTEST mode is the problem.

I understand that the mode is now determined from the certificate instead of from the config file setting. The certificate is (the same) production certificate and is recognized fine according to the log.

Why is the wrong mode determind for the access point and how can it be changed to production ? I guess this will also solve the document problem when sending (?)

Almalinux(/Redhat) Linux 9.2 java-openjdk-headless-11.0.19.0.7-4.el9.alma.x86_64 tomcat-9.0.62-11.el9.noarch oxalis 6.0.0-RC3

Thanks,

Paul

Hello Paul

It is a little unclear, how did you get the status page of the standalone oxalis, which you used to send a file. If it works in PRODUCTION mode in logs, then it uses lookup into SMP and loads endpoint data from http://smp.peppol.me/iso6523-actorid-upis::0106:41020244 This recipient actually published the endpoint for mentioned document type identifier, but it points to URL https://api.esize.nl/peppol/as4 , whose status page shows Oxalis 4.1 and mode: PRODUCTION : https://api.esize.nl/peppol/status

So how should it connect to your new version of Oxalis? Or you rolled back SMP changes after the test?

Maybe more details/screenshots can explain the issue you have? In any way, Oxalis 6.0.0.RC3 is a release candidate still...

Hi, Thanks for your quick answer.

The status (mode: FRTEST) of the access point shows on the standard status oxalis page https://peppol.ilge.eu/oxalis/status .

When sending from the commandline I see the following file in the oxalis-app.log: 2023-06-12 07:59:00,218 INFO [network.oxalis.vefa.peppol.security.ModeDetector] [] Detected mode: FRTEST

I think this wrong mode is the cause why it can't send an invoice (understandable).

So the question is: how to set the mode to PRODUCTION ? Could this be a problem in the detection of the certificate ?

I know 6.0.0-RC still a release candidate but it was the only version I could get to work on this server and software version.

Regards,

Paul

To use PRODUCTION mode, you need to ensure, that you configured PRODUCTION certificate. To get it detected as FRTEST, you may be copied the reference.conf from test resources of peppol-security (e.g. https://github.com/OxalisCommunity/vefa-peppol/blob/437fa318959772aa4d66dd782b0d3bdcab2e2b50/peppol-security/src/test/resources/fr-poc-test.cer) - that is the only way I see. Which certificate is printed in your logs? Before the mode, it should print the certificate subject and its issuer, something like

INFO [network.oxalis.commons.security.CertificateModule] Certificate subject: CN=dynconcepttestparty02gw, OU=CEF RND ERST, O=Concept Test, L=Copenhagen, ST=Denmark, C=DK
INFO [network.oxalis.commons.security.CertificateModule] Certificate issuer: CN=Concept Test Component CA, OU=CEF RND ERST, O=Concept Test, L=Copenhagen, ST=Denmark, C=DK
INFO [network.oxalis.vefa.peppol.security.ModeDetector] Detected mode: LOCAL_TEST

The way you run standalone version - java -classpath ".:bin/:as4/" - does not explain what is inside there... Usually, to include all jars, you run it like `.:bin/:as4/*" - with asterisk inside, see https://github.com/OxalisCommunity/Oxalis-AS4/blob/master/docs/installation/standalone.md Or did you unpack jars?

Anyway, please double check your reference.conf for oxalis.keystore and security.truststore definitions...

For history - status page of the server https://peppol.ilge.eu/oxalis/status really returns something very confusing - FRTEST for PRODUCTION certificate:

version.oxalis: 6.0.0-RC3
version.java: 11.0.19
mode: FRTEST
certificate.subject: CN=PBE000229,OU=PEPPOL PRODUCTION AP,O=ILGE Subscription Management BVBA,C=BE
certificate.issuer: CN=PEPPOL ACCESS POINT CA - G2,O=OpenPEPPOL AISBL,C=BE
certificate.expired: false
build.id: f447022cbf3d34d8078c6a314b20049fddd6da6d
build.tstamp: 11.05.2023 @ 18:48:42 UTC

I copied the production certificate from the old server to the new server, and the oxalis config file. When sending from the commandline, the first three lines in the oxalis-app.log are: 2023-06-12 07:59:00,195 INFO [network.oxalis.commons.security.CertificateModule] [] Certificate subject: CN=PBE000229, OU=PEPPOL PRODUCTION AP, O=ILGE Subscription Management BVBA, C=BE 2023-06-12 07:59:00,195 INFO [network.oxalis.commons.security.CertificateModule] [] Certificate issuer: CN=PEPPOL ACCESS POINT CA - G2, O=OpenPEPPOL AISBL, C=BE 2023-06-12 07:59:00,218 INFO [network.oxalis.vefa.peppol.security.ModeDetector] [] Detected mode: FRTEST

(As you can see from the status page)

The asterixes were on the commandline but copying the line here apparently deletes them.

(confused indeed)

It becomes really interesting... FRTEST is configured to use fr-poc-ac.jks for truststore and fr-pic-test.xml for detecting the mode as we can see in https://github.com/OxalisCommunity/vefa-peppol/blob/v3.0.0-RC1/peppol-security/src/main/resources/reference.conf (BTW, in v.3.0.0 there is no FRTEST). To be considered as PRODUCTION mode, it should be overwritten in some reference.conf like

mode.PRODUCTION.security.pki = /pki/fr-poc-test.xml
mode.PRODUCTION.security.truststore.ap = /truststore/fr-poc-ap.jks
mode.PRODUCTION.security.truststore.smp = /truststore/peppol-test-smp.jks
mode.PRODUCTION.security.truststore.password = changeit

which is hardly believable you did...

Please check which peppol-security version do you use? May be list your classpath folders with `ls -lar' to see files in your bin and as4 folders...

Please check also your oxalis.conf or optional reference.conf in your classpath - maybe post it here with removed/substituted secrets like passwords...

It says in the releasenotes that 'this version includes support for the French Peppol POC': https://github.com/OxalisCommunity/oxalis/releases (which is possibly analoque then to v.3.0.0-RC1 of the vefa peppol release)

Where do I check the Peppol-security version (and what does it do) ?

The keystore definition in the oxalis.conf file looks like this: oxalis.keystore {

Relative to OXALIS_HOME

 # path=Peppol_cert.pfx
 path=prod_cert.p12
 password="***"
 key.alias="cert"
 key.password="***"

keystore.type=pkcs12

}

These settings in reference.conf look to me like settings for the different possible modes, while the mode is determined in another way. I don't think I (yet) have a reference.conf file anywhere.

ls -lar bin gives: -rw-r--r-- 1 tomcat ilgeeu 946 May 11 21:08 send-self.sh -rw-r--r-- 1 tomcat ilgeeu 18666557 May 11 21:12 oxalis-standalone.jar drwxr-xr-x 10 tomcat ilgeeu 4096 Jun 11 22:05 .. drwxr-xr-x 2 tomcat ilgeeu 4096 Jun 11 15:38 .

ls -lar as4: -rw-r--r-- 1 tomcat ilgeeu 1128579 May 11 22:11 xmlsec-2.3.0.jar -rw-r--r-- 1 tomcat ilgeeu 173411 May 11 22:11 xmlschema-core-2.3.0.jar -rw-r--r-- 1 tomcat ilgeeu 84091 May 11 22:11 xml-resolver-1.2.jar -rw-r--r-- 1 tomcat ilgeeu 410883 May 11 22:11 wss4j-ws-security-stax-2.4.1.jar -rw-r--r-- 1 tomcat ilgeeu 131430 May 11 22:11 wss4j-ws-security-policy-stax-2.4.1.jar -rw-r--r-- 1 tomcat ilgeeu 335570 May 11 22:11 wss4j-ws-security-dom-2.4.1.jar -rw-r--r-- 1 tomcat ilgeeu 277556 May 11 22:11 wss4j-ws-security-common-2.4.1.jar -rw-r--r-- 1 tomcat ilgeeu 212251 May 11 22:11 wss4j-policy-2.4.1.jar -rw-r--r-- 1 tomcat ilgeeu 43070 May 11 22:11 wss4j-bindings-2.4.1.jar -rw-r--r-- 1 tomcat ilgeeu 186758 May 11 22:11 wsdl4j-1.6.3.jar -rw-r--r-- 1 tomcat ilgeeu 1586060 May 11 22:11 woodstox-core-6.4.0.jar -rw-r--r-- 1 tomcat ilgeeu 72008 May 11 22:11 txw2-2.3.5.jar -rw-r--r-- 1 tomcat ilgeeu 38537 May 11 22:11 stax-ex-1.8.3.jar -rw-r--r-- 1 tomcat ilgeeu 195909 May 11 22:11 stax2-api-4.2.1.jar -rw-r--r-- 1 tomcat ilgeeu 456968 May 11 22:11 saaj-impl-1.5.3.jar -rw-r--r-- 1 tomcat ilgeeu 671531 May 11 22:12 oxalis-as4-6.0.0-RC3.jar -rw-r--r-- 1 tomcat ilgeeu 74225 May 11 22:11 neethi-3.2.0.jar -rw-r--r-- 1 tomcat ilgeeu 636782 May 11 22:11 joda-time-2.12.2.jar -rw-r--r-- 1 tomcat ilgeeu 1019255 May 11 22:11 jaxb-runtime-2.3.5.jar -rw-r--r-- 1 tomcat ilgeeu 1133924 May 11 22:11 jaxb-impl-2.3.3.jar -rw-r--r-- 1 tomcat ilgeeu 142255 May 11 22:11 jasypt-1.9.3.jar -rw-r--r-- 1 tomcat ilgeeu 57697 May 11 22:11 jakarta.xml.ws-api-2.3.3.jar -rw-r--r-- 1 tomcat ilgeeu 36922 May 11 22:11 jakarta.xml.soap-api-1.4.2.jar -rw-r--r-- 1 tomcat ilgeeu 115638 May 11 22:11 jakarta.xml.bind-api-2.3.3.jar -rw-r--r-- 1 tomcat ilgeeu 15558 May 11 22:11 jakarta.jws-api-2.1.0.jar -rw-r--r-- 1 tomcat ilgeeu 25058 May 11 22:11 jakarta.annotation-api-1.3.5.jar -rw-r--r-- 1 tomcat ilgeeu 46613 May 11 22:11 jakarta.activation-api-1.2.2.jar -rw-r--r-- 1 tomcat ilgeeu 29807 May 11 22:11 istack-commons-runtime-3.0.12.jar -rw-r--r-- 1 tomcat ilgeeu 16030 May 11 22:11 geronimo-jta_1.1_spec-1.1.1.jar -rw-r--r-- 1 tomcat ilgeeu 707484 May 11 22:11 cxf-rt-ws-security-3.5.5.jar -rw-r--r-- 1 tomcat ilgeeu 215386 May 11 22:11 cxf-rt-ws-policy-3.5.5.jar -rw-r--r-- 1 tomcat ilgeeu 178396 May 11 22:11 cxf-rt-wsdl-3.5.5.jar -rw-r--r-- 1 tomcat ilgeeu 75779 May 11 22:11 cxf-rt-ws-addr-3.5.5.jar -rw-r--r-- 1 tomcat ilgeeu 393916 May 11 22:11 cxf-rt-transports-http-3.5.5.jar -rw-r--r-- 1 tomcat ilgeeu 35287 May 11 22:11 cxf-rt-security-saml-3.5.5.jar -rw-r--r-- 1 tomcat ilgeeu 41599 May 11 22:11 cxf-rt-security-3.5.5.jar -rw-r--r-- 1 tomcat ilgeeu 107725 May 11 22:11 cxf-rt-frontend-simple-3.5.5.jar -rw-r--r-- 1 tomcat ilgeeu 371935 May 11 22:11 cxf-rt-frontend-jaxws-3.5.5.jar -rw-r--r-- 1 tomcat ilgeeu 60080 May 11 22:11 cxf-rt-features-logging-3.5.5.jar -rw-r--r-- 1 tomcat ilgeeu 115318 May 11 22:11 cxf-rt-databinding-jaxb-3.5.5.jar -rw-r--r-- 1 tomcat ilgeeu 38471 May 11 22:11 cxf-rt-bindings-xml-3.5.5.jar -rw-r--r-- 1 tomcat ilgeeu 182643 May 11 22:11 cxf-rt-bindings-soap-3.5.5.jar -rw-r--r-- 1 tomcat ilgeeu 1435610 May 11 22:11 cxf-core-3.5.5.jar -rw-r--r-- 1 tomcat ilgeeu 162471 May 11 22:11 cryptacular-1.2.4.jar -rw-r--r-- 1 tomcat ilgeeu 122445 May 11 22:11 asm-9.4.jar drwxr-xr-x 10 tomcat ilgeeu 4096 Jun 11 22:05 .. drwxr-xr-x 2 tomcat ilgeeu 4096 Jun 11 22:03 .

oxalis 6.0.0-RC3 installed from https://github.com/OxalisCommunity/oxalis/releases/download/v6.0.0-RC3/oxalis-distribution-6.0.0-RC3-distro.tar.gz and as4 plugin from https://github.com/OxalisCommunity/Oxalis-AS4/releases/download/v6.0.0-RC3/oxalis-as4-6.0.0-RC3-dist.tar.gz

I will try this build by myself later today and return back.

Hello Paul

I am not able to reproduce your issue with RC3 (although I run it on Windows). With similar setup I get a correct sender log mode detection:

...
2023-06-12 17:31:29,641 INFO [network.oxalis.commons.security.CertificateModule] Certificate subject: CN=MY_PROD_CERTIFICATE, OU=PEPPOL PRODUCTION AP, O=My Company A/S, C=DK
2023-06-12 17:31:29,641 INFO [network.oxalis.commons.security.CertificateModule] Certificate issuer: CN=PEPPOL ACCESS POINT CA - G2, O=OpenPEPPOL AISBL, C=BE
2023-06-12 17:31:29,816 INFO [network.oxalis.vefa.peppol.security.ModeDetector] Detection error (FRTEST): Validation of subject principal(CN) failed.
2023-06-12 17:31:29,823 INFO [network.oxalis.vefa.peppol.security.ModeDetector] Detection error (TEST): Validation of subject principal(CN) failed.
2023-06-12 17:31:29,830 INFO [network.oxalis.vefa.peppol.security.ModeDetector] Detection error (LOCAL): Certificate should be self-signed.
2023-06-12 17:31:31,681 INFO [network.oxalis.vefa.peppol.security.ModeDetector] Detected mode: PRODUCTION
2023-06-12 17:31:31,685 INFO [network.oxalis.outbound.transmission.MessageSenderFactory] Prioritized list of transport profiles:
2023-06-12 17:31:31,685 INFO [network.oxalis.outbound.transmission.MessageSenderFactory] => peppol-transport-as4-v2_0
2023-06-12 17:31:31,685 INFO [network.oxalis.outbound.transmission.MessageSenderFactory] => busdox-transport-as2-ver1p0r1
2023-06-12 17:31:31,685 INFO [network.oxalis.outbound.transmission.MessageSenderFactory] => busdox-transport-as2-ver2p0
2023-06-12 17:31:31,685 INFO [network.oxalis.outbound.transmission.MessageSenderFactory] => busdox-transport-as2-ver1p0
...

As you can see, my PROD certificate fails FRTEST detection, but succeeds PRODUCTION detection. I do not understand why it satisfies your FRTEST detection, as it requires the certificate to have issuer "Peppol FRPOC AP TEST CA", but your certificate has a production issuer "PEPPOL ACCESS POINT CA - G2"...

Can you post here logs from your standalone sender client when it fails to send an invoice (cleaned from private data if there are), to have a full picture and exclude misunderstanding?

Thank you for testing ! Strange..the only differences I see is that you use de vefa peppol repo, and you're on Windows.

The other ModeDetector lines are completely missing from my log:

2023-06-12 07:59:00,195 INFO [network.oxalis.commons.security.CertificateModule] [] Certificate subject: CN=PBE000229, OU=PEPPOL PRODUCTION AP, O=ILGE Subscription Management BVBA, C=BE 2023-06-12 07:59:00,195 INFO [network.oxalis.commons.security.CertificateModule] [] Certificate issuer: CN=PEPPOL ACCESS POINT CA - G2, O=OpenPEPPOL AISBL, C=BE 2023-06-12 07:59:00,218 INFO [network.oxalis.vefa.peppol.security.ModeDetector] [] Detected mode: FRTEST 2023-06-12 07:59:00,221 INFO [network.oxalis.outbound.transmission.MessageSenderFactory] [] Prioritized list of transport profiles: 2023-06-12 07:59:00,221 INFO [network.oxalis.outbound.transmission.MessageSenderFactory] [] => peppol-transport-as4-v2_0 2023-06-12 07:59:00,221 INFO [network.oxalis.outbound.transmission.MessageSenderFactory] [] => busdox-transport-as2-ver1p0r1 2023-06-12 07:59:00,221 INFO [network.oxalis.outbound.transmission.MessageSenderFactory] [] => busdox-transport-as2-ver2p0 2023-06-12 07:59:00,221 INFO [network.oxalis.outbound.transmission.MessageSenderFactory] [] => busdox-transport-as2-ver1p0 2023-06-12 07:59:00,780 DEBUG [org.xbill.DNS.config.JndiContextResolverConfigProvider$InnerJndiContextResolverConfigProvider] [] JNDI class: javax.naming.directory.DirContext 2023-06-12 07:59:00,783 DEBUG [org.xbill.DNS.config.ResolvConfResolverConfigProvider] [] Added ilge.eu. to search paths 2023-06-12 07:59:00,784 DEBUG [org.xbill.DNS.config.ResolvConfResolverConfigProvider] [] Added /127.0.0.1:53 to nameservers 2023-06-12 07:59:00,784 DEBUG [org.xbill.DNS.config.ResolvConfResolverConfigProvider] [] Added /185.12.64.1:53 to nameservers 2023-06-12 07:59:00,784 DEBUG [org.xbill.DNS.config.ResolvConfResolverConfigProvider] [] Added /185.12.64.2:53 to nameservers 2023-06-12 07:59:00,785 DEBUG [org.xbill.DNS.config.ResolvConfResolverConfigProvider] [] Added /0:0:0:0:0:0:0:1:53 to nameservers 2023-06-12 07:59:01,390 DEBUG [org.xbill.DNS.Lookup] [] Lookup for B-010c97c143273f2d2a9519829e355f82.iso6523-actorid-upis.acc.edelivery.tech.ec.europa.eu./A, cache answer: unknown 2023-06-12 07:59:01,396 DEBUG [org.xbill.DNS.ExtendedResolver] [] Sending B-010c97c143273f2d2a9519829e355f82.iso6523-actorid-upis.acc.edelivery.tech.ec.europa.eu./A, id=42620 to resolver 0 (SimpleResolver [/127.0.0.1:53]), attempt 1 of 3 2023-06-12 07:59:01,398 DEBUG [org.xbill.DNS.SimpleResolver] [] Sending B-010c97c143273f2d2a9519829e355f82.iso6523-actorid-upis.acc.edelivery.tech.ec.europa.eu./A, id=42620 to udp/127.0.0.1:53 2023-06-12 07:59:01,403 DEBUG [org.xbill.DNS.NioClient] [] Starting dnsjava NIO selector thread 2023-06-12 07:59:01,423 DEBUG [org.xbill.DNS.Cache] [] Caching CNAME: { B-010c97c143273f2d2a9519829e355f82.iso6523-actorid-upis.acc.edelivery.tech.ec.europa.eu. 60 IN CNAME [TICKSTAR-TEST-IE-SMP.publisher.acc.edelivery.tech.ec.europa.eu.] } for B-010c97c143273f2d2a9519829e355f82.iso6523-actorid-upis.acc.edelivery.tech.ec.europa.eu./A 2023-06-12 07:59:01,424 DEBUG [org.xbill.DNS.Lookup] [] Queried B-010c97c143273f2d2a9519829e355f82.iso6523-actorid-upis.acc.edelivery.tech.ec.europa.eu./A, id=42620: CNAME: { B-010c97c143273f2d2a9519829e355f82.iso6523-actorid-upis.acc.edelivery.tech.ec.europa.eu. 60 IN CNAME [TICKSTAR-TEST-IE-SMP.publisher.acc.edelivery.tech.ec.europa.eu.] } 2023-06-12 07:59:01,424 DEBUG [org.xbill.DNS.Lookup] [] Lookup for TICKSTAR-TEST-IE-SMP.publisher.acc.edelivery.tech.ec.europa.eu./A, cache answer: CNAME: { TICKSTAR-TEST-IE-SMP.publisher.acc.edelivery.tech.ec.europa.eu. 60 IN CNAME [smp.test.galaxygw.com.] } cl = 3 2023-06-12 07:59:01,424 DEBUG [org.xbill.DNS.Lookup] [] Lookup for smp.test.galaxygw.com./A, cache answer: successful 2023-06-12 07:59:01,467 DEBUG [org.apache.http.client.protocol.RequestAddCookies] [] CookieSpec selected: default 2023-06-12 07:59:01,472 DEBUG [org.apache.http.client.protocol.RequestAuthCache] [] Auth cache not set in the context 2023-06-12 07:59:01,472 DEBUG [org.apache.http.impl.conn.PoolingHttpClientConnectionManager] [] Connection request: [route: {}->http://B-010c97c143273f2d2a9519829e355f82.iso6523-actorid-upis.acc.edelivery.tech.ec.europa.eu:80][total available: 0; route allocated: 0 of 2; total allocated: 0 of 20] 2023-06-12 07:59:01,479 DEBUG [org.apache.http.impl.conn.PoolingHttpClientConnectionManager] [] Connection leased: [id: 0][route: {}->http://B-010c97c143273f2d2a9519829e355f82.iso6523-actorid-upis.acc.edelivery.tech.ec.europa.eu:80][total available: 0; route allocated: 1 of 2; total allocated: 1 of 20] 2023-06-12 07:59:01,480 DEBUG [org.apache.http.impl.execchain.MainClientExec] [] Opening connection {}->http://B-010c97c143273f2d2a9519829e355f82.iso6523-actorid-upis.acc.edelivery.tech.ec.europa.eu:80 2023-06-12 07:59:01,482 DEBUG [org.apache.http.impl.conn.DefaultHttpClientConnectionOperator] [] Connecting to B-010c97c143273f2d2a9519829e355f82.iso6523-actorid-upis.acc.edelivery.tech.ec.europa.eu/34.247.126.170:80 2023-06-12 07:59:01,531 DEBUG [org.apache.http.impl.conn.DefaultHttpClientConnectionOperator] [] Connection established 65.109.173.125:56328<->34.247.126.170:80 2023-06-12 07:59:01,531 DEBUG [org.apache.http.impl.conn.DefaultManagedHttpClientConnection] [] http-outgoing-0: set socket timeout to 0 2023-06-12 07:59:01,531 DEBUG [org.apache.http.impl.execchain.MainClientExec] [] Executing request GET /iso6523-actorid-upis%3A%3A0106%3A41020244/services/busdox-docid-qns%3A%3Aurn%3Aoasis%3Anames%3Aspecification%3Aubl%3Aschema%3Axsd%3AInvoice-2%3A%3AInvoice%23%23urn%3Acen.eu%3Aen16931%3A2017%23compliant%23urn%3Afdc%3Apeppol.eu%3A2017%3Apoacc%3Abilling%3A3.0%3A%3A2.1 HTTP/1.1 2023-06-12 07:59:01,532 DEBUG [org.apache.http.impl.execchain.MainClientExec] [] Target auth state: UNCHALLENGED 2023-06-12 07:59:01,532 DEBUG [org.apache.http.impl.execchain.MainClientExec] [] Proxy auth state: UNCHALLENGED 2023-06-12 07:59:01,536 DEBUG [org.apache.http.headers] [] http-outgoing-0 >> GET /iso6523-actorid-upis%3A%3A0106%3A41020244/services/busdox-docid-qns%3A%3Aurn%3Aoasis%3Anames%3Aspecification%3Aubl%3Aschema%3Axsd%3AInvoice-2%3A%3AInvoice%23%23urn%3Acen.eu%3Aen16931%3A2017%23compliant%23urn%3Afdc%3Apeppol.eu%3A2017%3Apoacc%3Abilling%3A3.0%3A%3A2.1 HTTP/1.1 2023-06-12 07:59:01,536 DEBUG [org.apache.http.headers] [] http-outgoing-0 >> Host: B-010c97c143273f2d2a9519829e355f82.iso6523-actorid-upis.acc.edelivery.tech.ec.europa.eu 2023-06-12 07:59:01,536 DEBUG [org.apache.http.headers] [] http-outgoing-0 >> Connection: Keep-Alive 2023-06-12 07:59:01,537 DEBUG [org.apache.http.headers] [] http-outgoing-0 >> User-Agent: Oxalis 6.0.0-RC3 2023-06-12 07:59:01,537 DEBUG [org.apache.http.headers] [] http-outgoing-0 >> Accept-Encoding: gzip,deflate 2023-06-12 07:59:01,537 DEBUG [org.apache.http.wire] [] http-outgoing-0 >> "GET /iso6523-actorid-upis%3A%3A0106%3A41020244/services/busdox-docid-qns%3A%3Aurn%3Aoasis%3Anames%3Aspecification%3Aubl%3Aschema%3Axsd%3AInvoice-2%3A%3AInvoice%23%23urn%3Acen.eu%3Aen16931%3A2017%23compliant%23urn%3Afdc%3Apeppol.eu%3A2017%3Apoacc%3Abilling%3A3.0%3A%3A2.1 HTTP/1.1[\r][\n]" 2023-06-12 07:59:01,537 DEBUG [org.apache.http.wire] [] http-outgoing-0 >> "Host: B-010c97c143273f2d2a9519829e355f82.iso6523-actorid-upis.acc.edelivery.tech.ec.europa.eu[\r][\n]" 2023-06-12 07:59:01,537 DEBUG [org.apache.http.wire] [] http-outgoing-0 >> "Connection: Keep-Alive[\r][\n]" 2023-06-12 07:59:01,537 DEBUG [org.apache.http.wire] [] http-outgoing-0 >> "User-Agent: Oxalis 6.0.0-RC3[\r][\n]" 2023-06-12 07:59:01,537 DEBUG [org.apache.http.wire] [] http-outgoing-0 >> "Accept-Encoding: gzip,deflate[\r][\n]" 2023-06-12 07:59:01,537 DEBUG [org.apache.http.wire] [] http-outgoing-0 >> "[\r][\n]" 2023-06-12 07:59:01,590 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "HTTP/1.1 404 [\r][\n]" 2023-06-12 07:59:01,590 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "Date: Mon, 12 Jun 2023 07:59:01 GMT[\r][\n]" 2023-06-12 07:59:01,590 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "Content-Type: text/plain[\r][\n]" 2023-06-12 07:59:01,590 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "Content-Length: 26[\r][\n]" 2023-06-12 07:59:01,590 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "Connection: keep-alive[\r][\n]" 2023-06-12 07:59:01,590 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "Cache-Control: no-cache[\r][\n]" 2023-06-12 07:59:01,590 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "[\r][\n]" 2023-06-12 07:59:01,590 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "ServiceMetadata not found." 2023-06-12 07:59:01,594 DEBUG [org.apache.http.headers] [] http-outgoing-0 << HTTP/1.1 404
2023-06-12 07:59:01,594 DEBUG [org.apache.http.headers] [] http-outgoing-0 << Date: Mon, 12 Jun 2023 07:59:01 GMT 2023-06-12 07:59:01,594 DEBUG [org.apache.http.headers] [] http-outgoing-0 << Content-Type: text/plain 2023-06-12 07:59:01,594 DEBUG [org.apache.http.headers] [] http-outgoing-0 << Content-Length: 26 2023-06-12 07:59:01,594 DEBUG [org.apache.http.headers] [] http-outgoing-0 << Connection: keep-alive 2023-06-12 07:59:01,594 DEBUG [org.apache.http.headers] [] http-outgoing-0 << Cache-Control: no-cache 2023-06-12 07:59:01,600 DEBUG [org.apache.http.impl.execchain.MainClientExec] [] Connection can be kept alive indefinitely 2023-06-12 07:59:01,603 DEBUG [org.apache.http.impl.conn.DefaultManagedHttpClientConnection] [] http-outgoing-0: Close connection 2023-06-12 07:59:01,603 DEBUG [org.apache.http.impl.execchain.MainClientExec] [] Connection discarded 2023-06-12 07:59:01,603 DEBUG [org.apache.http.impl.conn.PoolingHttpClientConnectionManager] [] Connection released: [id: 0][route: {}->http://B-010c97c143273f2d2a9519829e355f82.iso6523-actorid-upis.acc.edelivery.tech.ec.europa.eu:80][total available: 0; route allocated: 0 of 2; total allocated: 0 of 20] 2023-06-12 07:59:01,606 ERROR [eu.sendregning.oxalis.Main] [] Execution failed: network.oxalis.api.lang.OxalisTransmissionException: No transmission is provided. java.util.concurrent.ExecutionException: network.oxalis.api.lang.OxalisTransmissionException: No transmission is provided. at java.base/java.util.concurrent.FutureTask.report(FutureTask.java:122) at java.base/java.util.concurrent.FutureTask.get(FutureTask.java:191) at eu.sendregning.oxalis.Main.main(Main.java:228) Caused by: network.oxalis.api.lang.OxalisTransmissionException: No transmission is provided. at network.oxalis.outbound.transmission.DefaultTransmitter.perform(DefaultTransmitter.java:116) at network.oxalis.outbound.transmission.DefaultTransmitter.transmit(DefaultTransmitter.java:93) at eu.sendregning.oxalis.TransmissionTask.performTransmission(TransmissionTask.java:166) at eu.sendregning.oxalis.TransmissionTask.call(TransmissionTask.java:94) at eu.sendregning.oxalis.TransmissionTask.call(TransmissionTask.java:48) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:829) 2023-06-12 07:59:01,637 DEBUG [org.xbill.DNS.NioClient] [] dnsjava NIO selector thread stopped [root@srv02 oxalis]#

Can you post the whole log output - starting from your shell file invocation?

There should be something about SettingsBuilder and oxalis home configuration like this:

2023-06-11 14:43:04,280 INFO [network.oxalis.commons.filesystem.detector.EnvironmentHomeDetector] Using Oxalis folder specified as environment variable 'OXALIS_HOME' with value 'D:\work\oxalis\6.0.0\home_edelivery'.
2023-06-11 14:43:04,284 INFO [network.oxalis.commons.filesystem.FileSystemModule] Home folder: D:\work\oxalis\6.0.0\home_edelivery
2023-06-11 14:43:04,284 INFO [network.oxalis.commons.filesystem.FileSystemModule] Configuration folder: D:\work\oxalis\6.0.0\home_edelivery
2023-06-11 14:43:04,285 INFO [network.oxalis.commons.config.ConfigModule] Configuration file: D:\work\oxalis\6.0.0\home_edelivery\oxalis.conf
2023-06-11 14:43:04,289 INFO [network.oxalis.commons.settings.SettingsBuilder] File system => CONF:
2023-06-11 14:43:04,289 INFO [network.oxalis.commons.settings.SettingsBuilder] File system => INBOUND: inbound
2023-06-11 14:43:04,289 INFO [network.oxalis.commons.settings.SettingsBuilder] File system => PLUGIN: <null>
2023-06-11 14:43:05,178 INFO [network.oxalis.commons.filesystem.detector.EnvironmentHomeDetector] Using Oxalis folder specified as environment variable 'OXALIS_HOME' with value 'D:\work\oxalis\6.0.0\home_edelivery'.
2023-06-11 14:43:05,179 INFO [network.oxalis.commons.filesystem.FileSystemModule] Home folder: D:\work\oxalis\6.0.0\home_edelivery
2023-06-11 14:43:05,179 INFO [network.oxalis.commons.filesystem.FileSystemModule] Configuration folder: D:\work\oxalis\6.0.0\home_edelivery
2023-06-11 14:43:05,179 INFO [network.oxalis.commons.config.ConfigModule] Configuration file: D:\work\oxalis\6.0.0\home_edelivery\oxalis.conf
2023-06-11 14:43:05,181 INFO [network.oxalis.commons.settings.SettingsBuilder] HTTP => POOL_TOTAL: 20
2023-06-11 14:43:05,181 INFO [network.oxalis.commons.settings.SettingsBuilder] HTTP => POOL_MAX_ROUTE: 2
2023-06-11 14:43:05,181 INFO [network.oxalis.commons.settings.SettingsBuilder] HTTP => POOL_VALIDATE_AFTER_INACTIVITY: 1000
2023-06-11 14:43:05,181 INFO [network.oxalis.commons.settings.SettingsBuilder] HTTP => POOL_TIME_TO_LIVE: 30
2023-06-11 14:43:05,181 INFO [network.oxalis.commons.settings.SettingsBuilder] HTTP => TIMEOUT_CONNECT: 0
2023-06-11 14:43:05,181 INFO [network.oxalis.commons.settings.SettingsBuilder] HTTP => TIMEOUT_READ: 0
2023-06-11 14:43:05,181 INFO [network.oxalis.commons.settings.SettingsBuilder] HTTP => TIMEOUT_SOCKET: 0
2023-06-11 14:43:05,182 INFO [network.oxalis.commons.settings.SettingsBuilder] Error => TRACKER: quiet
2023-06-11 14:43:05,182 INFO [network.oxalis.commons.settings.SettingsBuilder] AS2 => NOTIFICATION: not.in.use@difi.no
2023-06-11 14:43:05,182 INFO [network.oxalis.commons.settings.SettingsBuilder] File system => CONF:
2023-06-11 14:43:05,182 INFO [network.oxalis.commons.settings.SettingsBuilder] File system => INBOUND: inbound

I am sure there is some misconfiguration, but I cannot see which one. But if FRTEST can take over PRODUCTION in some cases - it could be a critical bug, that is why I need to see how to reproduce it...

This is the output on the commandline: [root@srv02 oxalis]# java -classpath ".:bin/:as4/" eu.sendregning.oxalis.Main -f /data/www/vhosts/ilge.eu/httpdocs/_peppol/_peppol_out/B19196.xml -r 0106:41020244 -s 0106:34205288 -e /data/www/vhosts/ilge.eu/_peppol_evp 2023-06-12 16:22:24,964 INFO [network.oxalis.commons.filesystem.detector.EnvironmentHomeDetector] Using Oxalis folder specified as environment variable 'OXALIS_HOME' with value '/home/tomcat/.oxalis'. 2023-06-12 16:22:24,968 INFO [network.oxalis.commons.filesystem.FileSystemModule] Home folder: /home/tomcat/.oxalis 2023-06-12 16:22:24,968 INFO [network.oxalis.commons.filesystem.FileSystemModule] Configuration folder: /home/tomcat/.oxalis 2023-06-12 16:22:24,968 INFO [network.oxalis.commons.config.ConfigModule] Configuration file: /home/tomcat/.oxalis/oxalis.conf 2023-06-12 16:22:24,972 INFO [network.oxalis.commons.settings.SettingsBuilder] File system => CONF:
2023-06-12 16:22:24,972 INFO [network.oxalis.commons.settings.SettingsBuilder] File system => INBOUND: /data/www/vhosts/ilge.eu/_peppol_in 2023-06-12 16:22:24,972 INFO [network.oxalis.commons.settings.SettingsBuilder] File system => PLUGIN: 2023-06-12 16:22:25,233 INFO [network.oxalis.as4.util.OxalisAlgorithmSuiteLoader] Registering OxalisAlgorithmSuite on bus cxf1521204009 WARNING: An illegal reflective access operation has occurred WARNING: Illegal reflective access by com.sun.xml.bind.v2.runtime.reflect.opt.Injector (file:/data/home/tomcat/oxalis-6.0.0-RC3/bin/oxalis-standalone.jar) to method java.lang.ClassLoader.defineClass(java.lang.String,byte[],int,int) WARNING: Please consider reporting this to the maintainers of com.sun.xml.bind.v2.runtime.reflect.opt.Injector WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations WARNING: All illegal access operations will be denied in a future release 2023-06-12 16:22:26,046 INFO [network.oxalis.commons.filesystem.detector.EnvironmentHomeDetector] Using Oxalis folder specified as environment variable 'OXALIS_HOME' with value '/home/tomcat/.oxalis'. 2023-06-12 16:22:26,046 INFO [network.oxalis.commons.filesystem.FileSystemModule] Home folder: /home/tomcat/.oxalis 2023-06-12 16:22:26,046 INFO [network.oxalis.commons.filesystem.FileSystemModule] Configuration folder: /home/tomcat/.oxalis 2023-06-12 16:22:26,046 INFO [network.oxalis.commons.config.ConfigModule] Configuration file: /home/tomcat/.oxalis/oxalis.conf 2023-06-12 16:22:26,048 INFO [network.oxalis.commons.settings.SettingsBuilder] HTTP => POOL_TOTAL: 20 2023-06-12 16:22:26,048 INFO [network.oxalis.commons.settings.SettingsBuilder] HTTP => POOL_MAX_ROUTE: 2 2023-06-12 16:22:26,048 INFO [network.oxalis.commons.settings.SettingsBuilder] HTTP => POOL_VALIDATE_AFTER_INACTIVITY: 1000 2023-06-12 16:22:26,048 INFO [network.oxalis.commons.settings.SettingsBuilder] HTTP => POOL_TIME_TO_LIVE: 30 2023-06-12 16:22:26,048 INFO [network.oxalis.commons.settings.SettingsBuilder] HTTP => TIMEOUT_CONNECT: 0 2023-06-12 16:22:26,048 INFO [network.oxalis.commons.settings.SettingsBuilder] HTTP => TIMEOUT_READ: 0 2023-06-12 16:22:26,048 INFO [network.oxalis.commons.settings.SettingsBuilder] HTTP => TIMEOUT_SOCKET: 0 2023-06-12 16:22:26,048 INFO [network.oxalis.commons.settings.SettingsBuilder] Error => TRACKER: quiet 2023-06-12 16:22:26,048 INFO [network.oxalis.commons.settings.SettingsBuilder] AS2 => NOTIFICATION: not.in.use@difi.no 2023-06-12 16:22:26,048 INFO [network.oxalis.commons.settings.SettingsBuilder] File system => CONF:
2023-06-12 16:22:26,048 INFO [network.oxalis.commons.settings.SettingsBuilder] File system => INBOUND: /data/www/vhosts/ilge.eu/_peppol_in 2023-06-12 16:22:26,048 INFO [network.oxalis.commons.settings.SettingsBuilder] File system => PLUGIN: 2023-06-12 16:22:26,048 INFO [network.oxalis.commons.settings.SettingsBuilder] Identifiers => HOSTNAME:
2023-06-12 16:22:26,048 INFO [network.oxalis.commons.settings.SettingsBuilder] Identifiers => MSGID_GENERATOR: default 2023-06-12 16:22:26,049 INFO [network.oxalis.commons.settings.SettingsBuilder] Key store => PATH: prod_cert.p12 2023-06-12 16:22:26,049 INFO [network.oxalis.commons.settings.SettingsBuilder] Key store => PASSWORD: **** 2023-06-12 16:22:26,049 INFO [network.oxalis.commons.settings.SettingsBuilder] Key store => KEY_ALIAS: cert 2023-06-12 16:22:26,049 INFO [network.oxalis.commons.settings.SettingsBuilder] Key store => KEY_PASSWORD: **** 2023-06-12 16:22:26,049 INFO [network.oxalis.commons.settings.SettingsBuilder] Header => PARSER: sbdh 2023-06-12 16:22:26,049 INFO [network.oxalis.commons.settings.SettingsBuilder] Persister => PAYLOAD: default 2023-06-12 16:22:26,049 INFO [network.oxalis.commons.settings.SettingsBuilder] Persister => RECEIPT: default 2023-06-12 16:22:26,049 INFO [network.oxalis.commons.settings.SettingsBuilder] Persister => EXCEPTION: default 2023-06-12 16:22:26,049 INFO [network.oxalis.commons.settings.SettingsBuilder] Persister => HANDLER: default 2023-06-12 16:22:26,049 INFO [network.oxalis.commons.settings.SettingsBuilder] Tracing => REPORTER: noop 2023-06-12 16:22:26,049 INFO [network.oxalis.commons.settings.SettingsBuilder] Tracing => HTTP: 2023-06-12 16:22:26,049 INFO [network.oxalis.commons.settings.SettingsBuilder] Tracing => TRACER: noop 2023-06-12 16:22:26,049 INFO [network.oxalis.commons.settings.SettingsBuilder] Executor => DEFAULT: 50 2023-06-12 16:22:26,050 INFO [network.oxalis.commons.settings.SettingsBuilder] Executor => STATISTICS: 50 2023-06-12 16:22:26,050 INFO [network.oxalis.commons.settings.SettingsBuilder] Tag => GENERATOR: noop 2023-06-12 16:22:26,050 INFO [network.oxalis.commons.settings.SettingsBuilder] Timestamp => SERVICE: system 2023-06-12 16:22:26,050 INFO [network.oxalis.commons.settings.SettingsBuilder] Evidence => SERVICE: rem 2023-06-12 16:22:26,050 INFO [network.oxalis.commons.settings.SettingsBuilder] Transformer => DETECTOR: noop 2023-06-12 16:22:26,050 INFO [network.oxalis.commons.settings.SettingsBuilder] Transformer => WRAPPER: xml 2023-06-12 16:22:26,050 INFO [network.oxalis.commons.settings.SettingsBuilder] Statistics => SERVICE: noop 2023-06-12 16:22:26,050 INFO [network.oxalis.commons.settings.SettingsBuilder] Transmission => VERIFIER: default 2023-06-12 16:22:26,050 INFO [network.oxalis.commons.settings.SettingsBuilder] AS4 => HOSTNAME:
2023-06-12 16:22:26,050 INFO [network.oxalis.commons.settings.SettingsBuilder] AS4 => MSGID_GENERATOR: default 2023-06-12 16:22:26,050 INFO [network.oxalis.commons.settings.SettingsBuilder] AS4 => TYPE: peppol 2023-06-12 16:22:26,050 INFO [network.oxalis.commons.settings.SettingsBuilder] Logging => CONFIG: logback-oxalis.xml 2023-06-12 16:22:26,051 INFO [network.oxalis.commons.settings.SettingsBuilder] Logging => SERVICE: logback 2023-06-12 16:22:26,051 INFO [network.oxalis.commons.logging.LoggingHandler] Logging service: logback Configuring Logback with configuration: /home/tomcat/.oxalis/logback-oxalis.xml

Total time spent: 1s Attempted to send 0 files Failed transmissions: 1 [root@srv02 oxalis]#

The only way I managed for now to get similar misconfiguration with FRTEST - is including into reference.conf in classpath the next line:

mode.default.security.validator.class = network.oxalis.vefa.peppol.security.util.EmptyCertificateValidator

It says, that by default any mode should be accepted - and correct value for it is network.oxalis.vefa.peppol.security.util.DifiCertificateValidator, and it is defined inside your oxalis-standalone.jar located at bin folder in reference.conf.

If I do it like this, I get the any first potential mode to be accepted - FRTEST in this case...

Please copy your command line and oxalis.conf again (without passwords) - but in a proper github fenced code block, so asterisks and potentially other special symbols are not hidden - see here: https://docs.github.com/en/get-started/writing-on-github/working-with-advanced-formatting/creating-and-highlighting-code-blocks

I hardly believe you have this line there - but I am out of ideas. In order to see the reason, the only option I see is a remote debugging of what happens inside ModeDetector class logic, as ModeDetector does not log its details...

It could help to include logging Mode.getConfig().render() into the code you run, which prints ALL configurations you have in multiple reference.conf and oxalis.conf files which are present in your classpath - to see where the proper setup is overwritten...

Hmm... There are chances that you have it :) I found this comment, where someone used such setup to make CEF conformance test:

https://github.com/OxalisCommunity/Oxalis-AS4/issues/17#issuecomment-493041277

Similar setup is present in an old Docker image readme: https://hub.docker.com/r/digdir/oxalis-as4

So theoretically this line could be present in your old oxalis.conf as a result of some previous attempts to pass some test. In old Oxalis you could have the first mode not FRTEST, but PRODUCTION - so it worked, but actually did not validate the mode.

So please check if you have anything like EmptyCertificateValidator in your configuration...

Brilliant ! That was it. While testing during the last days I also found this issue and added the two line to the configuration file. It then solved a problem in an older version but I found later that the first line was not necessary anymore, so I commented it out again. But not the second line.

mode.conformance.lookup.locator.hostname="acc.edelivery.tech.ec.europa.eu/edelivery-sml/" mode.conformance.security.validator.class="no.difi.vefa.peppol.security.util.EmptyCertificateValidator"

The invoice is now successfully sent and the AP is running in PRODUCTION mode. Case closed.

Thanks for all your effort.

Paul

OxalisCommunity / oxalis

SOLVED: urgent: 6.0.0-RC3 issue: can't send invoices, status page shows 'mode: FRTEST' instead of PRODUCTION #627

The access point is running but we get an error in the end when trying to send an invoice with: java -classpath ".:bin/:as4/" eu.sendregning.oxalis.Main -f /data/www/vhosts/ilge.eu/httpdocs/_peppol/_peppol_out/B19196.xml -r 0106:41020244 -s 0106:34205288 -e /data/www/vhosts/ilge.eu/_peppol_evp

Total time spent: 1s Attempted to send 0 files Failed transmissions: 1

Relative to OXALIS_HOME

keystore.type=pkcs12

Brilliant ! That was it. While testing during the last days I also found this issue and added the two line to the configuration file. It then solved a problem in an older version but I found later that the first line was not necessary anymore, so I commented it out again. But not the second line.

mode.conformance.lookup.locator.hostname="acc.edelivery.tech.ec.europa.eu/edelivery-sml/" mode.conformance.security.validator.class="no.difi.vefa.peppol.security.util.EmptyCertificateValidator"