Issue: file stored on sent dir on resend, message ID pendingMDN issue

[tanakaPD]

OpenAS2 version 3.10.1

When an "Unexpected error sending file" occurs during file sending, AS2 Message ID and pending file name are updated, message is put in resend queue (with new AS2 message ID) and a copy of the file is stored, with the new AS2 message ID reference, in the sent dir (but at this moment the file was not actually sent):

2024-05-29 03:25:56.623 ERROR AS2SenderModule: Unexpected error sending file: Read timed out [<OPENAS2-29052024032455+0000-e2e64d09-0947-4b9d-87e9-e37aeb46ee3e@Sender_APD_AS2>]
java.net.SocketTimeoutException: Read timed out

2024-05-29 03:25:56.624 FINE AS2Util: Renamed pending info file : OPENAS2-29052024032455+0000-e2e64d09-0947-4b9d-87e9-e37aeb46ee3e@Sender_APD_AS2 :::: New name: OPENAS2-29052024032556+0000-4e4160f8-3561-453c-95fa-f022429c5b78@Sender_APD_AS2 [<OPENAS2-29052024032556+0000-4e4160f8-3561-453c-95fa-f022429c5b78@Sender_APD_AS2>]
2024-05-29 03:25:56.626 FINE DirectoryResenderModule: Message put in resend queue [<OPENAS2-29052024032556+0000-4e4160f8-3561-453c-95fa-f022429c5b78@Sender_APD_AS2>]
2024-05-29 03:25:56.627 FINE AS2Util: moved /home/as2/openas2/bin/../config/../data/mdn/pendingMDN/OPENAS2-29052024032455+0000-e2e64d09-0947-4b9d-87e9-e37aeb46ee3e@Sender_APD_AS2 to /home/as2/openas2/bin/../config/../data/sent/2024/05/050098_025948828.EDI-OPENAS2-29052024032556+0000-4e4160f8-3561-453c-95fa-f022429c5b78@Sender_APD_AS2 [<OPENAS2-29052024032556+0000-4e4160f8-3561-453c-95fa-f022429c5b78@Sender_APD_AS2>]

when finally the file is correctly sent, the program looks for a file with the original AS2 message ID in the pending MDN folder, not the updated one:

2024-05-29 03:31:32.408 FINE AS2Util: Message sent and MDN received successfully. [<OPENAS2-29052024032556+0000-4e4160f8-3561-453c-95fa-f022429c5b78@Sender_APD_AS2>]
2024-05-29 03:31:33.302 ERROR AS2Util: Error moving file to /home/as2/openas2/bin/../config/../data/sent/2024/05 : Source '/home/as2/openas2/bin/../config/../data/mdn/pendingMDN/OPENAS2-29052024032455+0000-e2e64d09-0947-4b9d-87e9-e37aeb46ee3e@Sender_APD_AS2' does not exist [<OPENAS2-29052024032556+0000-4e4160f8-3561-453c-95fa-f022429c5b78@Sender_APD_AS2>]
java.io.FileNotFoundException: Source '/home/as2/openas2/bin/../config/../data/mdn/pendingMDN/OPENAS2-29052024032455+0000-e2e64d09-0947-4b9d-87e9-e37aeb46ee3e@Sender_APD_AS2' does not exist

2024-05-29 03:31:33.303 FINE AS2Util: deleted /home/as2/openas2/bin/../config/../data/mdn/pendingMDN/OPENAS2-29052024032455+0000-e2e64d09-0947-4b9d-87e9-e37aeb46ee3e@Sender_APD_AS2 [<OPENAS2-29052024032556+0000-4e4160f8-3561-453c-95fa-f022429c5b78@Sender_APD_AS2>]

This behavior is not present in version 2.14.0

[uhurusurfa]

I will look into this ASAP.

[uhurusurfa]

I have figured out the problem and reworking handling of MDNs but summer holidays loom so may be a few weeks befrore a fix is released.

[uhurusurfa]

The latest release 3.11.0 fixes this issue provided by this PR #388

[tanakaPD]

Hello, we updated to version 3.11.0

2024-09-16 08:26:06.676 FINE OpenAS2Server: OpenAS2 Server v3.11.0 started.

but this morning we got another similar anomaly, behavior is the same as before:

