SFTP コネクタが SFTP サーバーに接続しようとすると「Algorithm negotiation fail」(アルゴリズムのネゴシエーションに失敗しました) というエラーが発生する

問題

SFTP コネクタを含む Mule アプリケーションが以下のスタックトレースと同様の例外を表示して失敗する

org.mule.runtime.api.connection.ConnectionException:Could not establish SFTP connection with host: 'yourHost' at port: 'yourPort' - Algorithm negotiation failCaused by: com.jcraft.jsch.JSchException:Algorithm negotiation failat com.jcraft.jsch.Session.receive_kexinit(Session.java:590)at com.jcraft.jsch.Session.connect(Session.java:320)at com.jcraft.jsch.Session.connect(Session.java:183)at org.mule.extension.sftp.internal.connection.SftpClient.connect(SftpClient.java:179)at org.mule.extension.sftp.internal.connection.SftpClient.login(SftpClient.java:161)at org.mule.extension.sftp.internal.connection.SftpConnectionProvider.connect(SftpConnectionProvider.java:139)at org.mule.extension.sftp.internal.connection.SftpConnectionProvider.connect(SftpConnectionProvider.java:59)

原因

SFTP を介してクライアントとサーバー間でセキュアな接続が試行されると、鍵の交換アルゴリズム、暗号アルゴリズム、メッセージ認証コード (MAC)、圧縮アルゴリズムのリストが両方に公開されます。これらのアルゴリズムは、最もセキュリティ強度の高いものから低いものまで順序付けされています。アルゴリズムは、SSH 接続を続行する最適な選択肢のネゴシエーションに使用されます。 このネゴシエーション中に、使用するアルゴリズムの実装について合意に達しない場合、「Algorithm negotiation fail」(アルゴリズムのネゴシエーションに失敗しました) というメッセージが表示されます。 
この SSH アルゴリズムのネゴシエーションについての詳細は、「SSH RFC4253 セクション 7.1」を参照してください。

Mule アプリケーションで SFTP デバッグログを有効にすると、ネゴシエーション情報を確認できます。

Mule 4.x の場合、パッケージを設定してデバッグログを有効にすると「How to enable verbose logging for FTP and SFTP and FTPS module」(FTP、SFTP および FTPS モジュールで詳細なログを有効にする方法) を満たすことができますが、Mule 3.x では JSCH からデバッグログを取得するにあたり、いくつかの追加の修正が必要となります。この件については MuleSoft サポートまでお問い合わせください。

以下はこのネゴシエーションを示す SFTP デバッグログの例です。

DEBUG 2021-03-17 19:57:23,944 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] org.mule.extension.sftp.internal.connection.SftpConnectionProvider:Connecting to host: 'myHost' at port: 'myPort'DEBUG 2021-03-17 19:57:23,945 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch:Connecting to myHost port myPortDEBUG 2021-03-17 19:57:23,971 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch:Connection establishedDEBUG 2021-03-17 19:57:24,002 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch:Remote version string:SSH-2.0-CerberusFTPServer_11.0DEBUG 2021-03-17 19:57:24,002 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch:Local version string:SSH-2.0-JSCH-0.1.54DEBUG 2021-03-17 19:57:24,002 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch:CheckCiphers: aes256-ctr,aes192-ctr,aes128-ctr,aes256-cbc,aes192-cbc,aes128-cbc,3des-ctr,arcfour,arcfour128,arcfour256DEBUG 2021-03-17 19:57:24,006 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch: aes256-ctr is not available.DEBUG 2021-03-17 19:57:24,006 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch: aes192-ctr is not available.DEBUG 2021-03-17 19:57:24,006 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch: aes256-cbc is not available.DEBUG 2021-03-17 19:57:24,006 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch: aes192-cbc is not available.DEBUG 2021-03-17 19:57:24,006 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch:CheckKexes: diffie-hellman-group14-sha1,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521DEBUG 2021-03-17 19:57:24,075 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch:CheckSignatures: ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521DEBUG 2021-03-17 19:57:24,075 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch:SSH_MSG_KEXINIT sentDEBUG 2021-03-17 19:57:24,075 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch:SSH_MSG_KEXINIT receivedDEBUG 2021-03-17 19:57:24,075 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch: kex: server: ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1DEBUG 2021-03-17 19:57:24,076 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch: kex: server: ssh-rsa,ssh-ed25519,rsa-sha2-512,rsa-sha2-256DEBUG 2021-03-17 19:57:24,076 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch: kex: server: aes256-ctr,aes256-cbcDEBUG 2021-03-17 19:57:24,076 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch: kex: server: aes256-ctr,aes256-cbcDEBUG 2021-03-17 19:57:24,076 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch: kex: server: hmac-sha1,hmac-sha2-256,hmac-sha2-512,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-md5DEBUG 2021-03-17 19:57:24,076 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch: kex: server: hmac-sha1,hmac-sha2-256,hmac-sha2-512,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-md5DEBUG 2021-03-17 19:57:24,076 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch: kex: server: noneDEBUG 2021-03-17 19:57:24,076 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch: kex: server: noneDEBUG 2021-03-17 19:57:24,076 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch: kex: server: en-USDEBUG 2021-03-17 19:57:24,076 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch: kex: server: en-USDEBUG 2021-03-17 19:57:24,076 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch: kex: client: ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group14-sha1,diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group1-sha1DEBUG 2021-03-17 19:57:24,076 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch: kex: client: ssh-rsa,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521DEBUG 2021-03-17 19:57:24,076 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch: kex: client: aes128-ctr,aes128-cbc,3des-ctr,3des-cbc,blowfish-cbcDEBUG 2021-03-17 19:57:24,076 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch: kex: client: aes128-ctr,aes128-cbc,3des-ctr,3des-cbc,blowfish-cbcDEBUG 2021-03-17 19:57:24,076 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch: kex: client: hmac-md5,hmac-sha1,hmac-sha2-256,hmac-sha1-96,hmac-md5-96DEBUG 2021-03-17 19:57:24,076 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch: kex: client: hmac-md5,hmac-sha1,hmac-sha2-256,hmac-sha1-96,hmac-md5-96DEBUG 2021-03-17 19:57:24,076 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch: kex: client: noneDEBUG 2021-03-17 19:57:24,076 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch: kex: client: noneDEBUG 2021-03-17 19:57:24,076 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch: kex: client:DEBUG 2021-03-17 19:57:24,076 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch: kex: client:DEBUG 2021-03-17 19:57:24,077 [[MuleRuntime].uber.08: [my-mule-application].my-mule-applicationFlow.CPU_LITE @2a316d37] [processor: my-mule-applicationFlow/processors/0; event: ] com.jcraft.jsch:Disconnecting from myHost port myPort

