Wednesday 7 September 2016

How to solve JSchException Algorithm negotiation fail. And get logging out of JSch in SoapUI.

I was so glad with my SoapUI solution to SFTP files to a server. But so dissapointed I couldn't have it working at my customer.

After I changed the log entries to log with e.message, I got the line:
Wed Sep 07 11:17:43 CEST 2016:INFO:JSchException Algorithm negotiation fail

Now I needed more information than that. But the hint is at least that there is a mismatch in the available cyphers client side verses server side.

So first I wanted to get more logging out of Jsch. It turns out that it has it's own Logger framework, but the bright side of that is that you can easily wrap your own logging mechanism. In the case of SoapUI it is log4j. So create a java project with the libraries jsch-0.1.54.jar and from the SoapUI libs: log4j-1.2.14.jar. Then I created the following class file from an example from the answer in this stackoverflow question.

My version is:
package nl.darwin.jsch.log;


import com.jcraft.jsch.Logger; 

/**
 * Class to route log messages generated by JSch to Apache Log4J Logging.
 *
 * @author mrabbitt
 * @see com.jcraft.jsch.Logger
 */
public class JSchLog4JLogger implements Logger {
    private org.apache.log4j.Logger logger;
    
    /**
     * Constructor with custom category name 
     * 
     * @param logger the logger from Apache Log4J.
     */
    public JSchLog4JLogger(org.apache.log4j.Logger logger) {
        this.logger = logger;
    }
    
    /**
     * Default constructor
     */
    public JSchLog4JLogger() {
        this(org.apache.log4j.Logger.getLogger(Logger.class.getName()));
    }

    /* (non-Javadoc)
     * @see com.jcraft.jsch.Logger#isEnabled(int)
     */
    public boolean isEnabled(int level) {
        switch (level) {
        case DEBUG:
            return logger.isDebugEnabled();
        case INFO:
            return logger.isInfoEnabled();
        case WARN:
            return logger.isInfoEnabled();
        case ERROR:
            return logger.isInfoEnabled();
        case FATAL:
            return logger.isInfoEnabled();
        }
        return false;
    }

    /* (non-Javadoc)
     * @see com.jcraft.jsch.Logger#log(int, java.lang.String)
     */
    public void log(int level, String message) {
        switch (level) {
        case DEBUG:
            logger.debug(message);
            break;
        case INFO:
            logger.info(message);
            break;
        case WARN:
            logger.warn(message);
            break;
        case ERROR:
            logger.error(message);
            break;
        case FATAL:
            logger.fatal(message);
            break;
        }
    }
}

Then Jar it and add it to the bin/ext older of SoapUI (like in the previous blog post).
Now a simple extra line is needed and an import in your groovy script :
import nl.darwin.jsch.log.JSchLog4JLogger
...
  JSch.setLogger(new JSchLog4JLogger(log))
  JSch ssh = new JSch()

So simply set the logger on the JSch class, before the instantiation. Then the logging of JSch appears in the SoapUI logging, as easy as that.
It turned out that the server required the use of aes256-ctr, while the jre of SoapUI (which is Java 7 in SoapUI 5.2.1) has limited JCE policy. As is suggested here.

You can download the unlimited JCE policies here:
JDK
Unlimited JCE Download
JDK 1.6http://www.oracle.com/technetwork/java/javase/downloads/jce-6-download-429243.html
JDK 1.7http://www.oracle.com/technetwork/java/javase/downloads/jce-7-download-432124.html
JDK 1.8http://www.oracle.com/technetwork/java/javase/downloads/jce8-download-2133166.html

For SoapUI, download the JDK 1.7 policy. Go to your SoapUI Home folder, and navigate to the security library folder within the JRE. For instance: c:\Program Files\SmartBear\SoapUI-5.2.1\jre\lib\security.

Unzip the JCE to a new folder UnlimitedJCEPolicy within the security folder. Create a another backup folder like LimitedJCEPolicy and copy the jars US_export_policy.jar and local_policy.jar to the LimitedJCEPolicy folder. And copy the corresponding files from UnlimitedJCEPolicy to the security folder, replacing the original ones.

Restart SoapUI and you're good to go.


No comments :