search

OxalisCommunity / Oxalis-AS4

PEPPOL AS4 pMode plugin for Oxalis
32 stars 26 forks source link

oxalis-standalone AS4 "A security error was encountered when verifying the message" #15

Closed alessandrolorenzetti closed 5 years ago

alessandrolorenzetti commented 5 years ago

Good evening, I'm running the AS4 Conformance / onboarding test on the https://testbed.peppol.eu/secure/suite/view platform.

My user is PIT000252

I performed AS2 tests with success and started doing AS4 tests.

As for the AS4 tests I was receive (first test) a document from testbed laform .... but when I try resend to the test platform I get a error.

The component in error is oxalis-standalone

Configuration AP Oxalis 4.0.4 + AS4: 4.1.0 RC5

oxalis.conf

oxalis.keystore {

Relative to OXALIS_HOME

 path=oxalis-keystore.jks
 password = xxxxx
 key.alias = oxalis-ap
 key.password = xxxxxx

}

transport.as4_peppol_v1_to_v2_adapter = { profile: bdxr-transport-ebms3-as4-v1p0 sender: oxalis-as4 weight: 5000 }

oxalis.truststore { path = pilot-truststore.jks password = xxxxxxx } lookup.locator.hostname: acc.edelivery.tech.ec.europa.eu oxalis.path.plugin = oxalis-plugin oxalis.persister.receipt = plugin oxalis.path.inbound = IN oxalis.logging.config = logback.xml

keytool -list -v -keystore oxalis-keystore.jks

Keystore type: JKS Keystore provider: SUN

Your keystore contains 2 entries

Alias name: oxalis-ap Creation date: 26-mar-2019 Entry type: PrivateKeyEntry Certificate chain length: 2 Certificate[1]: Owner: C=IT, O="Infocamere ", OU=PEPPOL TEST AP, CN=PIT000252 Issuer: CN=PEPPOL ACCESS POINT TEST CA - G2, OU=FOR TEST ONLY, O=OpenPEPPOL AISBL, C=BE ....... Signature algorithm name: SHA256withRSA Version: 3

Extensions: ....... Certificate[2]: Owner: CN=PEPPOL ACCESS POINT TEST CA - G2, OU=FOR TEST ONLY, O=OpenPEPPOL AISBL, C=BE Issuer: CN=PEPPOL Root TEST CA - G2, OU=FOR TEST ONLY, O=OpenPEPPOL AISBL, C=BE Serial number: 36549386b9e6b821d2892d5a9ee9ae60 Valid from: Thu Jan 04 01:00:00 CET 2018 until: Mon Jan 03 00:59:59 CET 2028 Certificate fingerprints: MD5: 8E:CF:5B:50:E3:27:4E:D3:12:6E:62:E7:66:7B:27:8E SHA1: A0:62:7C:7D:3E:96:E4:15:14:18:8A:90:A8:40:39:6B:1F:9C:53:92 SHA256: 03:9A:30:FF:CA:41:44:46:80:2A:F0:22:BB:B7:EE:61:4E:98:6A:12:B9:2E:95:2C:B4:92:C8:EF:62:C9:62:E6 Signature algorithm name: SHA256withRSA Version: 3

Extensions: ........

Alias name: peppol root test ca - g2 Creation date: 26-mar-2019 Entry type: trustedCertEntry

Owner: CN=PEPPOL Root TEST CA - G2, OU=FOR TEST ONLY, O=OpenPEPPOL AISBL, C=BE Issuer: CN=PEPPOL Root TEST CA - G2, OU=FOR TEST ONLY, O=OpenPEPPOL AISBL, C=BE Serial number: 5c17f63f1afb4f75f5edca0e5a102565 Valid from: Thu Jan 04 01:00:00 CET 2018 until: Tue Jan 04 00:59:59 CET 2028 Certificate fingerprints: MD5: 1F:0C:10:BA:E3:A5:9D:D4:8C:9D:D6:24:C5:1F:AF:56 SHA1: BD:77:A1:1E:2B:21:9D:61:96:8A:EA:7B:BD:B1:99:33:F4:E8:97:09 SHA256: E4:B8:64:27:57:A0:2D:DD:4F:88:7C:B3:A2:C6:99:79:26:17:68:5E:AD:0B:E4:2D:E0:C2:1E:F5:90:CD:FF:AD Signature algorithm name: SHA256withRSA Version: 3

Extensions: .......

oxalis.log oxalis-standalone 4.0.4

