I am trying to read a series of zipped files, each with one fixed-width data files in it, from an SFTP server.
I collect the files, stream them to a temp file, then try to unzip them, and I have had no success with the last part.
I don't get an error. I don't see any logs. The process just abruptly exits, circumventing my try... catch... finally block and I've been scratching my head on this. I've tried with several different zip libraries and I'm seeing the same behavior with each. My code looks like this:
public async Task ProcessFiles(CommandLineOptions options)
{
try
{
var privateKey = new PrivateKeyFile(options.PrivateKeyPath, options.PrivateKeyPassword);
_logger.LogDebug("Loaded up the private key for {username}.", options.LoginUsername);
var connection = new ConnectionInfo(options.Host, options.LoginUsername,
new PrivateKeyAuthenticationMethod(options.LoginUsername, privateKey));
_logger.LogDebug("Created a connection object for SFTP to {host}.", options.Host);
using var client = new SftpClient(connection);
client.Connect();
_logger.LogDebug("Connected to {host}.", options.Host);
var files = client.ListDirectory(".").ToList();
_logger.LogTrace("{numFiles} file(s) found in the directory.", files.Count);
foreach (var file in files.Where(fn =>
fn.FullName.EndsWith(".zip", StringComparison.InvariantCultureIgnoreCase)))
{
string localFile = null;
try
{
_logger.LogDebug("Processing file {fileName}", file.FullName);
localFile = Path.Combine(Path.GetTempPath(), $"{Guid.NewGuid():N}.ZIP");
_logger.LogTrace("Writing to {tempPath}", localFile);
await using var downStream = File.OpenWrite(localFile);
client.DownloadFile(file.Name, downStream);
_logger.LogDebug("File {fileName} downloaded.", localFile);
await downStream.DisposeAsync();
_logger.LogTrace("Opening {fileName} for read access...", localFile);
await using var upStream = File.Open(localFile,FileMode.OpenOrCreate);
_logger.LogTrace("File has been opened for streaming, reading in ZipArchive...");
var archive = ZipArchive.Open(upStream, new ReaderOptions
{
LeaveStreamOpen = true,
LookForHeader = true,
DisableCheckIncomplete = false
});
_logger.LogTrace("Archive file successfully opened.");
var reader = archive.ExtractAllEntries();
foreach (var entry in archive.Entries)
{
_logger.LogTrace("Opening file {compressedFile} in the ZIP file {fileName}...", entry.Key,
file.FullName);
await using var inStream = reader.OpenEntryStream();
foreach (var record in _recordLoader.GetRecords(inStream))
{
_logger.LogTrace("Record parsed for file type {type} sequence {sequence}...", record.Type,
record.SequenceNumber);
record.TenantId = options.TenantId;
await _dbContext.Trades.AddAsync(record);
_logger.LogTrace("Adding trade {sequence} in file {zippedFile} to Trades...",
record.SequenceNumber, entry.Key);
}
var added = await _dbContext.SaveChangesAsync();
_logger.LogInformation("Loaded {recordsAdded} records from the zipped file {zippedFile}.",
added,
entry.Key);
}
}
catch (Exception ex)
{
_logger.LogError(ex, "Failure downloading file {fileName}.", file.FullName);
}
finally
{
_logger.LogDebug("Deleting local file {localFile}", localFile);
if (File.Exists(localFile)) File.Delete(localFile);
_logger.LogDebug("File {localFile} deleted.");
}
}
_logger.LogInformation("Pershing file processing is complete.");
}
catch (Exception ex)
{
_logger.LogError(ex, "Process to load Pershing files failed. The exception is included.");
}
}
When I run this I get something resembling:
dbug: Microsoft.EntityFrameworkCore.Infrastructure[10401]
An 'IServiceProvider' was created for internal use by Entity Framework.
dbug: AppRunner[0]
Loaded up the private key for mycompanysftp.pershing.importer.
dbug: AppRunner[0]
Created a connection object for SFTP to mycompanysftp.blob.core.windows.net.
dbug: AppRunner[0]
Connected to mycompanysftp.blob.core.windows.net.
trce: AppRunner[0]
5 file(s) found in the directory.
dbug: AppRunner[0]
Processing file /GSDE20221011.ZIP
trce: AppRunner[0]
Writing to C:\Users\jholo\AppData\Local\Temp\10826b52fba94b7db7844958dd3c2e9e.ZIP
dbug: AppRunner[0]
File C:\Users\jholo\AppData\Local\Temp\10826b52fba94b7db7844958dd3c2e9e.ZIP downloaded.
trce: AppRunner[0]
Opening C:\Users\jholo\AppData\Local\Temp\10826b52fba94b7db7844958dd3c2e9e.ZIP for read access...
trce: AppRunner[0]
File has been opened for streaming, reading in ZipArchive...
D:\Repos\jholovacs\mycompany\mycompany.Data.Pershing.TestApp\bin\Debug\net6.0\mycompany.Data.Pershing.Importer.exe (process 50628) exited with code 0.
If I go into my temp directory, the file exists, and I can open the zip file up just fine with my Windows Explorer.
What is going on here? How can my finally block be bypassed? How is no exception being thrown? What am I doing wrong?
OK, so this doesn't seem to be a problem with this code, but rather what is calling this code. It was run asynchronously in a synchronous console app, and it looks like the awaiter wasn't being invoked, so the process would continue on till it reached its end. I was invoking this with a library I haven't used before (CommandLineParser) and it has this novel approach:
Parser.Default.ParseArguments<CommandLineOptions>(args)
.WithParsedAsync(async clo =>
{
var runner = scope.ServiceProvider.GetService<AppRunner>();
await runner.ProcessFiles(clo);
Console.WriteLine("Holup");
});
... which I had assumed meant this was designed to run async code... and it does, but by itself being asynchronous.
When I added a .GetAwaiter().GetResult() to the end of that command, the result was very different.