All of the errors below are returned by running an SSIS Package that is deployed to SSISDB on a server (SQL Server 14.0.3445.2) - it all runs without error when running in Visual Studio on my own machine.
I have the some code, being run by a Script task called "Download Files from SFTP (removes as it goes)" in SSIS (VS 2019 deploying to MS SQL 2017 server, using Microsoft Visual C# 2017 task and targeting .NET 4.5, which is installed on the server). The task is designed to get files from an SFTP location and download them to a local folder, using the WinSCPNET.dll and WinSCP.exe library and executable. The minimally reduced version that still gives the error is as follows:
using System;
using Microsoft.SqlServer.Dts.Runtime;
using WinSCP;
namespace ST_661239b4b03f4f02bb8ffc102f7856a6
{
[Microsoft.SqlServer.Dts.Tasks.ScriptTask.SSISScriptTaskEntryPointAttribute]
public partial class ScriptMain : Microsoft.SqlServer.Dts.Tasks.ScriptTask.VSTARTScriptObjectModelBase
{
public void Main()
{
try
{
SessionOptions sessionOptions = new SessionOptions{};
Dts.TaskResult = (int)DTSExecResult.Success;
}
catch (Exception ex)
{
_ = Dts.Events.FireError(0, null, $"Error when using WinSCP to download files: {ex}", null, 0);
Dts.TaskResult = (int)DTSExecResult.Failure;
}
}
}
}
There is an OnError event handler on the task called "Record and Notify Error" - it sent the error message "Exception has been thrown by the target of an invocation.". The All Executions log on the server shows the the content of the table at the bottom when the task fails (verbose logging enabled):
In the course of attempting to debug, I added DTS.Event.FireInformation calls on every other line, but none fired, nor does the FireError call in the catch - the package goes straight to the error logging event handler.
Earlier, since I was having these errors and did some Googling, a colleague ran the following commands on the server to make sure that WinSCPNET.dll was added to the GAC, but this has not made a difference to the outcome:
cd "C:\Program Files(x86)\Microsoft SDKs\Windows\v8.1A\bin\NETFX 4.5.1 Tools"
gacutil.exe -i "C:\Program Files (x86)\WinSCP\WinSCPnet.dll"
I also downloaded the most recent version of SSIS (July 2023) and tried redeploying. The WinSCP logs were set and read as follows:
Started: 09:13:24
Package execution on IS Server failed. Execution ID: 236587, Execution Status:4.
To view the details for the execution, right-click on the Integration Services Catalog, and open the [All Executions] report
Started: 09:13:24
Finished: 09:13:28
Elapsed: 4.25 seconds
And that doesn't seem to add much more information. I have spent some time checking out the WinSCP documentation for using the .dll and I think that I have covered all the bases there - of course there may be something that I have missed as this is the first time I have tried to deploy a package that references a .dll like this. I am using version 6.1 of WinSCP.
So, my question is this: What should I do to fix or diagnose the issue here - What should be my next step?
Here are the text records of the logs:
| message_time | message_type | message_source_type | message |
|---|---|---|---|
| 2023-07-25 09:13:25.3729537 +01:00 | 10 | 30 | Package:Validation has started. |
| 2023-07-25 09:13:25.3885730 +01:00 | 10 | 40 | Download Files from SFTP (removes as it goes):Validation has started. |
| 2023-07-25 09:13:25.3885730 +01:00 | 20 | 40 | Download Files from SFTP (removes as it goes):Validation is complete. |
| 2023-07-25 09:13:25.3885730 +01:00 | 20 | 30 | Package:Validation is complete. |
| 2023-07-25 09:13:25.3885730 +01:00 | 400 | 30 | Beginning of package execution. |
| 2023-07-25 09:13:25.4041932 +01:00 | 140 | 30 | <DTS:PipelineColumnMap xmlns:DTS="www.microsoft.com/SqlServer/Dts"/> |
| 2023-07-25 09:13:25.4666978 +01:00 | 90 | 30 | Based on the system configuration, the maximum concurrent executables are set to 18. |
| 2023-07-25 09:13:25.4666978 +01:00 | 140 | 30 | <DTS:ParameterValues xmlns:DTS="www.microsoft.com/SqlServer/Dts"><DTS:PackageParameter DTS:DataType="8" DTS:ObjectName="Error_Documentation" |
| 2023-07-25 09:13:25.6697373 +01:00 | 140 | 30 | <DTS:ProcessMemoryUsage xmlns:DTS="www.microsoft.com/SqlServer/Dts">DTS:PeakWorkingSetSize70000640</DTS:PeakWorkingSetSize></DTS:ProcessMemoryUsage> |
| 2023-07-25 09:13:25.6697373 +01:00 | 400 | 30 | End of package execution. |
| 2023-07-25 09:13:25.4666978 +01:00 | 30 | 30 | Package:Start, 09:13:25. |
| 2023-07-25 09:13:25.4979152 +01:00 | 30 | 40 | Record and Notify Error:Start, 09:13:25. |
| 2023-07-25 09:13:25.4979152 +01:00 | 10 | 40 | Record and Notify Error:Validation has started. |
| 2023-07-25 09:13:25.4979152 +01:00 | 20 | 40 | Record and Notify Error:Validation is complete. |
| 2023-07-25 09:13:25.5291543 +01:00 | 90 | 30 | ExternalRequest_pre: The object is ready to make the following external request: 'IDbConnection.Open(ConnectionType: System.Data.SqlClient.SqlConnection, System.Data, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089 ConnectionString: Data Source=PRODSQLV1;Initial Catalog=util;Integrated Security=True;Application Name=SSIS-Package-{3448FBB1-957B-416B-8844-BD097AC40A9A}PRODSQL-V4.NWF_Utilities1;)'. |
| 2023-07-25 09:13:25.5291543 +01:00 | 90 | 30 | ExternalRequest_post: 'IDbConnection.Open succeeded'. The external request has completed. |
| 2023-07-25 09:13:25.5291543 +01:00 | 400 | 30 | Database connection acquired. |
| 2023-07-25 09:13:25.5291543 +01:00 | 90 | 30 | ExternalRequest_pre: The object is ready to make the following external request: 'IDbConnection.CreateCommand'. |
| 2023-07-25 09:13:25.5291543 +01:00 | 90 | 30 | ExternalRequest_post: 'IDbConnection.CreateCommand finished'. The external request has completed. |
| 2023-07-25 09:13:25.5291543 +01:00 | 400 | 30 | Preparing SQL statement:dbo.Error_Notify_Insert @ErrorCode ,@ErrorDescription ,@ErrorName ,@SourceName ,@SourceLocation ,NULL ,@Params ,NULL ,@RecipientOverride ,@SourceDocumentation; |
| 2023-07-25 09:13:25.5291543 +01:00 | 90 | 30 | ExternalRequest_pre: The object is ready to make the following external request: 'IDbCommand.ExecuteNonQuery'. |
| 2023-07-25 09:13:25.5916352 +01:00 | 90 | 30 | ExternalRequest_post: 'IDbCommand.ExecuteNonQuery finished'. The external request has completed. |
| 2023-07-25 09:13:25.5916352 +01:00 | 400 | 30 | Execution of the SQL statement is completed. |
| 2023-07-25 09:13:25.5916352 +01:00 | 60 | 40 | Record and Notify Error:Progress: Executing query "dbo.Error_Notify_Insert @ErrorCode ,@ErrorDes...".. |
| 2023-07-25 09:13:25.5916352 +01:00 | 90 | 30 | ExternalRequest_pre: The object is ready to make the following external request: 'IDbConnection.Close'. |
| 2023-07-25 09:13:25.5916352 +01:00 | 90 | 30 | ExternalRequest_post: 'IDbConnection.Close succeeded'. The external request has completed. |
| 2023-07-25 09:13:25.5916352 +01:00 | 40 | 40 | Record and Notify Error:Finished, 09:13:25, Elapsed time: 00:00:00.094. |
| 2023-07-25 09:13:25.6384962 +01:00 | 110 | 30 | Package:Warning: SSIS Warning Code DTS_W_MAXIMUMERRORCOUNTREACHED. The Execution method succeeded, but the number of errors raised (1) reached the maximum allowed (1); resulting in failure. This occurs when the number of errors reaches the number specified in MaximumErrorCount. Change the MaximumErrorCount or fix the errors. |
| 2023-07-25 09:13:25.6384962 +01:00 | 40 | 30 | Package:Finished, 09:13:25, Elapsed time: 00:00:00.234. |
| 2023-07-25 09:13:25.4822949 +01:00 | 30 | 40 | Download Files from SFTP (removes as it goes):Start, 09:13:25. |
| 2023-07-25 09:13:25.4822949 +01:00 | 10 | 40 | Download Files from SFTP (removes as it goes):Validation has started. |
| 2023-07-25 09:13:25.4822949 +01:00 | 20 | 40 | Download Files from SFTP (removes as it goes):Validation is complete. |
| 2023-07-25 09:13:25.5916352 +01:00 | 120 | 40 | Download Files from SFTP (removes as it goes):Error: Exception has been thrown by the target of an invocation. |
| 2023-07-25 09:13:25.6384962 +01:00 | 130 | 40 | Download Files from SFTP (removes as it goes):The task, 'Download Files from SFTP (removes as it goes)', failed. |
| 2023-07-25 09:13:25.6384962 +01:00 | 40 | 40 | Download Files from SFTP (removes as it goes):Finished, 09:13:25, Elapsed time: 00:00:00.156. |
The discovered reason for the error was that the version of WinSCP registered on the GAC of the server did not match the version available for use on the server, nor the one used during the building of the SSIS Package.
On the server, although the correct version was visible in Windows File Explorer, this did not match the version that was registered to the GAC, meaning that effectively the .dll that the SSIS package was attempting to use was not available.
In order to fix the error, the correct version (matching the development environment) was downloaded and added to the GAC using the same command as in the question. In our case, the old version was also removed from the GAC, but it has been shown elsewhere that this step is not necessary for correct execution.