2019-03-26 22:39:00,345 INFO [no.difi.oxalis.commons.security.CertificateModule] [] Certificate subject: C=IT, O="Infocamere ", OU=PEPPOL TEST AP, CN=PIT000252 2019-03-26 22:39:00,345 INFO [no.difi.oxalis.commons.security.CertificateModule] [] Certificate issuer: CN=PEPPOL ACCESS POINT TEST CA - G2, OU=FOR TEST ONLY, O=OpenPEPPOL AISBL, C=BE 2019-03-26 22:39:00,366 INFO [no.difi.oxalis.commons.mode.ModeProvider] [] Detected mode: test 2019-03-26 22:39:00,372 INFO [no.difi.oxalis.outbound.transmission.MessageSenderFactory] [] Prioritized list of transport profiles: 2019-03-26 22:39:00,373 INFO [no.difi.oxalis.outbound.transmission.MessageSenderFactory] [] => bdxr-transport-ebms3-as4-v1p0 2019-03-26 22:39:00,373 INFO [no.difi.oxalis.outbound.transmission.MessageSenderFactory] [] => busdox-transport-as2-ver1p0r1 2019-03-26 22:39:00,373 INFO [no.difi.oxalis.outbound.transmission.MessageSenderFactory] [] => busdox-transport-as2-ver1p0 2019-03-26 22:39:00,373 INFO [no.difi.oxalis.outbound.transmission.MessageSenderFactory] [] => peppol-transport-as4-v2_0 2019-03-26 22:39:00,834 WARN [no.difi.oxalis.sniffer.document.NoSbdhParser] [] You have enabled support for automatic detection of content. This functionality will be turned of by default in version 4.1 and removed in version 4.2/5.0. Use configuration "oxalis.transformer.detector = noop" to disable it today. 2019-03-26 22:39:01,454 DEBUG [org.apache.http.client.protocol.RequestAddCookies] [] CookieSpec selected: default 2019-03-26 22:39:01,463 DEBUG [org.apache.http.client.protocol.RequestAuthCache] [] Auth cache not set in the context 2019-03-26 22:39:01,464 DEBUG [org.apache.http.impl.conn.PoolingHttpClientConnectionManager] [] Connection request: [route: {}->http://test-smp.peppol.gr:80][total kept alive: 0; route allocated: 0 of 2; total allocated: 0 of 20] 2019-03-26 22:39:01,476 DEBUG [org.apache.http.impl.conn.PoolingHttpClientConnectionManager] [] Connection leased: [id: 0][route: {}->http://test-smp.peppol.gr:80][total kept alive: 0; route allocated: 1 of 2; total allocated: 1 of 20] 2019-03-26 22:39:01,478 DEBUG [org.apache.http.impl.execchain.MainClientExec] [] Opening connection {}->http://test-smp.peppol.gr:80 2019-03-26 22:39:01,484 DEBUG [org.apache.http.impl.conn.DefaultHttpClientConnectionOperator] [] Connecting to test-smp.peppol.gr/83.212.238.183:80 2019-03-26 22:39:01,563 DEBUG [org.apache.http.impl.conn.DefaultHttpClientConnectionOperator] [] Connection established 10.5.30.177:49174<->83.212.238.183:80 2019-03-26 22:39:01,564 DEBUG [org.apache.http.impl.conn.DefaultManagedHttpClientConnection] [] http-outgoing-0: set socket timeout to 0 2019-03-26 22:39:01,564 DEBUG [org.apache.http.impl.execchain.MainClientExec] [] Executing request GET /iso6523-actorid-upis::0088:tbcntrl00002/services/busdox-docid-qns::urn:oasis:names:specification:ubl:schema:xsd:Invoice-2::Invoice%23%23urn:www.cenbii.eu:transaction:biitrns010:ver2.0:extended:urn:www.peppol.eu:bis:peppol5a:ver2.0::2.1 HTTP/1.1 2019-03-26 22:39:01,564 DEBUG [org.apache.http.impl.execchain.MainClientExec] [] Target auth state: UNCHALLENGED 2019-03-26 22:39:01,564 DEBUG [org.apache.http.impl.execchain.MainClientExec] [] Proxy auth state: UNCHALLENGED 2019-03-26 22:39:01,566 DEBUG [org.apache.http.headers] [] http-outgoing-0 >> GET /iso6523-actorid-upis::0088:tbcntrl00002/services/busdox-docid-qns::urn:oasis:names:specification:ubl:schema:xsd:Invoice-2::Invoice%23%23urn:www.cenbii.eu:transaction:biitrns010:ver2.0:extended:urn:www.peppol.eu:bis:peppol5a:ver2.0::2.1 HTTP/1.1 2019-03-26 22:39:01,566 DEBUG [org.apache.http.headers] [] http-outgoing-0 >> Host: test-smp.peppol.gr 2019-03-26 22:39:01,566 DEBUG [org.apache.http.headers] [] http-outgoing-0 >> Connection: Keep-Alive 2019-03-26 22:39:01,566 DEBUG [org.apache.http.headers] [] http-outgoing-0 >> User-Agent: Oxalis 4.0.4 2019-03-26 22:39:01,566 DEBUG [org.apache.http.headers] [] http-outgoing-0 >> Accept-Encoding: gzip,deflate 2019-03-26 22:39:01,566 DEBUG [org.apache.http.wire] [] http-outgoing-0 >> "GET /iso6523-actorid-upis::0088:tbcntrl00002/services/busdox-docid-qns::urn:oasis:names:specification:ubl:schema:xsd:Invoice-2::Invoice%23%23urn:www.cenbii.eu:transaction:biitrns010:ver2.0:extended:urn:www.peppol.eu:bis:peppol5a:ver2.0::2.1 HTTP/1.1[\r][\n]" 2019-03-26 22:39:01,567 DEBUG [org.apache.http.wire] [] http-outgoing-0 >> "Host: test-smp.peppol.gr[\r][\n]" 2019-03-26 22:39:01,567 DEBUG [org.apache.http.wire] [] http-outgoing-0 >> "Connection: Keep-Alive[\r][\n]" 2019-03-26 22:39:01,567 DEBUG [org.apache.http.wire] [] http-outgoing-0 >> "User-Agent: Oxalis 4.0.4[\r][\n]" 2019-03-26 22:39:01,567 DEBUG [org.apache.http.wire] [] http-outgoing-0 >> "Accept-Encoding: gzip,deflate[\r][\n]" 2019-03-26 22:39:01,567 DEBUG [org.apache.http.wire] [] http-outgoing-0 >> "[\r][\n]" 2019-03-26 22:39:01,654 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "HTTP/1.1 200 OK[\r][\n]" 2019-03-26 22:39:01,654 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "Date: Tue, 26 Mar 2019 21:39:01 GMT[\r][\n]" 2019-03-26 22:39:01,654 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "Server: Apache[\r][\n]" 2019-03-26 22:39:01,654 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "Content-Type: text/xml;charset=UTF-8[\r][\n]" 2019-03-26 22:39:01,654 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "Content-Length: 6767[\r][\n]" 2019-03-26 22:39:01,655 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "Keep-Alive: timeout=5, max=100[\r][\n]" 2019-03-26 22:39:01,655 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "Connection: Keep-Alive[\r][\n]" 2019-03-26 22:39:01,655 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "[\r][\n]" 2019-03-26 22:39:01,655 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "<?xml version="1.0" encoding="UTF-8" standalone="no"?>0088:tbcntrl00002</ns2:ParticipantIdentifier>urn:oasis:names:specification:ubl:schema:xsd:Invoice-2::Invoice##urn:www.cenbii.eu:transaction:biitrns010:ver2.0:extended:urn:www.peppol.eu:bis:peppol5a:ver2.0::2.1</ns2:DocumentIdentifier>urn:www.cenbii.eu:profile:bii05:ver2.0</ns2:ProcessIdentifier>https://test-vefa.difi.no/tbap/as4</ns3:Address></ns3:EndpointReference>false2018-11-20T00:00:00.0002019-11-18T00:00:00.000MIIF2zCCA8OgAwIBAgIQd0IPLbDqS5WFxrVva8V/xDANBgkqhkiG9w0BAQsFADBr [\n]" 2019-03-26 22:39:01,655 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "MQswCQYDVQQGEwJCRTEZMBcGA1UEChMQT3BlblBFUFBPTCBBSVNCTDEWMBQGA1UE [\n]" 2019-03-26 22:39:01,655 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "CxMNRk9SIFRFU1QgT05MWTEpMCcGA1UEAxMgUEVQUE9MIEFDQ0VTUyBQT0lOVCBU [\n]" 2019-03-26 22:39:01,655 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "RVNUIENBIC0gRzIwHhcNMTgwNTI4MDAwMDAwWhcNMjAwNTE3MjM1OTU5WjBoMRIw [\n]" 2019-03-26 22:39:01,655 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "EAYDVQQDDAlQTk8wMDAwMDExFzAVBgNVBAsMDlBFUFBPTCBURVNUIEFQMSwwKgYD [\n]" 2019-03-26 22:39:01,655 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "VQQKDCNEaXJla3RvcmF0ZXQgZm9yIGZvcnZhbHRuaW5nIG9nIElLVDELMAkGA1UE [\n]" 2019-03-26 22:39:01,655 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "BhMCTk8wggEiMA0GCSqGSIb3DQEBAQUAA4IBDwAwggEKAoIBAQDAU7N4M2KSEOSI [\n]" 2019-03-26 22:39:01,656 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "qO2g8X93tLZvSvvP48yirWnCD8SVTU53EpD88YSjmhH9zdzUzlRIGC+AUJKxcynk [\n]" 2019-03-26 22:39:01,656 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "i6lHP0FERFN4NZcdLpOgyJsm+8OeyxfRoflHcMGs9HSK2MwBtyJkoqgjt9qMfjLK [\n]" 2019-03-26 22:39:01,656 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "8Wgb08Q/omln946OXKIvdmVKNGOg4cAFTSGinGWr6NFIc3G4v+H8VSBJmRk9btJD [\n]" 2019-03-26 22:39:01,656 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "fc7hofm9+KdOCYZ00pMHQj0q2SLGkzArXsTKtTrSQh7oSzmAjDs3/Nx2fmBjijs3 [\n]" 2019-03-26 22:39:01,656 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "PR2g46CrRZ9JexCuEynSQLgqM8gPnBnIUgVr0jxmXaFqIju1znAkx1GoZVQB2RG1 [\n]" 2019-03-26 22:39:01,656 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "yy7ckTafAgMBAAGjggF8MIIBeDAMBgNVHRMBAf8EAjAAMA4GA1UdDwEB/wQEAwID [\n]" 2019-03-26 22:39:01,656 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "qDAWBgNVHSUBAf8EDDAKBggrBgEFBQcDAjAdBgNVHQ4EFgQURcn+oSKJXJw8vGyi [\n]" 2019-03-26 22:39:01,656 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "RHTKo57Ddk8wXQYDVR0fBFYwVDBSoFCgToZMaHR0cDovL3BraS1jcmwuc3ltYXV0 [\n]" 2019-03-26 22:39:01,656 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "aC5jb20vY2FfNmE5Mzc3MzRhMzkzYTA4MDViZjMzY2RhOGIzMzEwOTMvTGF0ZXN0 [\n]" 2019-03-26 22:39:01,656 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "Q1JMLmNybDA3BggrBgEFBQcBAQQrMCkwJwYIKwYBBQUHMAGGG2h0dHA6Ly9wa2kt [\n]" 2019-03-26 22:39:01,656 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "b2NzcC5zeW1hdXRoLmNvbTAfBgNVHSMEGDAWgBRrb0u28Te6Kzx/GM26K7K5fCo3 [\n]" 2019-03-26 22:39:01,656 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "6zAtBgpghkgBhvhFARADBB8wHQYTYIZIAYb4RQEQAQIDAQGBqZDhAxYGOTU3NjA4 [\n]" 2019-03-26 22:39:01,657 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "MDkGCmCGSAGG+EUBEAUEKzApAgEAFiRhSFIwY0hNNkx5OXdhMmt0Y21FdWMzbHRZ [\n]" 2019-03-26 22:39:01,657 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "WFYwYUM1amIyMD0wDQYJKoZIhvcNAQELBQADggIBAKFSrKZe2u1+dz+jnmq6dNX8 [\n]" 2019-03-26 22:39:01,657 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "FXFRntkGeh0Tg0xTLPmJk+kargJa54QnS3iek1QkXH2MtYp+RKuNMEVRTxITNphN [\n]" 2019-03-26 22:39:01,657 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "vkWPEzBvSm/XmUeiEkpqGVqVjG45KWTKsxDw77qkK3mc84JZhE0wLD/x1LjAulX6 [\n]" 2019-03-26 22:39:01,657 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "iGE94DKGuOH7vGeQk1+st2oAEHcq0gTYoMqOmaDsw4Y/Y2ruYy6+U8yiAxqLRULA [\n]" 2019-03-26 22:39:01,657 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "HA/Q5RrXWoeYtlg0B9vYrR928lt7/UBbsgnLeSinosbBRrGzKKugwBqbhoiCRP8W [\n]" 2019-03-26 22:39:01,658 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "tI61WJ1oHXL7yxMN+eiNhgF9Q2nGFxPZ/bIYIeB9EFHkV+YUrfMNhtFgDAmBt/AZ [\n]" 2019-03-26 22:39:01,658 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "SQvZnMtqJCl40Qb5b247xc95eUr2tA8yyl9nFNY2vChSSBufpIbkNbfREQ4/5K2c [\n]" 2019-03-26 22:39:01,658 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "t3txxXw5GbsB1kqBsKeIIu+ctp276D2h7lY4+IVh5C3VeMe5DXfTUpd570YNKfWc [\n]" 2019-03-26 22:39:01,658 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "8A9077DL7g8pH6bPWz90dHI3g2n+h79rKg0woRUM1w1SWBaZvaioI6fSwxnvlK7x [\n]" 2019-03-26 22:39:01,658 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "3ptYCSVeHy38Ilu454zYqquNTAYjgqeXCcTLHbFznLo9wWzedzD0CUdRJ++VOPQ1 [\n]" 2019-03-26 22:39:01,658 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "mmDWPFNR6CM2YWCTjcWOCd5bpyMHt1GTGzKx8petINtkeT6xE0tGYweFG93CwAen [\n]" 2019-03-26 22:39:01,658 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "bQdMYq3OLMWAzrhe0XJLOpenPEPPOL Testbed AS4Jerry Dimitriou<Reference " 2019-03-26 22:39:01,660 DEBUG [org.apache.http.headers] [] http-outgoing-0 << HTTP/1.1 200 OK 2019-03-26 22:39:01,661 DEBUG [org.apache.http.headers] [] http-outgoing-0 << Date: Tue, 26 Mar 2019 21:39:01 GMT 2019-03-26 22:39:01,661 DEBUG [org.apache.http.headers] [] http-outgoing-0 << Server: Apache 2019-03-26 22:39:01,661 DEBUG [org.apache.http.headers] [] http-outgoing-0 << Content-Type: text/xml;charset=UTF-8 2019-03-26 22:39:01,661 DEBUG [org.apache.http.headers] [] http-outgoing-0 << Content-Length: 6767 2019-03-26 22:39:01,661 DEBUG [org.apache.http.headers] [] http-outgoing-0 << Keep-Alive: timeout=5, max=100 2019-03-26 22:39:01,661 DEBUG [org.apache.http.headers] [] http-outgoing-0 << Connection: Keep-Alive 2019-03-26 22:39:01,666 DEBUG [org.apache.http.impl.execchain.MainClientExec] [] Connection can be kept alive for 5000 MILLISECONDS 2019-03-26 22:39:01,669 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "URI="">86pFT04nf0vf+h/qjDD0xGWtc3U=Hf7d8Mo0IpKO1r0FNCo/0ecGhV3VpC6UdmzQcTXqmvwbFg+jUqbqx7uFRCud43omZaRxEdbFcvJG[\n]" 2019-03-26 22:39:01,669 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "3XJ6VFH4lKZWwJSCKOp5JGyCnarAoMlpYo9oCBpPVtMaMWr4a5LQza5zMACL+V1NCA6lNM++FN+W[\n]" 2019-03-26 22:39:01,669 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "X0zRYYGvtFgFi5De0bI+r65nEdumo0BD2qr+J3CQmdfj+6Vx1fn5Suhk/+GIz0bbWHK/5+LutVZq[\n]" 2019-03-26 22:39:01,669 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "dYQtIoiR+VshyDOYrQDtwpcj72isD0+JYmeNrW5IerYLDULf2AGMjhXY4Wg6+jaMIABenobT7e2Q[\n]" 2019-03-26 22:39:01,670 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "cO8AT35yh/tsLLUwChoYPppyKR5jE6CjdUSRDA==C=GR,O=UPRC Greece,OU=PEPPOL TEST SMP,CN=PDK000207MIIF0jCCA7qgAwIBAgIQOhSivMvvWW2x7NOsjobtSTANBgkqhkiG9w0BAQsFADB5MQswCQYDVQQG[\n]" 2019-03-26 22:39:01,670 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "EwJCRTEZMBcGA1UEChMQT3BlblBFUFBPTCBBSVNCTDEWMBQGA1UECxMNRk9SIFRFU1QgT05MWTE3[\n]" 2019-03-26 22:39:01,670 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "MDUGA1UEAxMuUEVQUE9MIFNFUlZJQ0UgTUVUQURBVEEgUFVCTElTSEVSIFRFU1QgQ0EgLSBHMjAe[\n]" 2019-03-26 22:39:01,670 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "Fw0xODExMjYwMDAwMDBaFw0yMDExMTUyMzU5NTlaMFExEjAQBgNVBAMMCVBESzAwMDIwNzEYMBYG[\n]" 2019-03-26 22:39:01,670 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "A1UECwwPUEVQUE9MIFRFU1QgU01QMRQwEgYDVQQKDAtVUFJDIEdyZWVjZTELMAkGA1UEBhMCR1Iw[\n]" 2019-03-26 22:39:01,670 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "ggEiMA0GCSqGSIb3DQEBAQUAA4IBDwAwggEKAoIBAQCj5jx7Dn195bs40yyZZuPK+OTxaAIdoGOJ[\n]" 2019-03-26 22:39:01,670 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "CRFfZaAEPl6tvarOnAeM8vLq1KYeak9g8bmSB9CDLAbVwuSLRCGmrSTIbzrZbVt19cxJRh4ExB81[\n]" 2019-03-26 22:39:01,670 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "xGjbIjN6DqBRg3DzaSkc9D8SIAevfu34zx6rvWCjF3LaoskOZ6Nsq4/XY3BXxcHL+p6/OFB4GghP[\n]" 2019-03-26 22:39:01,670 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "gUyos9Qi8bRC90QTt7alPPo3XrH1+2hRliUgr6rjbUVtzpv3YPTE4NTdoCQcI90i7D7F4TcXPmUW[\n]" 2019-03-26 22:39:01,670 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "cbYiJvlXHZfbszOldpyj45V5towkL/tTxgo9FlH/KXBJj2/i/9hbkhsiYhlB01A6BTN4gPDVipj1[\n]" 2019-03-26 22:39:01,670 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "pyYvAgMBAAGjggF8MIIBeDAMBgNVHRMBAf8EAjAAMA4GA1UdDwEB/wQEAwIDqDAWBgNVHSUBAf8E[\n]" 2019-03-26 22:39:01,670 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "DDAKBggrBgEFBQcDAjAdBgNVHQ4EFgQUSUTU8YzXBcQLHKLa1OMfL5Iv2D4wXQYDVR0fBFYwVDBS[\n]" 2019-03-26 22:39:01,670 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "oFCgToZMaHR0cDovL3BraS1jcmwuc3ltYXV0aC5jb20vY2FfYjZkMGRjMWRjMzE0NzcyM2ZlMzZi[\n]" 2019-03-26 22:39:01,670 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "NzU3NTk5N2FmYzQvTGF0ZXN0Q1JMLmNybDA3BggrBgEFBQcBAQQrMCkwJwYIKwYBBQUHMAGGG2h0[\n]" 2019-03-26 22:39:01,670 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "dHA6Ly9wa2ktb2NzcC5zeW1hdXRoLmNvbTAfBgNVHSMEGDAWgBR8HbJI8brZCgbKFmOp8HpPvSOd[\n]" 2019-03-26 22:39:01,670 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "ezAtBgpghkgBhvhFARADBB8wHQYTYIZIAYb4RQEQAQIDAQGBqNWBChYGOTU3NjA4MDkGCmCGSAGG[\n]" 2019-03-26 22:39:01,670 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "+EUBEAUEKzApAgEAFiRhSFIwY0hNNkx5OXdhMmt0Y21FdWMzbHRZWFYwYUM1amIyMD0wDQYJKoZI[\n]" 2019-03-26 22:39:01,670 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "hvcNAQELBQADggIBAKD6wIj30nAiQbZ+YWYGicN1X6+6WRP9CTAqySXoCQxB6Rt6/ZjBppzudxdA[\n]" 2019-03-26 22:39:01,670 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "yISGblNctC1iXR+WCzYynL6vNG1bPdURGIrxEHqdNU2DlrDQ3runNkJLsKdIrLg97tdYrfoSovs4[\n]" 2019-03-26 22:39:01,670 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "0sS+UuhpWS1a/pavCD5DeXil9ri5ZYEA7l+K/YTTUqVGAQOTVOoP3/l+zMycs7l4SdKKh15OKawq[\n]" 2019-03-26 22:39:01,671 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "RlHBFGorVFOi5oyb2b67bbHxRAJkOFJ7TzwPJgbJ/Pmv6+MkAj7TprvGBzk1GAcVsIJjTXBhblug[\n]" 2019-03-26 22:39:01,671 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "wZzr8vujhqztqiG9q3g4opsxP34ShZA7pxN3PPjolYbWJcr84m1jVnyYB27Q0BxcY51HVnY6Ew50[\n]" 2019-03-26 22:39:01,671 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "YxUY4bX59E93R6wb4iYfGGdg53AMLROO+RZKJtvxHQHE6bcBc4OorEdgUYOLm8zjUhe/FKhGubBj[\n]" 2019-03-26 22:39:01,671 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "MkRgHnNDUdN9NiIh1m9RIp+u4cvO8dqVpS9iB13F/P/eWyputwSLgsoO/ukDf6mwwu9qD9anWYus[\n]" 2019-03-26 22:39:01,671 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "/YihQFpd/joSXJRm4hqBlRpphtC8CV2QcLY2c/Yy9hzBhkGEnVYIiU32kNc5Kyhjyl/YlFXjU+6c[\n]" 2019-03-26 22:39:01,671 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "pYmiCRU14PcUh3dssfVJr9j6OQJM8N1rHnnN+ifi1ArUMoS7iKw+maH5m8d5Jt5id4lJgqZ/p4oH[\n]" 2019-03-26 22:39:01,671 DEBUG [org.apache.http.wire] [] http-outgoing-0 << "GNNvo1NxzbqsRGtx" 2019-03-26 22:39:01,671 DEBUG [org.apache.http.impl.conn.PoolingHttpClientConnectionManager] [] Connection [id: 0][route: {}->http://test-smp.peppol.gr:80] can be kept alive for 5.0 seconds 2019-03-26 22:39:01,671 DEBUG [org.apache.http.impl.conn.DefaultManagedHttpClientConnection] [] http-outgoing-0: set socket timeout to 0 2019-03-26 22:39:01,672 DEBUG [org.apache.http.impl.conn.PoolingHttpClientConnectionManager] [] Connection released: [id: 0][route: {}->http://test-smp.peppol.gr:80][total kept alive: 1; route allocated: 1 of 2; total allocated: 1 of 20] 2019-03-26 22:39:01,809 INFO [org.springframework.oxm.jaxb.Jaxb2Marshaller] [] Creating JAXBContext with context path [no.difi.commons.sbdh.jaxb:org.xmlsoap.schemas.soap.envelope:org.w3.soap:org.w3.xmldsig:org.oasis_open.docs.ebxml_bp.ebbp_signals_2:org.oasis_open.docs.ebxml_msg.ebms.v3_0.ns.core._200704] 2019-03-26 22:39:02,369 DEBUG [no.difi.oxalis.as4.outbound.As4WebServiceTemplate] [] Opening [org.springframework.ws.transport.http.HttpComponentsConnection@49052d39] to [https://test-vefa.difi.no/tbap/as4] 2019-03-26 22:39:02,553 DEBUG [no.difi.oxalis.as4.outbound.WsSecurityInterceptor] [] Securing message [SaajSoapMessage] with actions [Signature Encrypt] 2019-03-26 22:39:02,621 DEBUG [org.apache.xml.security.utils.resolver.ResourceResolver] [] Registered resolver: org.apache.wss4j.dom.resolvers.ResolverAttachment@198cdb8f 2019-03-26 22:39:02,623 DEBUG [org.apache.wss4j.common.crypto.WSProviderConfig] [] The provider STRTransform was added at position: 11 2019-03-26 22:39:02,623 DEBUG [org.apache.wss4j.common.crypto.WSProviderConfig] [] The provider AttachmentContentSignatureTransform was added at position: 12 2019-03-26 22:39:02,624 DEBUG [org.apache.wss4j.common.crypto.WSProviderConfig] [] The provider AttachmentCompleteSignatureTransform was added at position: 13 2019-03-26 22:39:02,629 DEBUG [org.apache.xml.security.Init] [] Registering default algorithms 2019-03-26 22:39:02,661 DEBUG [org.apache.wss4j.common.crypto.WSProviderConfig] [] The provider ApacheXMLDSig - 2.11 was added at position: 2 2019-03-26 22:39:02,680 DEBUG [org.apache.wss4j.dom.handler.WSHandler] [] partDefs: 'Content' ,'http://www.w3.org/2003/05/soap-envelope' ,'Body' 2019-03-26 22:39:02,680 DEBUG [org.apache.wss4j.dom.handler.WSHandler] [] partDefs: 'Content' ,'http://docs.oasis-open.org/ebxml-msg/ebms/v3.0/ns/core/200704/' ,'Messaging' 2019-03-26 22:39:02,681 DEBUG [org.apache.wss4j.dom.action.SignatureConfirmationAction] [] Perform Signature confirmation 2019-03-26 22:39:02,681 DEBUG [org.apache.wss4j.dom.handler.WSHandler] [] Performing Action: 2 2019-03-26 22:39:02,723 DEBUG [org.apache.jcp.xml.dsig.internal.dom.DOMReference] [] Marshalling Reference 2019-03-26 22:39:02,723 DEBUG [org.apache.jcp.xml.dsig.internal.dom.DOMReference] [] Adding digestValueElem 2019-03-26 22:39:02,723 DEBUG [org.apache.jcp.xml.dsig.internal.dom.DOMReference] [] Marshalling Reference 2019-03-26 22:39:02,724 DEBUG [org.apache.jcp.xml.dsig.internal.dom.DOMReference] [] Adding digestValueElem 2019-03-26 22:39:02,724 DEBUG [org.apache.jcp.xml.dsig.internal.dom.DOMReference] [] Marshalling Reference 2019-03-26 22:39:02,724 DEBUG [org.apache.jcp.xml.dsig.internal.dom.DOMReference] [] Adding digestValueElem 2019-03-26 22:39:02,728 DEBUG [org.apache.jcp.xml.dsig.internal.dom.DOMReference] [] URIDereferencer class name: org.apache.jcp.xml.dsig.internal.dom.DOMURIDereferencer 2019-03-26 22:39:02,728 DEBUG [org.apache.jcp.xml.dsig.internal.dom.DOMReference] [] Data class name: org.apache.jcp.xml.dsig.internal.dom.ApacheNodeSetData 2019-03-26 22:39:02,729 DEBUG [org.apache.xml.security.transforms.Transform] [] Create URI "http://www.w3.org/2001/10/xml-exc-c14n#" class "class org.apache.xml.security.transforms.implementations.TransformC14NExclusive" 2019-03-26 22:39:02,729 DEBUG [org.apache.xml.security.transforms.Transform] [] The NodeList is [ds:Transform: null] 2019-03-26 22:39:02,729 DEBUG [org.apache.xml.security.utils.ElementProxy] [] setElement(ds:Transform, "null") 2019-03-26 22:39:02,729 DEBUG [org.apache.jcp.xml.dsig.internal.dom.ApacheCanonicalizer] [] Created transform for algorithm: http://www.w3.org/2001/10/xml-exc-c14n# 2019-03-26 22:39:02,729 DEBUG [org.apache.jcp.xml.dsig.internal.dom.ApacheCanonicalizer] [] ApacheData = true 2019-03-26 22:39:02,734 DEBUG [org.apache.jcp.xml.dsig.internal.DigesterOutputStream] [] Pre-digested input: 2019-03-26 22:39:02,735 DEBUG [org.apache.jcp.xml.dsig.internal.DigesterOutputStream] [] </env:Body> 2019-03-26 22:39:02,736 DEBUG [org.apache.jcp.xml.dsig.internal.dom.DOMReference] [] Reference object uri = #id-1299896f-8c92-4ecb-8c58-2badfbfe2361 2019-03-26 22:39:02,736 DEBUG [org.apache.jcp.xml.dsig.internal.dom.DOMReference] [] Reference digesting completed 2019-03-26 22:39:02,736 DEBUG [org.apache.jcp.xml.dsig.internal.dom.DOMReference] [] URIDereferencer class name: org.apache.jcp.xml.dsig.internal.dom.DOMURIDereferencer 2019-03-26 22:39:02,736 DEBUG [org.apache.jcp.xml.dsig.internal.dom.DOMReference] [] Data class name: org.apache.jcp.xml.dsig.internal.dom.ApacheNodeSetData 2019-03-26 22:39:02,736 DEBUG [org.apache.xml.security.transforms.Transform] [] Create URI "http://www.w3.org/2001/10/xml-exc-c14n#" class "class org.apache.xml.security.transforms.implementations.TransformC14NExclusive" 2019-03-26 22:39:02,736 DEBUG [org.apache.xml.security.transforms.Transform] [] The NodeList is [ds:Transform: null] 2019-03-26 22:39:02,736 DEBUG [org.apache.xml.security.utils.ElementProxy] [] setElement(ds:Transform, "null") 2019-03-26 22:39:02,736 DEBUG [org.apache.jcp.xml.dsig.internal.dom.ApacheCanonicalizer] [] Created transform for algorithm: http://www.w3.org/2001/10/xml-exc-c14n# 2019-03-26 22:39:02,736 DEBUG [org.apache.jcp.xml.dsig.internal.dom.ApacheCanonicalizer] [] ApacheData = true 2019-03-26 22:39:02,737 DEBUG [org.apache.jcp.xml.dsig.internal.DigesterOutputStream] [] Pre-digested input: 2019-03-26 22:39:02,737 DEBUG [org.apache.jcp.xml.dsig.internal.DigesterOutputStream] [] eb:UserMessage><eb:MessageInfo><eb:Timestamp>2019-03-26T22:39:02.455+01:00</eb:Timestamp><eb:MessageId>65e27e0e-3901-4d53-8cb3-64f84f089399@vlcibatch001.intra.infocamere.it</eb:MessageId</eb:MessageInfo>PIT000252</eb:PartyId>http://docs.oasis-open.org/ebxml-msg/ebms/v3.0/ns/core/200704/initiator</eb:Role></eb:From>PNO000001</eb:PartyId>http://docs.oasis-open.org/ebxml-msg/ebms/v3.0/ns/core/200704/responder</eb:Role></eb:To></eb:PartyInfo>urn:fdc:peppol.eu:2017:agreements:tia:ap_provider</eb:AgreementRef>urn:www.cenbii.eu:profile:bii05:ver2.0/eb:Service><eb:Action>busdox-docid-qns::urn:oasis:names:specification:ubl:schema:xsd:Invoice-2::Invoice##urn:www.cenbii.eu:transaction:biitrns010:ver2.0:extended:urn:www.peppol.eu:bis:peppol5a:ver2.0::2.1</eb:Action><eb:ConversationId>afc4dc51-13a5-4524-b2de-becc18be0eff@vlcibatch001.intra.infocamere.it</eb:ConversationId</eb:CollaborationInfo>9921:ictest</eb:Property>0088:tbcntrl00002</eb:Property></eb:MessageProperties>application/gzip</eb:Property>application/xml</eb:Property></eb:PartProperties></eb:PartInfo></eb:PayloadInfo></eb:UserMessage></eb:Messaging> 2019-03-26 22:39:02,738 DEBUG [org.apache.jcp.xml.dsig.internal.dom.DOMReference] [] Reference object uri = #id-434fdf24-749e-4e6d-8225-12a30ce8a56e 2019-03-26 22:39:02,739 DEBUG [org.apache.jcp.xml.dsig.internal.dom.DOMReference] [] Reference digesting completed 2019-03-26 22:39:02,739 DEBUG [org.apache.xml.security.utils.resolver.ResourceResolver] [] check resolvability by class org.apache.xml.security.utils.resolver.ResourceResolver 2019-03-26 22:39:02,739 DEBUG [org.apache.jcp.xml.dsig.internal.dom.DOMReference] [] URIDereferencer class name: org.apache.jcp.xml.dsig.internal.dom.DOMURIDereferencer 2019-03-26 22:39:02,740 DEBUG [org.apache.jcp.xml.dsig.internal.dom.DOMReference] [] Data class name: org.apache.jcp.xml.dsig.internal.dom.ApacheOctetStreamData 2019-03-26 22:39:02,741 DEBUG [org.apache.jcp.xml.dsig.internal.DigesterOutputStream] [] Pre-digested input: 2019-03-26 22:39:02,741 DEBUG [org.apache.jcp.xml.dsig.internal.DigesterOutputStream] [] ￭Y[sﾛ8~￯ﾯ￨￫:\|Iￂ8t￬￮z￪\;}￨▒▒ￖ,ﾖﾨIﾼ﾿~ﾏﾸa￀8ﾝ￮￦a3i'B￧|￧￨ￜ￣O/ￛ@yB,ￂﾔ\ﾨￆﾉﾮ*ﾈxￔￇd}ﾡ￞ﾯ>￷ￎT%￢.￱￝ﾀtﾡﾪ~ﾲ?ﾌﾗ￉#￦_ￆ&(ﾊﾦￔﾋﾷﾈp￠Htﾡn8-M{~~>ﾉ ￲￐ ekￍCﾏﾮￇ5￢nQﾺﾊﾴ&ﾘ?ﾑ￫#ﾦￚﾥQTJ#Hﾀ(]|Kￏaￃ1ￆﾚ(%["R￰￀r￮~ￄﾈ)ﾓﾘo(ￃ|wﾡ￢ﾈﾎﾆf﾿ﾺￂ﾿ﾇ8R￭￳sￓﾰﾰￇQￄￇￚ+cﾬﾕﾑￇwpb￴FAﾺ~vfﾭ.ﾝ￫ￕ￝BﾇﾳNﾜ,aﾜￛ$'￴\^ﾺdB;fￄﾢnﾄ#+qﾂﾅ￈+￈ﾭ￸!ﾰ"oﾃﾶﾮ￵ￖﾜ<Q￬ﾡ(P￤ﾈﾫ]ﾈrￓﾚ'ￆX+?(NMD￤xﾨﾤ▒￭|%ﾎ44{F﾿g￪ￆﾹ￞7ￍﾕqjﾜ▒▒ﾲﾆﾲ@;ￓ(ﾕVl9 ￣hﾑﾮﾆnNn%▒mqﾍￖ￁$ﾷw7ￎlﾹ￬n@!ﾣﾏ8@￢00SﾬﾳNcmￏw￣ﾕ'ﾡ￉*kZoﾒﾷￄￊ▒￸QﾈD￳y￀￸ￅg.ﾉ ﾪ<￢ﾌDﾺﾡ[/￦ﾉnﾡ.ﾂￕﾷrￆﾅ! ﾱﾗﾴﾷIM￙-ￏ￵ﾎﾄp￨vK￉dﾽfh ﾴￗ￤ﾌﾨￂE1Tￚ~O￴ﾈ,￰ﾱtE�￢ￅTKﾑￖﾲ￮/YﾕﾚOￓￂﾵ￷Tfp￢ﾈￓ-▒ﾻ﾿6￙Ruﾪ2eﾍnￓ\ﾨￕﾥ>Od. ￒbﾧￂﾑ&ﾄpﾑC}ﾤ8￢￳)ﾌￗￎￂ￐uCﾵg9ﾄLZﾺﾦﾀ￭Pf￷ﾸ￲￬F td￷￰6￈W￸ﾆ￑xﾽQhￌﾔg￴aﾎR￐ﾄMFￊS￞ﾉﾃﾙg'￩5_￞ L￣Tﾵﾧ_ﾾu￤eDﾷ￐1L�ￗ=I*ￆKﾦ3￠7￰ﾺSￏ9#ﾾd￲ﾜ▒ﾪﾋￖﾢLﾢhn﾿Lw￨ﾉC5ﾉﾆX￞_.ﾝﾻ￡ﾩﾱﾵVMￊ|.Gﾶﾥh5J4ﾟxﾍﾡￚﾓ￵2ￃj▒-XmWﾧ P7￬UￍR ﾪ$E %￮_Y￳ￛﾉj￧ﾟL￘ﾆﾘKﾭￅ2;￐ﾡUﾶvﾴ￰Wuﾯ￝mﾍ￳kﾕLHﾗ￱C￤1 % Vuﾾ￝ﾽ￉ﾬ%ￅ;￩Rt2hﾞ￈￣ﾌ￬Alﾗp￸ﾛ▒^.fQVￍ﾿ﾲﾪ/ﾳ￐ﾾQﾝￒ￡ﾪﾭ￯Kﾫ4ﾾt<Eﾍ￯ﾏￅﾵjￋo▒ﾋ￞ￗﾠￆﾻﾗ￱1/ﾍi%￠▒ﾻ￫}ﾲK;_ﾩ￯?ￛ￷ﾔￓg￲ﾳmￏ￐￟qￓﾻﾾyMﾯS￁h(Y\￯ￄ }ﾅ￠zￚ0ﾫﾗI￶neﾃneﾃ,￳ﾪﾤ￭ﾈS￩v8,nﾇﾕ￭Vﾇﾳﾺￒ:J+ﾥX￪ﾂxcf0GﾷUL￩ q3uw =o�ￅ#=/Bﾟ1qﾉﾇ￁ﾮﾩﾍﾔ@ﾩ￦,nﾜ￉"￩\ﾦa￶ﾯ▒Zn<Z￉Qﾍ;ￒￒ￴Yﾼ￈r6.[7ﾙ%￝ﾜ_ﾄ$e6gqvﾷﾭ￮ￔ￳Wﾤￜ!7ﾪ$C￦￵ﾡjﾟg#r#ￏ12￬ￏ ￡￵ﾆ+^￲ﾰﾹ u+ ﾪx￙ￅ;3ﾾﾨPG￴=ﾋﾬﾔﾦ!4`r ￞ￖﾴ5+￷B￘c￘ￗ￁ￋ￭'ﾉQh ￠dￛf1ﾛﾭￛK�ﾱￓlￗ￑￱￠￈X￬['ﾫ4Mﾑﾙ￫ﾽﾢPￃￜￛMﾞ3ￍa￡ﾹﾂﾬ￙y0ﾟ￱zAUﾁ￮CﾀﾚﾄﾞﾗￂE"= ﾓ￧ﾨﾞ￧p0J ﾼ=(%ﾘﾣﾃﾳﾪ￶{ﾼ￧ﾴZ￳k/ﾀﾊﾭJ'gMﾮW0ﾖpﾗ￭ￚB|ﾁ ﾚﾉ7ﾼ￢￝qSﾐﾜﾕ￢ﾮﾆﾡ9{f/^G￸ﾩkDW￨ﾛﾁ￧￤ﾰa￈ﾁ]ah￭Pﾉﾽﾺﾔ￬=￲￦yﾠ-ﾭ%]%ￚﾪﾷￛￜZ+ﾜￔ"￴￐ ￐ ￄ▒ﾻ￉Vﾉ ￦ﾢg^ﾨￎ￈Tﾋ￥ﾢ￨ﾺ3gvﾇ<SW ￬ ￒQﾚ.q]"lﾜ￑eyￒ'ﾒ4￟ￅ￷￤d)▒l<l▒OpF\1# ﾞￜ,￶a;￝ﾳﾒ!<pﾣ(2ﾽmg:ﾮ￞vﾴk￶ ﾢ6ﾊￒiﾝ￡ﾺﾯ 2019-03-26 22:39:02,743 DEBUG [org.apache.jcp.xml.dsig.internal.dom.DOMReference] [] Reference object uri = cid:4e9f5f01-a892-4cc4-86ba-1f40aad26bf0@vlcibatch001.intra.infocamere.it 2019-03-26 22:39:02,743 DEBUG [org.apache.jcp.xml.dsig.internal.dom.DOMReference] [] Reference digesting completed 2019-03-26 22:39:02,744 DEBUG [org.apache.jcp.xml.dsig.internal.dom.DOMSignatureMethod] [] Signature provider: SunRsaSign version 1.8 2019-03-26 22:39:02,744 DEBUG [org.apache.jcp.xml.dsig.internal.dom.DOMSignatureMethod] [] Signing with key: sun.security.rsa.RSAPrivateCrtKeyImpl@fffab989 2019-03-26 22:39:02,744 DEBUG [org.apache.jcp.xml.dsig.internal.dom.DOMSignatureMethod] [] JCA Algorithm: SHA256withRSA 2019-03-26 22:39:02,744 DEBUG [org.apache.xml.security.transforms.Transform] [] Create URI "http://www.w3.org/2001/10/xml-exc-c14n#" class "class org.apache.xml.security.transforms.implementations.TransformC14NExclusive" 2019-03-26 22:39:02,744 DEBUG [org.apache.xml.security.transforms.Transform] [] The NodeList is [ds:CanonicalizationMethod: null] 2019-03-26 22:39:02,745 DEBUG [org.apache.xml.security.utils.ElementProxy] [] setElement(ds:CanonicalizationMethod, "null") 2019-03-26 22:39:02,745 DEBUG [org.apache.jcp.xml.dsig.internal.dom.ApacheCanonicalizer] [] Created transform for algorithm: http://www.w3.org/2001/10/xml-exc-c14n# 2019-03-26 22:39:02,745 DEBUG [org.apache.jcp.xml.dsig.internal.dom.ApacheCanonicalizer] [] isNodeSet() = true 2019-03-26 22:39:02,745 DEBUG [org.apache.xml.security.utils.ElementProxy] [] setElement("ec:InclusiveNamespaces", "null") 2019-03-26 22:39:02,746 DEBUG [org.apache.jcp.xml.dsig.internal.dom.DOMSignedInfo] [] Canonicalized SignedInfo: 2019-03-26 22:39:02,746 DEBUG [org.apache.jcp.xml.dsig.internal.dom.DOMSignedInfo] [] </ec:InclusiveNamespaces></ds:CanonicalizationMethod></ds:SignatureMethod></ds:Transform></ds:Transforms></ds:DigestMethod>c0RLxjVdw1i8X5fPYK/YTZqvWl72EKTU21jMvtqafk4=</ds:DigestValue></ds:Reference></ds:Transform></ds:Transforms></ds:DigestMethod>MPJEHxt3AhixJaHwW/pxGkfyuF+gMXLWiL1GQf/oc24=</ds:DigestValue></ds:Reference></ds:Transform></ds:Transforms></ds:DigestMethod>uiNUcUhJozvZosCuv0iuGiw+T/3Zj/x2vZm4DJBYPz8=</ds:DigestValue></ds:Reference></ds:SignedInfo> 2019-03-26 22:39:02,746 DEBUG [org.apache.jcp.xml.dsig.internal.dom.DOMSignedInfo] [] Data to be signed/verified:PGRzOlNpZ25lZEluZm8geG1sbnM6ZHM9Imh0dHA6Ly93d3cudzMub3JnLzIwMDAvMDkveG1sZHNp ZyMiIHhtbG5zOmVudj0iaHR0cDovL3d3dy53My5vcmcvMjAwMy8wNS9zb2FwLWVudmVsb3BlIj48 ZHM6Q2Fub25pY2FsaXphdGlvbk1ldGhvZCBBbGdvcml0aG09Imh0dHA6Ly93d3cudzMub3JnLzIw MDEvMTAveG1sLWV4Yy1jMTRuIyI+PGVjOkluY2x1c2l2ZU5hbWVzcGFjZXMgeG1sbnM6ZWM9Imh0 dHA6Ly93d3cudzMub3JnLzIwMDEvMTAveG1sLWV4Yy1jMTRuIyIgUHJlZml4TGlzdD0iZW52Ij48 L2VjOkluY2x1c2l2ZU5hbWVzcGFjZXM+PC9kczpDYW5vbmljYWxpemF0aW9uTWV0aG9kPjxkczpT aWduYXR1cmVNZXRob2QgQWxnb3JpdGhtPSJodHRwOi8vd3d3LnczLm9yZy8yMDAxLzA0L3htbGRz aWctbW9yZSNyc2Etc2hhMjU2Ij48L2RzOlNpZ25hdHVyZU1ldGhvZD48ZHM6UmVmZXJlbmNlIFVS ST0iI2lkLTEyOTk4OTZmLThjOTItNGVjYi04YzU4LTJiYWRmYmZlMjM2MSI+PGRzOlRyYW5zZm9y bXM+PGRzOlRyYW5zZm9ybSBBbGdvcml0aG09Imh0dHA6Ly93d3cudzMub3JnLzIwMDEvMTAveG1s LWV4Yy1jMTRuIyI+PC9kczpUcmFuc2Zvcm0+PC9kczpUcmFuc2Zvcm1zPjxkczpEaWdlc3RNZXRo b2QgQWxnb3JpdGhtPSJodHRwOi8vd3d3LnczLm9yZy8yMDAxLzA0L3htbGVuYyNzaGEyNTYiPjwv ZHM6RGlnZXN0TWV0aG9kPjxkczpEaWdlc3RWYWx1ZT5jMFJMeGpWZHcxaThYNWZQWUsvWVRacXZX bDcyRUtUVTIxak12dHFhZms0PTwvZHM6RGlnZXN0VmFsdWU+PC9kczpSZWZlcmVuY2U+PGRzOlJl ZmVyZW5jZSBVUkk9IiNpZC00MzRmZGYyNC03NDllLTRlNmQtODIyNS0xMmEzMGNlOGE1NmUiPjxk czpUcmFuc2Zvcm1zPjxkczpUcmFuc2Zvcm0gQWxnb3JpdGhtPSJodHRwOi8vd3d3LnczLm9yZy8y MDAxLzEwL3htbC1leGMtYzE0biMiPjwvZHM6VHJhbnNmb3JtPjwvZHM6VHJhbnNmb3Jtcz48ZHM6 RGlnZXN0TWV0aG9kIEFsZ29yaXRobT0iaHR0cDovL3d3dy53My5vcmcvMjAwMS8wNC94bWxlbmMj c2hhMjU2Ij48L2RzOkRpZ2VzdE1ldGhvZD48ZHM6RGlnZXN0VmFsdWU+TVBKRUh4dDNBaGl4SmFI d1cvcHhHa2Z5dUYrZ01YTFdpTDFHUWYvb2MyND08L2RzOkRpZ2VzdFZhbHVlPjwvZHM6UmVmZXJl bmNlPjxkczpSZWZlcmVuY2UgVVJJPSJjaWQ6NGU5ZjVmMDEtYTg5Mi00Y2M0LTg2YmEtMWY0MGFh ZDI2YmYwQHZsY2liYXRjaDAwMS5pbnRyYS5pbmZvY2FtZXJlLml0Ij48ZHM6VHJhbnNmb3Jtcz48 ZHM6VHJhbnNmb3JtIEFsZ29yaXRobT0iaHR0cDovL2RvY3Mub2FzaXMtb3Blbi5vcmcvd3NzL29h c2lzLXdzcy1Td0FQcm9maWxlLTEuMSNBdHRhY2htZW50LUNvbnRlbnQtU2lnbmF0dXJlLVRyYW5z Zm9ybSI+PC9kczpUcmFuc2Zvcm0+PC9kczpUcmFuc2Zvcm1zPjxkczpEaWdlc3RNZXRob2QgQWxn b3JpdGhtPSJodHRwOi8vd3d3LnczLm9yZy8yMDAxLzA0L3htbGVuYyNzaGEyNTYiPjwvZHM6RGln ZXN0TWV0aG9kPjxkczpEaWdlc3RWYWx1ZT51aU5VY1VoSm96dlpvc0N1djBpdUdpdytULzNaai94 MnZabTRESkJZUHo4PTwvZHM6RGlnZXN0VmFsdWU+PC9kczpSZWZlcmVuY2U+PC9kczpTaWduZWRJ bmZvPg== 2019-03-26 22:39:02,788 DEBUG [org.apache.wss4j.dom.handler.WSHandler] [] Performing Action: 4 2019-03-26 22:39:02,794 DEBUG [org.apache.xml.security.algorithms.JCEMapper] [] Request for URI http://www.w3.org/2009/xmlenc11#aes128-gcm 2019-03-26 22:39:02,810 DEBUG [org.apache.xml.security.algorithms.JCEMapper] [] Request for URI http://www.w3.org/2009/xmlenc11#rsa-oaep 2019-03-26 22:39:02,811 DEBUG [org.apache.xml.security.algorithms.JCEMapper] [] Request for URI http://www.w3.org/2001/04/xmlenc#sha256 2019-03-26 22:39:02,813 DEBUG [org.apache.wss4j.dom.message.WSSecEncryptedKey] [] cipher blksize: 0 2019-03-26 22:39:02,816 DEBUG [org.apache.wss4j.dom.message.WSSecEncrypt] [] Beginning Encryption... 2019-03-26 22:39:02,824 DEBUG [org.apache.xml.security.algorithms.JCEMapper] [] Request for URI http://www.w3.org/2009/xmlenc11#aes128-gcm 2019-03-26 22:39:02,835 DEBUG [org.apache.xml.security.encryption.XMLCipher] [] Have functional IdentityTransformer: false 2019-03-26 22:39:02,836 DEBUG [org.apache.xml.security.encryption.XMLCipher] [] Getting XMLCipher with transformation 2019-03-26 22:39:02,836 DEBUG [org.apache.xml.security.encryption.XMLCipher] [] Constructing XMLCipher... 2019-03-26 22:39:02,841 DEBUG [org.apache.xml.security.algorithms.JCEMapper] [] Request for URI http://www.w3.org/2009/xmlenc11#aes128-gcm 2019-03-26 22:39:02,841 DEBUG [org.apache.xml.security.encryption.XMLCipher] [] JCE Algorithm = AES/GCM/NoPadding 2019-03-26 22:39:02,842 DEBUG [org.apache.xml.security.algorithms.JCEMapper] [] Request for URI http://www.w3.org/2009/xmlenc11#aes128-gcm 2019-03-26 22:39:02,842 DEBUG [org.apache.xml.security.algorithms.JCEMapper] [] Request for URI http://www.w3.org/2009/xmlenc11#aes128-gcm 2019-03-26 22:39:02,855 DEBUG [org.apache.xml.security.encryption.XMLCipherUtil] [] Saw AES-GCM block cipher, attempting to create GCMParameterSpec: http://www.w3.org/2009/xmlenc11#aes128-gcm 2019-03-26 22:39:02,856 DEBUG [org.apache.xml.security.encryption.XMLCipherUtil] [] Successfully created GCMParameterSpec 2019-03-26 22:39:02,868 DEBUG [org.apache.wss4j.dom.message.WSSecEncrypt] [] Encryption complete. 2019-03-26 22:39:02,878 TRACE [org.springframework.ws.client.MessageTracing.sent] [] Sent request [------=_Part_1_2122349228.1553636342871 Content-Type: application/soap+xml; charset=utf-8

Rcn+oSKJXJw8vGyiRHTKo57Ddk8=NqOu6v3xhGcrJ5GpfCX5/XcddGA8sD5V4gCNBcmscVMekpIpzZrQ+5dIgwvGCVd0sPb21fakwjTB Mleh3jQKsBZAjz5sLPQpK5JNE5tQFzPmpahPX+hUFPuibBjtCEcxck55/Sn1uTABdVJmhtit5nBK 5cKogPliAy1Oaub2N9V/oIUsQSNsiqfhMwJwcJc+SThkUA1IBs5+fdb/P8Ivq+uWycGR/abA8UD8 AQXdYhlUCPWu87dIHD0IdEJkOq9AN12mFV/i42WMnEUmpWFdA1r0Dr0vsCWeNQoI13bQRUGWId+8 fRZ2Y3XAgEY2KPujqDToISwUcvS2M8bnSTlJQA==MIIFwzCCA6ugAwIBAgIQaVGTAxII7HUg/5QOnds9dTANBgkqhkiG9w0BAQsFADBrMQswCQYDVQQG EwJCRTEZMBcGA1UEChMQT3BlblBFUFBPTCBBSVNCTDEWMBQGA1UECxMNRk9SIFRFU1QgT05MWTEp MCcGA1UEAxMgUEVQUE9MIEFDQ0VTUyBQT0lOVCBURVNUIENBIC0gRzIwHhcNMTkwMTA5MDAwMDAw WhcNMjAxMjI5MjM1OTU5WjBQMRIwEAYDVQQDDAlQSVQwMDAyNTIxFzAVBgNVBAsMDlBFUFBPTCBU RVNUIEFQMRQwEgYDVQQKDAtJbmZvY2FtZXJlIDELMAkGA1UEBhMCSVQwggEiMA0GCSqGSIb3DQEB AQUAA4IBDwAwggEKAoIBAQCKlfdI6K45Hn2yj2OkeQOeH58ITKzGyHq64OM5WHeCFB+CP6nKU+/1 Lv+9Sxg2u8E0whpgEZjdYetnfm/meQwEPz8ZGK8VvV4dXGDjhF11muXANzLzv9jDXZYcCwQB4LQr QPFgnS5CiH1tL29qMUEBtyG9BR+mbMS74X/CJUQw95dBVDi8kNdlCy3wSJ4wfjV+VGu14comPKuz kckYSBF253cekQx0oFmCS3XiqQk9P+VwMwtabHRxguv/VP6iBw+Uby9IeS6dNfpcJ6tYfW86K+QE zMsJmXRzWQIFVJi5WIPvgOL6J135KMP9d2X7wvFudYaccZAI5rmCTPfQI8DfAgMBAAGjggF8MIIB eDAMBgNVHRMBAf8EAjAAMA4GA1UdDwEB/wQEAwIDqDAWBgNVHSUBAf8EDDAKBggrBgEFBQcDAjAd BgNVHQ4EFgQUMEiOA6/eZyMO3bo9wRYPwVIzRlMwXQYDVR0fBFYwVDBSoFCgToZMaHR0cDovL3Br aS1jcmwuc3ltYXV0aC5jb20vY2FfNmE5Mzc3MzRhMzkzYTA4MDViZjMzY2RhOGIzMzEwOTMvTGF0 ZXN0Q1JMLmNybDA3BggrBgEFBQcBAQQrMCkwJwYIKwYBBQUHMAGGG2h0dHA6Ly9wa2ktb2NzcC5z eW1hdXRoLmNvbTAfBgNVHSMEGDAWgBRrb0u28Te6Kzx/GM26K7K5fCo36zAtBgpghkgBhvhFARAD BB8wHQYTYIZIAYb4RQEQAQIDAQGBqZDhAxYGOTU3NjA4MDkGCmCGSAGG+EUBEAUEKzApAgEAFiRh SFIwY0hNNkx5OXdhMmt0Y21FdWMzbHRZWFYwYUM1amIyMD0wDQYJKoZIhvcNAQELBQADggIBACfw qxUJpdO8NmWQiwCnvnJ7DJSZgSLJBmCvPMWemzm+hmI0hxRC59MdQXN0ABRq/7NAsd00UGl27SYC N0jyVS0MvTtaFrvRif5DK9Wh8PZ/qPxyDS2hO3pthwOYNieo87oaS0BAhu5g5Rc7w+1FGusx2dH9 is0GnvlqNVWITG9vAIBkYS2P3iuGMsRRkp/0l0YgXH4DimnOSZhN6lIN/anxVW2mWhht503fLkoA okS/difsw5Md9sb3kcPHGMtbLS7ItMnT8apmzRMUkffKUJ5TwM9hdTgypceRwEI0wHqaVy/opvTZ 8taqgbW4Tk1xnC+EZRpaoFLkc4Of0EZsxyiN5NBzReE9LOx+dmqJH5raYGkcvIxznj2hLhJbrjwP qY98vflocPrf0UQ3Qptjx0/5PekWi59UKtconmDffH+tBHwvGsfkvKND1ammNkrIexF93udOg64f v0+7lmXoFOFcns03dl0yZrTVE++GPfrfu4eYwosU8+VTO4gLHeKlQ4iOo2+Daj/Hpvi5L8c6gW4b wOG93Y1z5n8aCMO9MydTtX0M2vbkzmtUWjmb+Tl/fLpw2FEA7dkfKYmyupCFLn+zxD6kazsml5Qi xK+S4wJB9z7cypMAsx9fEshjVIX150je0LCzFyWQD1bywHyc4PdmVmxmejWrjhtRnWfuQ1Onc0RLxjVdw1i8X5fPYK/YTZqvWl72EKTU21jMvtqafk4=MPJEHxt3AhixJaHwW/pxGkfyuF+gMXLWiL1GQf/oc24=uiNUcUhJozvZosCuv0iuGiw+T/3Zj/x2vZm4DJBYPz8=Dg74HTbOaEohZgiJ09Fx3szIB61Z+2D7WWQClyBE3AHIRi7oLQSAYJGST2ZdS7V38PvGop8+aU0W vJxHDxSvyoOygLL+W05K4MDGJe5CtfA0l4Pc10vRPZn3EV2awpLz3ockVrJYy+ji5HJKXSST0x92 WL3mDag+gUyiwwJ5C3HbzxuUhoCPGfbWdX3kqQpzvR1IzmHeCXfxyOVdt/CzT0EjiCBkeQcMihoW W+miHasEMkcFYOtcxfjwjnv+fy8AWHHOP+opUFfSk9vzkSnauPdkiBezwLe2g7KAzhhB5jTJVtEZ js+otF/GQm3Ju3mNFBNBWfPpc70BehOvFQNNFg==2019-03-26T22:39:02.455+01:0065e27e0e-3901-4d53-8cb3-64f84f089399@vlcibatch001.intra.infocamere.itPIT000252http://docs.oasis-open.org/ebxml-msg/ebms/v3.0/ns/core/200704/initiatorPNO000001http://docs.oasis-open.org/ebxml-msg/ebms/v3.0/ns/core/200704/responderurn:fdc:peppol.eu:2017:agreements:tia:ap_providerurn:www.cenbii.eu:profile:bii05:ver2.0busdox-docid-qns::urn:oasis:names:specification:ubl:schema:xsd:Invoice-2::Invoice##urn:www.cenbii.eu:transaction:biitrns010:ver2.0:extended:urn:www.peppol.eu:bis:peppol5a:ver2.0::2.1afc4dc51-13a5-4524-b2de-becc18be0eff@vlcibatch001.intra.infocamere.it9921:ictest0088:tbcntrl00002application/gzipapplication/xml ------=_Part_1_2122349228.1553636342871 Content-Type: application/octet-stream Content-ID: <4e9f5f01-a892-4cc4-86ba-1f40aad26bf0@vlcibatch001.intra.infocamere.it> Content-Transfer-Encoding: binary �4�NW�C����y�+@u[j���▒���QM��R��ly��� ^�� 6�#=�F87����W΢���P}8��qo[@����&���^q��܄��/��J����9�h,J���5�0E+��o=ݕ��{�!��#;�k�jn ������ŗ65-��GW�Z�ՔT�X�� �Nyvv޺2��V�O9�>w�C����KX8��w��h�.���[p������鍙k)�ǘm�h��xp�T����el]�j��ߩ�� ֵ"5VWj J��>\ >�DC�kwu[�O��AS��X7���kaL��z��iw���[7jwT�D��d���z���X �*�͓�-_$ O�K����{�������m84���'B�2�:�ur6�g>���,�aV�w��()Q-��VI�D<�8�+68s����6��-��S��P.�d�IS���Pau���`dCZ�O�P/�V��� �e���mp�ONkM�Gs �&.�v��_��x��-9�nCt6�*�5�#I;�'�u�B��<<Ƒ_�����P�z��C��d|�N��-�l��a���AQ����G�ՇêO�J�/���va��{W����v��&�]�Q��ݦ=�@b6�(ؒ}���PcVBJǁ�p�0�4N[�X����N�����F���dpN�ղe��T�d݁� x@����ps�~��f�����%����%�j2�Ҿ#n�!z�|L�uQxQ�dco��1κ��]>( ��N���Ȓ��K`"'x+.�%� ���`�w�cLR�JW(�����"�g"h�{�/ٺ���NW\�`�rv� f�xbx'�'.Mc ���b��u>�4�G���?�Z\���� `��$jF����l�����?��!҈� [�U�����m���9�#�L�L�6e��q��}�� ��Gt��z�>�).�kj�v�HԻ��3f6��d�#�=g;<�+��bL6�~��9������n�����'L���';�հ��<�h�ˈ��?�@v7y�ٲ�M!9�E�h?<���Qb�~�˛=o�v/��X��ȓ�â�;�ɬ���y۩����+L4�#7�T���]|.�X9$ػ_�[�}eסn&�-�S{&�r�B�O▒▒�w2�铲W9�K��,fE�-���������O�e�3�u�AZ�サ��/�)[�����Ռ��� iq`�ƛ:�lw���q7��*cY�o�Wh�o� hT2�U�)��v]@�sW� }��q~t!�{���d_D�_(��B`�▒▒ܾ��ZF�ÖIw�.���Z+x���҅B���A&�^��б�u�a���֘��`�9�Q}�(�os����}�e�1���ކ��|�ӮtŴ�ɻu�g�V Ѐ<�B&%�h���0�Q��BT�;y��+���f�M��[�U�]�>tO�o�v�זv�D��41&s�r�2uCL�ׯ�?����}�w����f�����]���Uq�mbD��AW)�\��ҘWg�9��Ee��/���վ6�׎�����H\�h%yh0y#4�1udl����,�ե �������;��U:�PS#���m� ���:Ybi��Ac�+��o�X���e���`�e�u�n]�_r g6�nM��.kڡ�8��/���Qء���}��L�,�Q�($���B���3������Ћ�GA���}�YY8�ߊ�˟��'�6���IK�:xN����W"{LsPQ� ------=_Part_1_2122349228.1553636342871--] 2019-03-26 22:39:02,896 DEBUG [org.apache.http.impl.conn.PoolingClientConnectionManager] [] Connection request: [route: {s}->https://test-vefa.difi.no:443][total kept alive: 0; route allocated: 0 of 2; total allocated: 0 of 20] 2019-03-26 22:39:02,900 DEBUG [org.apache.http.impl.conn.PoolingClientConnectionManager] [] Connection leased: [id: 0][route: {s}->https://test-vefa.difi.no:443][total kept alive: 0; route allocated: 1 of 2; total allocated: 1 of 20] 2019-03-26 22:39:02,903 DEBUG [org.apache.http.impl.conn.DefaultClientConnectionOperator] [] Connecting to test-vefa.difi.no:443 2019-03-26 22:39:03,238 DEBUG [org.apache.http.client.protocol.RequestAddCookies] [] CookieSpec selected: default 2019-03-26 22:39:03,239 DEBUG [org.apache.http.client.protocol.RequestAuthCache] [] Auth cache not set in the context 2019-03-26 22:39:03,239 DEBUG [org.apache.http.client.protocol.RequestTargetAuthentication] [] Target auth state: UNCHALLENGED 2019-03-26 22:39:03,240 DEBUG [org.apache.http.client.protocol.RequestProxyAuthentication] [] Proxy auth state: UNCHALLENGED 2019-03-26 22:39:03,240 DEBUG [org.apache.http.impl.client.DefaultHttpClient] [] Attempt 1 to execute request 2019-03-26 22:39:03,240 DEBUG [org.apache.http.impl.conn.DefaultClientConnection] [] Sending request: POST /tbap/as4 HTTP/1.1 2019-03-26 22:39:03,240 DEBUG [org.apache.http.wire] [] >> "POST /tbap/as4 HTTP/1.1[\r][\n]" 2019-03-26 22:39:03,240 DEBUG [org.apache.http.wire] [] >> "Accept-Encoding: gzip[\r][\n]" 2019-03-26 22:39:03,240 DEBUG [org.apache.http.wire] [] >> "Accept: application/soap+xml, text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2[\r][\n]" 2019-03-26 22:39:03,241 DEBUG [org.apache.http.wire] [] >> "Content-Type: multipart/related; boundary="----=_Part_2_1589326257.1553636342879"; type="application/soap+xml"[\r][\n]" 2019-03-26 22:39:03,241 DEBUG [org.apache.http.wire] [] >> "Content-Length: 10238[\r][\n]" 2019-03-26 22:39:03,241 DEBUG [org.apache.http.wire] [] >> "Host: test-vefa.difi.no[\r][\n]" 2019-03-26 22:39:03,241 DEBUG [org.apache.http.wire] [] >> "Connection: Keep-Alive[\r][\n]" 2019-03-26 22:39:03,241 DEBUG [org.apache.http.wire] [] >> "User-Agent: Apache-HttpClient/4.5.7 (Java/1.8.0_191)[\r][\n]" 2019-03-26 22:39:03,241 DEBUG [org.apache.http.wire] [] >> "[\r][\n]" 2019-03-26 22:39:03,241 DEBUG [org.apache.http.headers] [] >> POST /tbap/as4 HTTP/1.1 2019-03-26 22:39:03,241 DEBUG [org.apache.http.headers] [] >> Accept-Encoding: gzip 2019-03-26 22:39:03,241 DEBUG [org.apache.http.headers] [] >> Accept: application/soap+xml, text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2 2019-03-26 22:39:03,241 DEBUG [org.apache.http.headers] [] >> Content-Type: multipart/related; boundary="----=_Part_2_1589326257.1553636342879"; type="application/soap+xml" 2019-03-26 22:39:03,241 DEBUG [org.apache.http.headers] [] >> Content-Length: 10238 2019-03-26 22:39:03,241 DEBUG [org.apache.http.headers] [] >> Host: test-vefa.difi.no 2019-03-26 22:39:03,241 DEBUG [org.apache.http.headers] [] >> Connection: Keep-Alive 2019-03-26 22:39:03,241 DEBUG [org.apache.http.headers] [] >> User-Agent: Apache-HttpClient/4.5.7 (Java/1.8.0_191) 2019-03-26 22:39:03,245 DEBUG [org.apache.http.wire] [] >> "------=_Part_2_1589326257.1553636342879[\r][\n]" 2019-03-26 22:39:03,245 DEBUG [org.apache.http.wire] [] >> "Content-Type: application/soap+xml; charset=utf-8[\r][\n]" 2019-03-26 22:39:03,245 DEBUG [org.apache.http.wire] [] >> "[\r][\n]" 2019-03-26 22:39:03,245 DEBUG [org.apache.http.wire] [] >> "Rcn+oSKJXJw8vGyiRHTKo57Ddk8=NqOu6v3xhGcrJ5GpfCX5/XcddGA8sD5V4gCNBcmscVMekpIpzZrQ+5dIgwvGCVd0sPb21fakwjTB [\n]" 2019-03-26 22:39:03,245 DEBUG [org.apache.http.wire] [] >> "Mleh3jQKsBZAjz5sLPQpK5JNE5tQFzPmpahPX+hUFPuibBjtCEcxck55/Sn1uTABdVJmhtit5nBK [\n]" 2019-03-26 22:39:03,245 DEBUG [org.apache.http.wire] [] >> "5cKogPliAy1Oaub2N9V/oIUsQSNsiqfhMwJwcJc+SThkUA1IBs5+fdb/P8Ivq+uWycGR/abA8UD8 [\n]" 2019-03-26 22:39:03,245 DEBUG [org.apache.http.wire] [] >> "AQXdYhlUCPWu87dIHD0IdEJkOq9AN12mFV/i42WMnEUmpWFdA1r0Dr0vsCWeNQoI13bQRUGWId+8 [\n]" 2019-03-26 22:39:03,245 DEBUG [org.apache.http.wire] [] >> "fRZ2Y3XAgEY2KPujqDToISwUcvS2M8bnSTlJQA==MIIFwzCCA6ugAwIBAgIQaVGTAxII7HUg/5QOnds9dTANBgkqhkiG9w0BAQsFADBrMQswCQYDVQQG [\n]" 2019-03-26 22:39:03,245 DEBUG [org.apache.http.wire] [] >> "EwJCRTEZMBcGA1UEChMQT3BlblBFUFBPTCBBSVNCTDEWMBQGA1UECxMNRk9SIFRFU1QgT05MWTEp [\n]" 2019-03-26 22:39:03,245 DEBUG [org.apache.http.wire] [] >> "MCcGA1UEAxMgUEVQUE9MIEFDQ0VTUyBQT0lOVCBURVNUIENBIC0gRzIwHhcNMTkwMTA5MDAwMDAw [\n]" 2019-03-26 22:39:03,246 DEBUG [org.apache.http.wire] [] >> "WhcNMjAxMjI5MjM1OTU5WjBQMRIwEAYDVQQDDAlQSVQwMDAyNTIxFzAVBgNVBAsMDlBFUFBPTCBU [\n]" 2019-03-26 22:39:03,246 DEBUG [org.apache.http.wire] [] >> "RVNUIEFQMRQwEgYDVQQKDAtJbmZvY2FtZXJlIDELMAkGA1UEBhMCSVQwggEiMA0GCSqGSIb3DQEB [\n]" 2019-03-26 22:39:03,246 DEBUG [org.apache.http.wire] [] >> "AQUAA4IBDwAwggEKAoIBAQCKlfdI6K45Hn2yj2OkeQOeH58ITKzGyHq64OM5WHeCFB+CP6nKU+/1 [\n]" 2019-03-26 22:39:03,246 DEBUG [org.apache.http.wire] [] >> "Lv+9Sxg2u8E0whpgEZjdYetnfm/meQwEPz8ZGK8VvV4dXGDjhF11muXANzLzv9jDXZYcCwQB4LQr [\n]" 2019-03-26 22:39:03,246 DEBUG [org.apache.http.wire] [] >> "QPFgnS5CiH1tL29qMUEBtyG9BR+mbMS74X/CJUQw95dBVDi8kNdlCy3wSJ4wfjV+VGu14comPKuz [\n]" 2019-03-26 22:39:03,246 DEBUG [org.apache.http.wire] [] >> "kckYSBF253cekQx0oFmCS3XiqQk9P+VwMwtabHRxguv/VP6iBw+Uby9IeS6dNfpcJ6tYfW86K+QE [\n]" 2019-03-26 22:39:03,246 DEBUG [org.apache.http.wire] [] >> "zMsJmXRzWQIFVJi5WIPvgOL6J135KMP9d2X7wvFudYaccZAI5rmCTPfQI8DfAgMBAAGjggF8MIIB [\n]" 2019-03-26 22:39:03,246 DEBUG [org.apache.http.wire] [] >> "eDAMBgNVHRMBAf8EAjAAMA4GA1UdDwEB/wQEAwIDqDAWBgNVHSUBAf8EDDAKBggrBgEFBQcDAjAd [\n]" 2019-03-26 22:39:03,246 DEBUG [org.apache.http.wire] [] >> "BgNVHQ4EFgQUMEiOA6/eZyMO3bo9wRYPwVIzRlMwXQYDVR0fBFYwVDBSoFCgToZMaHR0cDovL3Br [\n]" 2019-03-26 22:39:03,246 DEBUG [org.apache.http.wire] [] >> "aS1jcmwuc3ltYXV0aC5jb20vY2FfNmE5Mzc3MzRhMzkzYTA4MDViZjMzY2RhOGIzMzEwOTMvTGF0 [\n]" 2019-03-26 22:39:03,246 DEBUG [org.apache.http.wire] [] >> "ZXN0Q1JMLmNybDA3BggrBgEFBQcBAQQrMCkwJwYIKwYBBQUHMAGGG2h0dHA6Ly9wa2ktb2NzcC5z [\n]" 2019-03-26 22:39:03,246 DEBUG [org.apache.http.wire] [] >> "eW1hdXRoLmNvbTAfBgNVHSMEGDAWgBRrb0u28Te6Kzx/GM26K7K5fCo36zAtBgpghkgBhvhFARAD [\n]" 2019-03-26 22:39:03,246 DEBUG [org.apache.http.wire] [] >> "BB8wHQYTYIZIAYb4RQEQAQIDAQGBqZDhAxYGOTU3NjA4MDkGCmCGSAGG+EUBEAUEKzApAgEAFiRh [\n]" 2019-03-26 22:39:03,246 DEBUG [org.apache.http.wire] [] >> "SFIwY0hNNkx5OXdhMmt0Y21FdWMzbHRZWFYwYUM1amIyMD0wDQYJKoZIhvcNAQELBQADggIBACfw [\n]" 2019-03-26 22:39:03,246 DEBUG [org.apache.http.wire] [] >> "qxUJpdO8NmWQiwCnvnJ7DJSZgSLJBmCvPMWemzm+hmI0hxRC59MdQXN0ABRq/7NAsd00UGl27SYC [\n]" 2019-03-26 22:39:03,246 DEBUG [org.apache.http.wire] [] >> "N0jyVS0MvTtaFrvRif5DK9Wh8PZ/qPxyDS2hO3pthwOYNieo87oaS0BAhu5g5Rc7w+1FGusx2dH9 [\n]" 2019-03-26 22:39:03,246 DEBUG [org.apache.http.wire] [] >> "is0GnvlqNVWITG9vAIBkYS2P3iuGMsRRkp/0l0YgXH4DimnOSZhN6lIN/anxVW2mWhht503fLkoA [\n]" 2019-03-26 22:39:03,246 DEBUG [org.apache.http.wire] [] >> "okS/difsw5Md9sb3kcPHGMtbLS7ItMnT8apmzRMUkffKUJ5TwM9hdTgypceRwEI0wHqaVy/opvTZ [\n]" 2019-03-26 22:39:03,246 DEBUG [org.apache.http.wire] [] >> "8taqgbW4Tk1xnC+EZRpaoFLkc4Of0EZsxyiN5NBzReE9LOx+dmqJH5raYGkcvIxznj2hLhJbrjwP [\n]" 2019-03-26 22:39:03,246 DEBUG [org.apache.http.wire] [] >> "qY98vflocPrf0UQ3Qptjx0/5PekWi59UKtconmDffH+tBHwvGsfkvKND1ammNkrIexF93udOg64f [\n]" 2019-03-26 22:39:03,246 DEBUG [org.apache.http.wire] [] >> "v0+7lmXoFOFcns03dl0yZrTVE++GPfrfu4eYwosU8+VTO4gLHeKlQ4iOo2+Daj/Hpvi5L8c6gW4b [\n]" 2019-03-26 22:39:03,246 DEBUG [org.apache.http.wire] [] >> "wOG93Y1z5n8aCMO9MydTtX0M2vbkzmtUWjmb+Tl/fLpw2FEA7dkfKYmyupCFLn+zxD6kazsml5Qi [\n]" 2019-03-26 22:39:03,246 DEBUG [org.apache.http.wire] [] >> "xK+S4wJB9z7cypMAsx9fEshjVIX150je0LCzFyWQD1bywHyc4PdmVmxmejWrjhtRnWfuQ1Onc0RLxjVdw1i8X5fPYK/YTZqvWl72EKTU21jMvtqafk4=MPJEHxt3AhixJaHwW/pxGkfyuF+gMXLWiL1GQf/oc24=uiNUcUhJozvZosCuv0iuGiw+T/3Zj/x2vZm4DJBYPz8=Dg74HTbOaEohZgiJ09Fx3szIB61Z+2D7WWQClyBE3AHIRi7oLQSAYJGST2ZdS7V38PvGop8+aU0W [\n]" 2019-03-26 22:39:03,246 DEBUG [org.apache.http.wire] [] >> "vJxHDxSvyoOygLL+W05K4MDGJe5CtfA0l4Pc10vRPZn3EV2awpLz3ockVrJYy+ji5HJKXSST0x92 [\n]" 2019-03-26 22:39:03,246 DEBUG [org.apache.http.wire] [] >> "WL3mDag+gUyiwwJ5C3HbzxuUhoCPGfbWdX3kqQpzvR1IzmHeCXfxyOVdt/CzT0EjiCBkeQcMihoW [\n]" 2019-03-26 22:39:03,246 DEBUG [org.apache.http.wire] [] >> "W+miHasEMkcFYOtcxfjwjnv+fy8AWHHOP+opUFfSk9vzkSnauPdkiBezwLe2g7KAzhhB5jTJVtEZ [\n]" 2019-03-26 22:39:03,247 DEBUG [org.apache.http.wire] [] >> "js+otF/GQm3Ju3mNFBNBWfPpc70BehOvFQNNFg==2019-03-26T22:39:02.455+01:0065e27e0e-3901-4d53-8cb3-64f84f089399@vlcibatch001.intra.infocamere.itPIT000252http://docs.oasis-open.org/ebxml-msg/ebms/v3.0/ns/core/200704/initiatorPNO000001http://docs.oasis-open.org/ebxml-msg/ebms/v3.0/ns/core/200704/responderurn:fdc:peppol.eu:2017:agreements:tia:ap_providerurn:www.cenbii.eu:profile:bii05:ver2.0busdox-docid-qns::urn:oasis:names:specification:ubl:schema:xsd:Invoice-2::Invoice##urn:www.cenbii.eu:transaction:biitrns010:ver2.0:extended:urn:www.peppol.eu:bis:peppol5a:ver2.0::2.1afc4dc51-13a5-4524-b2de-becc18be0eff@vlcibatch001.intra.infocamere.it9921:ictest0088:tbcntrl00002application/gzipapplication/xml[\r][\n]" 2019-03-26 22:39:03,247 DEBUG [org.apache.http.wire] [] >> "------=_Part_2_1589326257.1553636342879[\r][\n]" 2019-03-26 22:39:03,247 DEBUG [org.apache.http.wire] [] >> "Content-Type: application/octet-stream[\r][\n]" 2019-03-26 22:39:03,247 DEBUG [org.apache.http.wire] [] >> "Content-ID: <4e9f5f01-a892-4cc4-86ba-1f40aad26bf0@vlcibatch001.intra.infocamere.it>[\r][\n]" 2019-03-26 22:39:03,247 DEBUG [org.apache.http.wire] [] >> "Content-Transfer-Encoding: binary[\r][\n]" 2019-03-26 22:39:03,247 DEBUG [org.apache.http.wire] [] >> "[\r][\n]" 2019-03-26 22:39:03,247 DEBUG [org.apache.http.wire] [] >> "[\r][\n]" 2019-03-26 22:39:03,247 DEBUG [org.apache.http.wire] [] >> "------=_Part_2_1589326257.1553636342879--" 2019-03-26 22:39:03,309 DEBUG [org.apache.http.wire] [] << "HTTP/1.1 500 Server Error[\r][\n]" 2019-03-26 22:39:03,309 DEBUG [org.apache.http.wire] [] << "Server: nginx[\r][\n]" 2019-03-26 22:39:03,309 DEBUG [org.apache.http.wire] [] << "Date: Tue, 26 Mar 2019 21:39:03 GMT[\r][\n]" 2019-03-26 22:39:03,309 DEBUG [org.apache.http.wire] [] << "Content-Type: application/soap+xml; charset=UTF-8[\r][\n]" 2019-03-26 22:39:03,309 DEBUG [org.apache.http.wire] [] << "Transfer-Encoding: chunked[\r][\n]" 2019-03-26 22:39:03,309 DEBUG [org.apache.http.wire] [] << "Connection: keep-alive[\r][\n]" 2019-03-26 22:39:03,310 DEBUG [org.apache.http.wire] [] << "[\r][\n]" 2019-03-26 22:39:03,310 DEBUG [org.apache.http.impl.conn.DefaultClientConnection] [] Receiving response: HTTP/1.1 500 Server Error 2019-03-26 22:39:03,310 DEBUG [org.apache.http.headers] [] << HTTP/1.1 500 Server Error 2019-03-26 22:39:03,310 DEBUG [org.apache.http.headers] [] << Server: nginx 2019-03-26 22:39:03,310 DEBUG [org.apache.http.headers] [] << Date: Tue, 26 Mar 2019 21:39:03 GMT 2019-03-26 22:39:03,310 DEBUG [org.apache.http.headers] [] << Content-Type: application/soap+xml; charset=UTF-8 2019-03-26 22:39:03,310 DEBUG [org.apache.http.headers] [] << Transfer-Encoding: chunked 2019-03-26 22:39:03,310 DEBUG [org.apache.http.headers] [] << Connection: keep-alive 2019-03-26 22:39:03,311 DEBUG [org.apache.http.impl.client.DefaultHttpClient] [] Connection can be kept alive indefinitely 2019-03-26 22:39:03,316 DEBUG [org.apache.http.wire] [] << "1a8[\r][\n]" 2019-03-26 22:39:03,317 DEBUG [org.apache.http.wire] [] << "<" 2019-03-26 22:39:03,317 DEBUG [org.apache.http.wire] [] << "soap:Envelope xmlns:soap="http://www.w3.org/2003/05/soap-envelope">soap:Senderns1:SecurityErrorA security error was encountered when verifying the message" 2019-03-26 22:39:03,318 DEBUG [org.apache.http.wire] [] << "[\r][\n]" 2019-03-26 22:39:03,318 DEBUG [org.apache.http.wire] [] << "0[\r][\n]" 2019-03-26 22:39:03,318 DEBUG [org.apache.http.wire] [] << "[\r][\n]" 2019-03-26 22:39:03,318 DEBUG [org.apache.http.impl.conn.PoolingClientConnectionManager] [] Connection [id: 0][route: {s}->https://test-vefa.difi.no:443] can be kept alive indefinitely 2019-03-26 22:39:03,318 DEBUG [org.apache.http.impl.conn.PoolingClientConnectionManager] [] Connection released: [id: 0][route: {s}->https://test-vefa.difi.no:443][total kept alive: 1; route allocated: 1 of 2; total allocated: 1 of 20] 2019-03-26 22:39:03,325 TRACE [org.springframework.ws.client.MessageTracing.received] [] Received response [soap:Senderns1:SecurityErrorA security error was encountered when verifying the message] for request [------=_Part_3_1142114596.1553636343322 Content-Type: application/soap+xml; charset=utf-8 Rcn+oSKJXJw8vGyiRHTKo57Ddk8=NqOu6v3xhGcrJ5GpfCX5/XcddGA8sD5V4gCNBcmscVMekpIpzZrQ+5dIgwvGCVd0sPb21fakwjTB Mleh3jQKsBZAjz5sLPQpK5JNE5tQFzPmpahPX+hUFPuibBjtCEcxck55/Sn1uTABdVJmhtit5nBK 5cKogPliAy1Oaub2N9V/oIUsQSNsiqfhMwJwcJc+SThkUA1IBs5+fdb/P8Ivq+uWycGR/abA8UD8 AQXdYhlUCPWu87dIHD0IdEJkOq9AN12mFV/i42WMnEUmpWFdA1r0Dr0vsCWeNQoI13bQRUGWId+8 fRZ2Y3XAgEY2KPujqDToISwUcvS2M8bnSTlJQA==MIIFwzCCA6ugAwIBAgIQaVGTAxII7HUg/5QOnds9dTANBgkqhkiG9w0BAQsFADBrMQswCQYDVQQG EwJCRTEZMBcGA1UEChMQT3BlblBFUFBPTCBBSVNCTDEWMBQGA1UECxMNRk9SIFRFU1QgT05MWTEp MCcGA1UEAxMgUEVQUE9MIEFDQ0VTUyBQT0lOVCBURVNUIENBIC0gRzIwHhcNMTkwMTA5MDAwMDAw WhcNMjAxMjI5MjM1OTU5WjBQMRIwEAYDVQQDDAlQSVQwMDAyNTIxFzAVBgNVBAsMDlBFUFBPTCBU RVNUIEFQMRQwEgYDVQQKDAtJbmZvY2FtZXJlIDELMAkGA1UEBhMCSVQwggEiMA0GCSqGSIb3DQEB AQUAA4IBDwAwggEKAoIBAQCKlfdI6K45Hn2yj2OkeQOeH58ITKzGyHq64OM5WHeCFB+CP6nKU+/1 Lv+9Sxg2u8E0whpgEZjdYetnfm/meQwEPz8ZGK8VvV4dXGDjhF11muXANzLzv9jDXZYcCwQB4LQr QPFgnS5CiH1tL29qMUEBtyG9BR+mbMS74X/CJUQw95dBVDi8kNdlCy3wSJ4wfjV+VGu14comPKuz kckYSBF253cekQx0oFmCS3XiqQk9P+VwMwtabHRxguv/VP6iBw+Uby9IeS6dNfpcJ6tYfW86K+QE zMsJmXRzWQIFVJi5WIPvgOL6J135KMP9d2X7wvFudYaccZAI5rmCTPfQI8DfAgMBAAGjggF8MIIB eDAMBgNVHRMBAf8EAjAAMA4GA1UdDwEB/wQEAwIDqDAWBgNVHSUBAf8EDDAKBggrBgEFBQcDAjAd BgNVHQ4EFgQUMEiOA6/eZyMO3bo9wRYPwVIzRlMwXQYDVR0fBFYwVDBSoFCgToZMaHR0cDovL3Br aS1jcmwuc3ltYXV0aC5jb20vY2FfNmE5Mzc3MzRhMzkzYTA4MDViZjMzY2RhOGIzMzEwOTMvTGF0 ZXN0Q1JMLmNybDA3BggrBgEFBQcBAQQrMCkwJwYIKwYBBQUHMAGGG2h0dHA6Ly9wa2ktb2NzcC5z eW1hdXRoLmNvbTAfBgNVHSMEGDAWgBRrb0u28Te6Kzx/GM26K7K5fCo36zAtBgpghkgBhvhFARAD BB8wHQYTYIZIAYb4RQEQAQIDAQGBqZDhAxYGOTU3NjA4MDkGCmCGSAGG+EUBEAUEKzApAgEAFiRh SFIwY0hNNkx5OXdhMmt0Y21FdWMzbHRZWFYwYUM1amIyMD0wDQYJKoZIhvcNAQELBQADggIBACfw qxUJpdO8NmWQiwCnvnJ7DJSZgSLJBmCvPMWemzm+hmI0hxRC59MdQXN0ABRq/7NAsd00UGl27SYC N0jyVS0MvTtaFrvRif5DK9Wh8PZ/qPxyDS2hO3pthwOYNieo87oaS0BAhu5g5Rc7w+1FGusx2dH9 is0GnvlqNVWITG9vAIBkYS2P3iuGMsRRkp/0l0YgXH4DimnOSZhN6lIN/anxVW2mWhht503fLkoA okS/difsw5Md9sb3kcPHGMtbLS7ItMnT8apmzRMUkffKUJ5TwM9hdTgypceRwEI0wHqaVy/opvTZ 8taqgbW4Tk1xnC+EZRpaoFLkc4Of0EZsxyiN5NBzReE9LOx+dmqJH5raYGkcvIxznj2hLhJbrjwP qY98vflocPrf0UQ3Qptjx0/5PekWi59UKtconmDffH+tBHwvGsfkvKND1ammNkrIexF93udOg64f v0+7lmXoFOFcns03dl0yZrTVE++GPfrfu4eYwosU8+VTO4gLHeKlQ4iOo2+Daj/Hpvi5L8c6gW4b wOG93Y1z5n8aCMO9MydTtX0M2vbkzmtUWjmb+Tl/fLpw2FEA7dkfKYmyupCFLn+zxD6kazsml5Qi xK+S4wJB9z7cypMAsx9fEshjVIX150je0LCzFyWQD1bywHyc4PdmVmxmejWrjhtRnWfuQ1Onc0RLxjVdw1i8X5fPYK/YTZqvWl72EKTU21jMvtqafk4=MPJEHxt3AhixJaHwW/pxGkfyuF+gMXLWiL1GQf/oc24=uiNUcUhJozvZosCuv0iuGiw+T/3Zj/x2vZm4DJBYPz8=Dg74HTbOaEohZgiJ09Fx3szIB61Z+2D7WWQClyBE3AHIRi7oLQSAYJGST2ZdS7V38PvGop8+aU0W vJxHDxSvyoOygLL+W05K4MDGJe5CtfA0l4Pc10vRPZn3EV2awpLz3ockVrJYy+ji5HJKXSST0x92 WL3mDag+gUyiwwJ5C3HbzxuUhoCPGfbWdX3kqQpzvR1IzmHeCXfxyOVdt/CzT0EjiCBkeQcMihoW W+miHasEMkcFYOtcxfjwjnv+fy8AWHHOP+opUFfSk9vzkSnauPdkiBezwLe2g7KAzhhB5jTJVtEZ js+otF/GQm3Ju3mNFBNBWfPpc70BehOvFQNNFg==2019-03-26T22:39:02.455+01:0065e27e0e-3901-4d53-8cb3-64f84f089399@vlcibatch001.intra.infocamere.itPIT000252http://docs.oasis-open.org/ebxml-msg/ebms/v3.0/ns/core/200704/initiatorPNO000001http://docs.oasis-open.org/ebxml-msg/ebms/v3.0/ns/core/200704/responderurn:fdc:peppol.eu:2017:agreements:tia:ap_providerurn:www.cenbii.eu:profile:bii05:ver2.0busdox-docid-qns::urn:oasis:names:specification:ubl:schema:xsd:Invoice-2::Invoice##urn:www.cenbii.eu:transaction:biitrns010:ver2.0:extended:urn:www.peppol.eu:bis:peppol5a:ver2.0::2.1afc4dc51-13a5-4524-b2de-becc18be0eff@vlcibatch001.intra.infocamere.it9921:ictest0088:tbcntrl00002application/gzipapplication/xml ------=_Part_3_1142114596.1553636343322 Content-Type: application/octet-stream Content-ID: <4e9f5f01-a892-4cc4-86ba-1f40aad26bf0@vlcibatch001.intra.infocamere.it> Content-Transfer-Encoding: binary ------=_Part_3_1142114596.1553636343322--] 2019-03-26 22:39:03,327 DEBUG [no.difi.oxalis.as4.outbound.As4WebServiceTemplate] [] Received Fault message for request [SaajSoapMessage] 2019-03-26 22:39:03,332 ERROR [no.difi.oxalis.commons.error.QuietErrorTracker] [] [9761def9-41d6-4903-bb0e-f4ca4462a4b4] A security error was encountered when verifying the message org.springframework.ws.soap.client.SoapFaultClientException: A security error was encountered when verifying the message at org.springframework.ws.soap.client.core.SoapFaultMessageResolver.resolveFault(SoapFaultMessageResolver.java:38) at org.springframework.ws.client.core.WebServiceTemplate.handleFault(WebServiceTemplate.java:830) at org.springframework.ws.client.core.WebServiceTemplate.doSendAndReceive(WebServiceTemplate.java:624) at no.difi.oxalis.as4.outbound.As4WebServiceTemplate.doSendAndReceive(As4WebServiceTemplate.java:21) at org.springframework.ws.client.core.WebServiceTemplate.sendAndReceive(WebServiceTemplate.java:555) at no.difi.oxalis.as4.outbound.As4MessageSender.send(As4MessageSender.java:65) at no.difi.oxalis.as4.outbound.As4MessageSenderFascade.send(As4MessageSenderFascade.java:21) at no.difi.oxalis.api.outbound.MessageSender.send(MessageSender.java:59) at no.difi.oxalis.outbound.transmission.DefaultTransmitter.perform(DefaultTransmitter.java:149) at no.difi.oxalis.outbound.transmission.DefaultTransmitter.transmit(DefaultTransmitter.java:93) at eu.sendregning.oxalis.TransmissionTask.performTransmission(TransmissionTask.java:168) at eu.sendregning.oxalis.TransmissionTask.call(TransmissionTask.java:96) at eu.sendregning.oxalis.TransmissionTask.call(TransmissionTask.java:49) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 2019-03-26 22:39:03,333 ERROR [eu.sendregning.oxalis.Main] [] Execution failed: org.springframework.ws.soap.client.SoapFaultClientException: A security error was encountered when verifying the message java.util.concurrent.ExecutionException: org.springframework.ws.soap.client.SoapFaultClientException: A security error was encountered when verifying the message at java.util.concurrent.FutureTask.report(FutureTask.java:122) at java.util.concurrent.FutureTask.get(FutureTask.java:192) at eu.sendregning.oxalis.Main.main(Main.java:227) Caused by: org.springframework.ws.soap.client.SoapFaultClientException: A security error was encountered when verifying the message at org.springframework.ws.soap.client.core.SoapFaultMessageResolver.resolveFault(SoapFaultMessageResolver.java:38) at org.springframework.ws.client.core.WebServiceTemplate.handleFault(WebServiceTemplate.java:830) at org.springframework.ws.client.core.WebServiceTemplate.doSendAndReceive(WebServiceTemplate.java:624) at no.difi.oxalis.as4.outbound.As4WebServiceTemplate.doSendAndReceive(As4WebServiceTemplate.java:21) at org.springframework.ws.client.core.WebServiceTemplate.sendAndReceive(WebServiceTemplate.java:555) at no.difi.oxalis.as4.outbound.As4MessageSender.send(As4MessageSender.java:65) at no.difi.oxalis.as4.outbound.As4MessageSenderFascade.send(As4MessageSenderFascade.java:21) at no.difi.oxalis.api.outbound.MessageSender.send(MessageSender.java:59) at no.difi.oxalis.outbound.transmission.DefaultTransmitter.perform(DefaultTransmitter.java:149) at no.difi.oxalis.outbound.transmission.DefaultTransmitter.transmit(DefaultTransmitter.java:93) at eu.sendregning.oxalis.TransmissionTask.performTransmission(TransmissionTask.java:168) at eu.sendregning.oxalis.TransmissionTask.call(TransmissionTask.java:96) at eu.sendregning.oxalis.TransmissionTask.call(TransmissionTask.java:49) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) ### Auto send Test if i send the document to my AS4 Access Point Receiver I get the following error 2019-03-26 22:29:27,185 INFO [org.apache.cxf.services.As4Provider.REQ_IN] [] REQ_IN Address: https://peppolcl.infocamere.it/oxalis/as4 HttpMethod: POST Content-Type: multipart/related; boundary="----=_Part_2_1636359788.1553639362250"; type="application/soap+xml" ExchangeId: 1e3d1ea5-c4ec-4e09-a604-99dc6bf3babe ServiceName: As4ProviderService PortName: As4ProviderPort PortTypeName: As4Provider Headers: {Accept=application/soap+xml, text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2, host=peppolcl.infocamere.it, connection=Keep-Alive, content-type=multipart/related; boundary="----=_Part_2_1636359788.1553639362250"; type="application/soap+xml", Content-Length=10130, user-agent=Apache-HttpClient/4.5.7 (Java/1.8.0_45)} 2019-03-26 22:29:27,185 DEBUG [org.apache.cxf.phase.PhaseInterceptorChain] [] Invoking handleFault on interceptor org.apache.cxf.ext.logging.WireTapIn@525471b6 2019-03-26 22:29:27,185 DEBUG [org.apache.cxf.phase.PhaseInterceptorChain] [] Invoking handleFault on interceptor org.apache.cxf.interceptor.AttachmentInInterceptor@1d4c43b8 2019-03-26 22:29:27,185 DEBUG [org.apache.cxf.phase.PhaseInterceptorChain] [] Invoking handleFault on interceptor org.apache.cxf.ws.policy.PolicyInInterceptor@6fc02fb5 2019-03-26 22:29:27,186 WARN [org.apache.cxf.phase.PhaseInterceptorChain] [] Interceptor for {http://inbound.as4.oxalis.difi.no/}As4ProviderService has thrown exception, unwinding now org.apache.cxf.binding.soap.SoapFault: A security error was encountered when verifying the message at org.apache.cxf.ws.security.wss4j.WSS4JUtils.createSoapFault(WSS4JUtils.java:236) at org.apache.cxf.ws.security.wss4j.WSS4JInInterceptor.handleMessageInternal(WSS4JInInterceptor.java:341) at org.apache.cxf.ws.security.wss4j.WSS4JInInterceptor.handleMessage(WSS4JInInterceptor.java:176) at no.difi.oxalis.as4.inbound.OxalisAS4WsInInterceptor.handleMessage(OxalisAS4WsInInterceptor.java:39) at no.difi.oxalis.as4.inbound.OxalisAS4WsInInterceptor.handleMessage(OxalisAS4WsInInterceptor.java:20) at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:308) at org.apache.cxf.transport.MultipleEndpointObserver.onMessage(MultipleEndpointObserver.java:98) at org.apache.cxf.transport.http.AbstractHTTPDestination.invoke(AbstractHTTPDestination.java:267) at org.apache.cxf.transport.servlet.ServletController.invokeDestination(ServletController.java:234) at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:208) at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:160) at org.apache.cxf.transport.servlet.CXFNonSpringServlet.invoke(CXFNonSpringServlet.java:191) at org.apache.cxf.transport.servlet.AbstractHTTPServlet.handleRequest(AbstractHTTPServlet.java:301) at org.apache.cxf.transport.servlet.AbstractHTTPServlet.doPost(AbstractHTTPServlet.java:220) at javax.servlet.http.HttpServlet.service(HttpServlet.java:661) at org.apache.cxf.transport.servlet.AbstractHTTPServlet.service(AbstractHTTPServlet.java:276) at com.google.inject.servlet.ServletDefinition.doServiceImpl(ServletDefinition.java:290) at com.google.inject.servlet.ServletDefinition.doService(ServletDefinition.java:280) at com.google.inject.servlet.ServletDefinition.service(ServletDefinition.java:184) at com.google.inject.servlet.ManagedServletPipeline.service(ManagedServletPipeline.java:89) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:85) at io.opentracing.contrib.web.servlet.filter.TracingFilter.doFilter(TracingFilter.java:188) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82) at com.google.inject.servlet.ManagedFilterPipeline.dispatch(ManagedFilterPipeline.java:121) at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:133) at no.difi.oxalis.dist.war.WarGuiceFilter.doFilter(WarGuiceFilter.java:21) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:493) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81) at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:650) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87) at org.apache.catalina.ha.session.JvmRouteBinderValve.invoke(JvmRouteBinderValve.java:182) at org.apache.catalina.ha.tcp.ReplicationValve.invoke(ReplicationValve.java:322) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342) at org.apache.coyote.ajp.AjpProcessor.service(AjpProcessor.java:479) at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:806) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1498) at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.lang.Thread.run(Thread.java:748) Caused by: org.apache.wss4j.common.ext.WSSecurityException: javax.xml.crypto.dsig.TransformException: java.lang.IndexOutOfBoundsException at org.apache.wss4j.dom.processor.SignatureProcessor.verifyXMLSignature(SignatureProcessor.java:400) at org.apache.wss4j.dom.processor.SignatureProcessor.handleToken(SignatureProcessor.java:233) at org.apache.wss4j.dom.engine.WSSecurityEngine.processSecurityHeader(WSSecurityEngine.java:340) at org.apache.cxf.ws.security.wss4j.WSS4JInInterceptor.handleMessageInternal(WSS4JInInterceptor.java:285) ... 45 common frames omitted Caused by: javax.xml.crypto.dsig.XMLSignatureException: javax.xml.crypto.dsig.TransformException: java.lang.IndexOutOfBoundsException at org.apache.jcp.xml.dsig.internal.dom.DOMReference.transform(DOMReference.java:531) at org.apache.jcp.xml.dsig.internal.dom.DOMReference.validate(DOMReference.java:371) at org.apache.jcp.xml.dsig.internal.dom.DOMXMLSignature.validate(DOMXMLSignature.java:265) at org.apache.wss4j.dom.processor.SignatureProcessor.verifyXMLSignature(SignatureProcessor.java:373) ... 48 common frames omitted Caused by: javax.xml.crypto.dsig.TransformException: java.lang.IndexOutOfBoundsException at org.apache.wss4j.dom.transform.AttachmentContentSignatureTransform.attachmentRequestCallback(AttachmentContentSignatureTransform.java:130) at org.apache.wss4j.dom.transform.AttachmentContentSignatureTransform.transform(AttachmentContentSignatureTransform.java:113) at org.apache.jcp.xml.dsig.internal.dom.DOMTransform.transform(DOMTransform.java:159) at org.apache.jcp.xml.dsig.internal.dom.DOMReference.transform(DOMReference.java:443) ... 51 common frames omitted Caused by: java.lang.IndexOutOfBoundsException: null at java.io.ByteArrayInputStream.read(ByteArrayInputStream.java:180) at org.apache.wss4j.common.util.AttachmentUtils$1.initCipher(AttachmentUtils.java:491) at org.apache.wss4j.common.util.AttachmentUtils$1.available(AttachmentUtils.java:543) at org.apache.cxf.helpers.IOUtils.copy(IOUtils.java:187) at org.apache.cxf.helpers.IOUtils.copy(IOUtils.java:146) at org.apache.cxf.attachment.AttachmentDataSource.cache(AttachmentDataSource.java:54) at org.apache.cxf.attachment.AttachmentDeserializer.cacheStreamedAttachments(AttachmentDeserializer.java:225) at org.apache.cxf.attachment.AttachmentDeserializer.readNext(AttachmentDeserializer.java:197) at org.apache.cxf.attachment.LazyAttachmentCollection.loadAll(LazyAttachmentCollection.java:52) at org.apache.cxf.attachment.LazyAttachmentCollection.size(LazyAttachmentCollection.java:125) at org.apache.cxf.ws.security.wss4j.AttachmentCallbackHandler.loadAttachments(AttachmentCallbackHandler.java:123) at org.apache.cxf.ws.security.wss4j.AttachmentCallbackHandler.handle(AttachmentCallbackHandler.java:66) at org.apache.wss4j.dom.transform.AttachmentContentSignatureTransform.attachmentRequestCallback(AttachmentContentSignatureTransform.java:128) ... 54 common frames omitted
evenos commented 5 years ago

Thank you for your help and patience with this issue

I will summarize our findings for our correspondence solving this issue in hope that it will help future users with similar issues.

The provided logs were from two transmission attempts, one the remote PEPPOL TestBed, and one to your own local server. Both where rejected by the receiver with the message "A security error was encountered when verifying the message" On the message this is the only bit of information we get, in the logs from your own server there was this helpful line

Caused by: java.lang.IndexOutOfBoundsException: null .. SignatureProcessor.verifyXMLSignature

that made us suspect an error with the transmitted payload not being sent/received. After some debugging back and forth we found the issue to stem from configuring the logging level of org.apache.http.wire to TRACE, in this mode the payload is consumed by the logging layer and not sent to the receiver.

Disabling or changing the logging level of org.apache.http.wire to INFO or DEBUG solves the issue.