この記事では 2 つのシナリオについて説明します。

シナリオ 1:圧縮アルゴリズムの不一致

圧縮アルゴリズムの不一致は次のスニペットと似ています。

com.jcraft.jsch: kex: server: zlibcom.jcraft.jsch: kex: client: none

暗号化の不一致は次のスニペットと似ています。

com.jcraft.jsch: kex: server: aes256-ctr,aes256-cbccom.jcraft.jsch: kex: client: aes128-ctr,aes128-cbc,3des-ctr,3des-cbc,blowfish-cbc

ソリューション 

サーバーとクライアント (SFTP コネクタ) の両方でサポートされる SSH のバージョンは、デバッグログの最初の部分に記載されています。

リモートバージョン文字列:SSH-2.0-OpenSSH_8.8ローカルバージョン文字列:SSH-2.0-JSCH-0.1.54

経験則として、ネゴシエートされたアルゴリズムの各カテゴリ (RFC に記載) は、クライアントとサーバーの間で少なくとも共通の実装 (および制約の充足) がなければ続行できません。

RFC 4253:Algorithm Negotiation      name-list    kex_algorithms      name-list    server_host_key_algorithms      name-list    encryption_algorithms_client_to_server      name-list    encryption_algorithms_server_to_client      name-list    mac_algorithms_client_to_server      name-list    mac_algorithms_server_to_client      name-list    compression_algorithms_client_to_server      name-list    compression_algorithms_server_to_client      name-list    languages_client_to_server      name-list    languages_server_to_client

シナリオ 1 (圧縮アルゴリズム)

SFTP コネクタは現時点で「zlib」圧縮をサポートしていません。そのため、サーバー側と互換性のあるアルゴリズムは「NONE」のみとなります。Ideas Portal を通じて機能強化の要望が提出されています。  

現時点で選択可能な代替策は以下のとおりです。

1. SFTP サーバーを構成して圧縮なしの接続を許可する (「NONE」アルゴリズムを有効化して提供)。 
2. Java SKD / DeviKit(Mule 3.x) または Java モジュールを使用する Java プログラムで、この機能に対応するライブラリを使用して該当する SFTP サーバーに接続するカスタムコネクタを開発する。

シナリオ 2 (暗号化の不一致)

a.使用する暗号が JSCH ライブラリでサポートされていることを確認する

SFTP コネクタは、SFTP サーバーへの接続を確立するためにJSCHライブラリを使用します。JSCH には、使用するバージョンに応じてドキュメントに記載された一連のサポート対象暗号化が含まれています。JSCH ChangeLog に含まれている機能を確認してください。 

• Mule Runtime 4.x の場合、ライブラリは各 SFTP コネクタのリリースにバンドルされており、Anypoint Studio のパッケージエクスプローラーから簡単にそのバージョンにアクセスできます。

例

• Mule Runtime 3.x のライブラリはランタイム自体とバンドルされており、「jsch-」のプレフィックスで始まる .jar ファイルを /lib/opt ディレクトリで検索すると確認できます。

該当する暗号化がライブラリでサポートされていない場合、SFTP サーバーでその JSCH バージョンによってサポートされている暗号化の間に含まれる 1 つ以上の暗号化を有効にする必要があります。

重要:使用中のライブラリを変更することは推奨されません。SFTP コネクタの動作はバンドルされたバージョンでテストと検証が行われているため、変更を試みる場合は下位環境で行い、できれば JSCH バージョンに互換性があるかどうかを MuleSoft サポートに確認してください。

b.暗号化が JVM レベルでの使用に対応していることを確認する 

SFTP コネクタは SFTP サーバーへの接続に JSCH ライブラリを内部で使用しており、このライブラリは最終的に JCE Java(TM) Cryptography Extension に依存します。JVM によっては、管理上の制限により特定の暗号が使用対象に含まれない場合があります。これらの制限が使用している JVM に適用されるかどうかは、ベンダーのドキュメントを参照して確認してください。

たとえば Oracle JVM の場合、特定の暗号化方式を許可するには JCE の無制限強度を追加する必要があります。各 Java バージョンには、それぞれ対応する JCE パッケージとインストールの詳細があります。

JDK8 の場合は以下を参照してください。

無制限強度のポリシーとインストールの詳細、無制限強度の JCE ポリシーファイル。

免責事項:このソリューションは個々の使用事例や要件と併せて考慮すべき提案であり、あらゆる状況に対応する完全なソリューションを意味するものではありません。