Strange Behavior on Graceful Shut Down

[phatt-millips]

I have a Spring Boot service with Apache Camel that uploads files to an SMB file share. It seems that when the service is shut down mid upload it is closing the connection and reopening the connection. Then I believe it begins to overwrite the file but I'm not totally sure. Either way, the resulting output is a zip file with half the data that was originally supplied. It also usually requires a specialized zip extractor as my Mac throws an error when it tries to open the file.

camel version: 3.0.0 jcifs-ng version: 2.1.5 spring-integration-smb version: 1.2.1.RELEASE

I have also posted the issue here but was asked to move the issue to this GitHub repo

[mbechler]

If the connection/context is forcibly closed (you may want to figure out why/when this is happening, this seems to be too early if IO is occuring afterwards) then, yes, I think the current behavior is to reestablish the connection if further IO is performed. Overwriting the file should only be possible if a new stream is opened (as this keeps track of the write position). Legacy jcifs did "cache" the input stream with the SmbFile object, so calling getInputStream() multiple times would not have caused an issue. If camel relies on this behavior and does that, that might be the culprit.

Getting a debug log would help a lot to figure out what is actually happening.

[phatt-millips]

Here are the logs for the situation. At 2021-06-01 10:36:23.760 the service is stopped and the file then tries to finish uploading as part of the graceful shutdown. Something to note is that the fid is different after the service starts the graceful shutdown. I'm not sure if that affects things or not. half-zip-file-redacted-short.log

Side note: In redacting the above logs I found that 2021-06-01 10:36:33.518 on the "Tree handle was not properly released" warning it actually prints out the username and pass as part of the connection string.

[mbechler]

Sorry this took so long.

2021-06-01 10:36:23.760 DEBUG 23068 --- [       Thread-6] jcifs.smb.SmbTransportPoolImpl           : Closing pool

indicates that something in the calling is explicitly closing the context and therefore the connection at this point. Performing operations afterwards will automatically restablish the connection. This works as intended from the jcifs side.

Then we see the file being reopened, showing flags 0x52 which includes O_TRUNC (ultimately this results in FILE_SUPERSEDE CreateDisposition, truncating the file)

2021-06-01 10:36:23.893 DEBUG 23068 --- [E.DOCUMENT.BOL]] jcifs.smb.SmbFile                        : openUnshared: \data\*******\**********601-403964-a2600.zip flags: 52 access: 2 attrs: 80 options: 0

this would/should have been cleared by SmbOutputStream after the initial open, so it seems that the caller is in fact getting/opening a new stream, e.g. calling getOutputStream(). As mentioned this may have worked with jcifs 1.x, but now has side effects.

[tvirtualw]

Is it possible the shutdown hook in jcifs.context.AbstractCIFSContext#AbstractCIFSContext is interfering here? I remember in one of our projects we had to remove that shutdown hook added by AbstractCIFSContext because otherwise it would cause issues for us while our logic was still processing things.