2024-09-27 03:24:36.668 FINE MessageBuilderModule: File assigned to message: OPENAS2-27092024032436+0000-c23a02e9-e0cd-4d00-a134-ab8298a036e3@Sender_Receiver [<OPENAS2-27092024032436+0000-c23a02e9-e0cd-4d00-a134-ab8298a036e3@Sender_Receiver>]
2024-09-27 03:24:36.668 FINE AS2SenderModule: Message sender invoked for log ID: [<OPENAS2-27092024032436+0000-c23a02e9-e0cd-4d00-a134-ab8298a036e3@Sender_Receiver>]
2024-09-27 03:24:36.669 FINE AS2SenderModule: Save Original mic & message id information into file: /home/as2/openas2/bin/../config/../data/mdn/pendinginfoMDN/OPENAS2-27092024032436+0000-c23a02e9-e0cd-4d00-a134-ab8298a036e3@Sender_Receiver [<OPENAS2-27092024032436+0000-c23a02e9-e0cd-4d00-a134-ab8298a036e3@Sender_Receiver>]
2024-09-27 03:24:36.669 FINE AS2SenderModule: Connecting to: http://service.receiverl.com:5080 [<OPENAS2-27092024032436+0000-c23a02e9-e0cd-4d00-a134-ab8298a036e3@Sender_Receiver>]
2024-09-27 03:25:18.964 ERROR AS2SenderModule: Unexpected error sending file: Connection reset [<OPENAS2-27092024032436+0000-c23a02e9-e0cd-4d00-a134-ab8298a036e3@Sender_Receiver>]
2024-09-27 03:25:18.964 FINE AS2Util: Renamed pending info file : OPENAS2-27092024032436+0000-c23a02e9-e0cd-4d00-a134-ab8298a036e3@Sender_Receiver :::: New name: OPENAS2-27092024032518+0000-62f4238c-b5f4-4129-8998-142cbaec5107@Sender_Receiver [<OPENAS2-27092024032518+0000-62f4238c-b5f4-4129-8998-142cbaec5107@Sender_Receiver>]
2024-09-27 03:25:18.965 FINE AS2Util: Pending file /home/as2/openas2/bin/../config/../data/mdn/pendingMDN/OPENAS2-27092024032436+0000-c23a02e9-e0cd-4d00-a134-ab8298a036e3@Sender_Receiver moved to /home/as2/openas2/bin/../config/../data/sent/2024/09/file_to_send.txt-OPENAS2-27092024032518+0000-62f4238c-b5f4-4129-8998-142cbaec5107@Sender_Receiver [<OPENAS2-27092024032518+0000-62f4238c-b5f4-4129-8998-142cbaec5107@Sender_Receiver>]

024-09-27 03:30:36.666 FINE DirectoryResenderModule: loaded message for resend. [<OPENAS2-27092024032518+0000-62f4238c-b5f4-4129-8998-142cbaec5107@Sender_Receiver>]
2024-09-27 03:30:36.666 FINE AS2SenderModule: Message sender invoked for log ID: [<OPENAS2-27092024032518+0000-62f4238c-b5f4-4129-8998-142cbaec5107@Sender_Receiver>]
2024-09-27 03:30:36.667 FINE AS2SenderModule: Save Original mic & message id information into file: /home/as2/openas2/bin/../config/../data/mdn/pendinginfoMDN/OPENAS2-27092024032518+0000-62f4238c-b5f4-4129-8998-142cbaec5107@Sender_Receiver [<OPENAS2-27092024032518+0000-62f4238c-b5f4-4129-8998-142cbaec5107@Sender_Receiver>]
2024-09-27 03:30:36.668 FINE AS2SenderModule: Connecting to: http://service.receiver.com:5080 [<OPENAS2-27092024032518+0000-62f4238c-b5f4-4129-8998-142cbaec5107@Sender_Receiver>]
2024-09-27 03:30:38.175 FINE AS2SenderModule: Message sent and response received in 1488 milliseconds [<OPENAS2-27092024032518+0000-62f4238c-b5f4-4129-8998-142cbaec5107@Sender_Receiver>]
2024-09-27 03:30:38.177 FINE AS2Util: Partner Receiver responded with MDN [automatic-action/MDN-sent-automatically; processed] [<OPENAS2-27092024032518+0000-62f4238c-b5f4-4129-8998-142cbaec5107@Sender_Receiver>]
2024-09-27 03:30:38.177 FINE AS2Util: Message sent and MDN received successfully. [<OPENAS2-27092024032518+0000-62f4238c-b5f4-4129-8998-142cbaec5107@Sender_Receiver>]
2024-09-27 03:30:38.920 ERROR AS2Util: Error moving file to /home/as2/openas2/bin/../config/../data/sent/2024/09 : Source '/home/as2/openas2/bin/../config/../data/mdn/pendingMDN/OPENAS2-27092024032436+0000-c23a02e9-e0cd-4d00-a134-ab8298a036e3@Sender_Receiver' does not exist [<OPENAS2-27092024032518+0000-62f4238c-b5f4-4129-8998-142cbaec5107@Sender_Receiver>]
2024-09-27 03:30:38.921 FINE AS2Util: deleted /home/as2/openas2/bin/../config/../data/mdn/pendingMDN/OPENAS2-27092024032436+0000-c23a02e9-e0cd-4d00-a134-ab8298a036e3@Sender_Receiver [<OPENAS2-27092024032518+0000-62f4238c-b5f4-4129-8998-142cbaec5107@Sender_Receiver>]

[uhurusurfa]

I will take a look at it ASAP

[uhurusurfa]

This PR #394 fixes the issue. There are a few other items that will be done before a new release goes out with the fix.

[uhurusurfa]

Released in version 4.0.0