Apache-commons-net lib (Java) 的受控日志记录答案

【问题标题】：Controlled Logging for Apache-commons-net lib (Java)Apache-commons-net lib (Java) 的受控日志记录
【发布时间】：2012-07-20 03:41:20
【问题描述】：

我有一个非常小的 Java 程序，它能够使用 apache-commons-net 库通过 SSL（不是 SFTP）或 FTPS 执行 FTP。我写这个程序的原因是客户端机器是 AIX 5.3，它不支持 FTP over SSL (OOTB)，而 FTP 主机运行 FileZilla 服务器，只启用了 FTP over SSL。该程序运行良好，没有任何问题，但它生成的日志量很大。我的问题是 - 有没有办法控制日志记录的数量？

（再次注意-该程序非常适合我的简约要求）

下面是我的代码中的一个 sn-p

import java.io.*;
import java.text.MessageFormat;
import java.util.logging.Logger;
import org.apache.commons.
.....
....
....
try {
            int reply;
            logger.info("# Invoking Trust Manager");
            client.setTrustManager(TrustManagerUtils.getAcceptAllTrustManager());
            //client.setTrustManager(TrustManagerUtils.getValidateServerCertificateTrustManager());
            logger.info("# Connect Call");
            client.connect(server, port);
            client.login(username, password);
            logger.info("# Login Success");

            client.setFileType(FTP.ASCII_FILE_TYPE);
            client.execPBSZ(0); // Set protection buffer size
            client.execPROT("P"); // Set data channel protection to private
            client.enterLocalPassiveMode();

            logger.info(MessageFormat.format("Connected to {0} .", server));
            reply = client.getReplyCode();
            if (!FTPReply.isPositiveCompletion(reply)) {
                client.disconnect();
                logger.severe("FTP server refused connection.");
                System.exit(1);
            }

            if (flag.equals("-d")) { //Dir mode
                if (args.length == 7){
                    renameFile = args[6]; //copy rename token
                }
                //We will get the file listing and stream the output to create files
                logger.info("# Invoked Directory mode");
                client.changeWorkingDirectory(remoteFile);
                FTPFile[] ftpFiles;
                ftpFiles = client.listFiles(remoteFile);
                if (ftpFiles != null && ftpFiles.length > 0) {                    
                    for (FTPFile file : ftpFiles) {
                        if (!file.isFile()) {
                            continue;
                        }                        
                        InputStream fin = client.retrieveFileStream(remoteFile + "/" + file.getName());
                        if (fin == null) {
                            logger.severe(MessageFormat.format("could not retrieve file: {0}", file.getName()));
                            continue;
                        }
                        // write the inputStream to a FileOutputStream
                        OutputStream out = new FileOutputStream(new File(localFile + "/"+ renameFile + file.getName()));
                        int read = 0;
                        byte[] bytes = new byte[1024];

                        while ((read = fin.read(bytes)) != -1) {
                            out.write(bytes, 0, read);
                        }
                        fin.close();
                        out.flush();
                        out.close();
                        fin = null;
                        client.completePendingCommand();
                    }
                }
            }

            if (flag.equals("-f")) { //File mode
                //Transfer a single file
                logger.info("# Invoked File mode");
                client.listFiles();
                boolean retrieved = client.retrieveFile(remoteFile, new FileOutputStream(localFile));

                if (retrieved) {
                    logger.info("# File copied.");
                }
            }
        } catch (Exception e) {
            if (client.isConnected()) {
                try {
                    client.disconnect();
                } catch (IOException ex) {
                    ex.printStackTrace();
                }
            }
            logger.severe("!! Could not connect to server.!! Please retry!");
            e.printStackTrace();            
        } finally {
            client.disconnect();            
            logger.info("# FTP Client disconnected");
            System.exit(0);
        }

它为传输一个文件而生成的日志如下-

Jul 20, 2012 5:00:08 AM com.mff.ftps.FTPSSLTool main
INFO: Connecting to IP: 216.153.173.246 on Port: 00890
Jul 20, 2012 5:00:09 AM com.mff.ftps.FTPSSLTool main
INFO: # Initiating SSL connection
Jul 20, 2012 5:00:09 AM com.mff.ftps.FTPSSLTool main
INFO: # Invoking Trust Manager
Jul 20, 2012 5:00:09 AM com.mff.ftps.FTPSSLTool main
INFO: # Connect Call
IBMJSSEProvider2 Build-Level: -20110513
keyStore is: /usr/java6_64/jre/lib/security/cacerts
keyStore type is: jks
keyStore provider is: 
init keystore
SSLContextImpl:  Using X509ExtendedKeyManager com.ibm.jsse2.xc
SSLContextImpl:  Using X509TrustManager org.apache.commons.net.util.TrustManagerUtils$TrustManager
Installed Providers = 
    IBMJSSE2
    IBMJCE
    IBMJGSSProvider
    IBMCertPath
    IBMSASL
    IBMXMLCRYPTO
    IBMXMLEnc
    Policy
    IBMSPNEGO
JsseJCE:  Using SecureRandom  from provider IBMJCE version 1.2
trigger seeding of SecureRandom
done seeding SecureRandom
IBMJSSE2 to send SCSV Cipher Suite on initial ClientHello
JsseJCE:  Using cipher AES/CBC/NoPadding from provider TBD via init 
IBMJSSE2 will allow RFC 5746 renegotiation per com.ibm.jsse2.renegotiate set to none or default
IBMJSSE2 will not require renegotiation indicator during initial handshake per com.ibm.jsse2.renegotiation.indicator set to OPTIONAL or default taken
IBMJSSE2 will not perform identity checking against the peer cert check during renegotiation per com.ibm.jsse2.renegotiation.peer.cert.check set to OFF or default
JsseJCE:  Using MessageDigest MD5 from provider IBMJCE version 1.2
JsseJCE:  Using MessageDigest SHA from provider IBMJCE version 1.2
JsseJCE:  Using MessageDigest MD5 from provider IBMJCE version 1.2
JsseJCE:  Using MessageDigest SHA from provider IBMJCE version 1.2
%% No cached client session
*** ClientHello, SSLv3
RandomCookie:  GMT: 1342778411 bytes = { 246, 135, 47, 123, 204, 170, 94, 224, 76, 244, 28, 242, 63, 243, 124, 13, 93, 156, 170, 88, 91, 79, 89, 55, 157, 135, 214, 250 }
Session ID:  {}
Cipher Suites: [SSL_RSA_WITH_RC4_128_MD5, SSL_RSA_WITH_RC4_128_SHA, SSL_RSA_WITH_AES_128_CBC_SHA, SSL_DHE_RSA_WITH_AES_128_CBC_SHA, SSL_DHE_DSS_WITH_AES_128_CBC_SHA, SSL_RSA_WITH_3DES_EDE_CBC_SHA, SSL_RSA_FIPS_WITH_3DES_EDE_CBC_SHA, SSL_DHE_RSA_WITH_3DES_EDE_CBC_SHA, SSL_DHE_DSS_WITH_3DES_EDE_CBC_SHA, SSL_DHE_DSS_WITH_RC4_128_SHA, SSL_RSA_WITH_DES_CBC_SHA, SSL_RSA_FIPS_WITH_DES_CBC_SHA, SSL_DHE_RSA_WITH_DES_CBC_SHA, SSL_DHE_DSS_WITH_DES_CBC_SHA, SSL_RSA_EXPORT_WITH_RC4_40_MD5, SSL_RSA_EXPORT_WITH_DES40_CBC_SHA, SSL_DHE_RSA_EXPORT_WITH_DES40_CBC_SHA, SSL_DHE_DSS_EXPORT_WITH_DES40_CBC_SHA, SSL_RENEGO_PROTECTION_REQUEST]
Compression Methods:  { 0 }
***
main, WRITE: SSLv3 Handshake, length = 81
main, READ: SSLv3 Handshake, length = 74
*** ServerHello, SSLv3
RandomCookie:  GMT: 1342778410 bytes = { 142, 39, 57, 18, 38, 123, 184, 245, 24, 29, 238, 158, 68, 17, 226, 210, 53, 31, 36, 225, 52, 166, 78, 116, 251, 98, 122, 4 }
Session ID:  {143, 221, 201, 170, 184, 190, 241, 94, 223, 253, 199, 199, 50, 161, 233, 224, 88, 78, 82, 162, 13, 222, 236, 56, 215, 253, 101, 12, 39, 45, 126, 203}
Cipher Suite: SSL_RSA_WITH_RC4_128_MD5
Compression Method: 0
***
Server did not supply RI Extension - com.ibm.jsse2.extended.renegotiation.indicator=optional or default - processing will continue
%% Created:  [Session-1, SSL_RSA_WITH_RC4_128_MD5]
** SSL_RSA_WITH_RC4_128_MD5
main, READ: SSLv3 Handshake, length = 1361
*** Certificate chain
chain [0] = [
[
  Version: V3
  Subject: CN=ftps.thillsecure.com, OU=Terms of use at www.verisign.com/rpa (c)05, OU=Thill Logistics, O=TCFC LLC, L=Neenah, ST=Wisconsin, C=US
  Signature Algorithm: SHA1withRSA, OID = 1.2.840.113549.1.1.5

  Key:  IBMJCE RSA Public Key:
modulus:134055911103149706293270567805752446004906288958857850
public exponent:
65537

  Validity: [From: Sun Dec 04 18:00:00 CST 2011,
               To: Wed Dec 12 17:59:59 CST 2012]
  Issuer: CN=VeriSign Class 3 Secure Server CA - G3, OU=Terms of use at https://www.verisign.com/rpa (c)10, OU=VeriSign Trust Network, O="VeriSign, Inc.", C=US
  SerialNumber: [168622087069244624687861365106323602194]
....
....
....
Hundreds and hundreds of more lines

我将java.utils.logging.Logger 用于我自己的日志记录目的，但是日志行被apache-commons-net 库方法本身生成的大量日志行混淆了。

再说一遍 - 问题是 - “有没有办法控制 apache-commons-net 库本身的这种日志记录行为？我可以使用的任何方法或需要设置的任何标志？”

更新：

我终于控制了日志记录（特别感谢Flavio）。我所要做的就是在我的代码中包含System.setProperty("javax.net.debug", "false");。我最初将它设置为System.setProperty("javax.net.debug", "ssl");，它启用了调试级别的日志记录。现在日志更短更精确。很明显，这些日志毕竟不是来自 commons-net 库，而是来自javax.net。日志要短得多，如下所示-

Jul 30, 2012 9:03:16 AM com.mff.ftps.FTPSSLTool main
INFO: Connecting to IP: xxx.xxx.xxx.xxx on Port: 890
Jul 30, 2012 9:03:16 AM com.mff.ftps.FTPSSLTool main
INFO: # Initiating SSL connection
Jul 30, 2012 9:03:16 AM com.mff.ftps.FTPSSLTool main
INFO: # Invoking Trust Manager
Jul 30, 2012 9:03:16 AM com.mff.ftps.FTPSSLTool main
INFO: # Connect Call
220 GlobalSCAPE Secure FTP Server
USER XXXXXXX
331 Password required for XXXXXXX.
PASS XXXXXXXXX
230 Login OK. Proceed.
Jul 30, 2012 9:03:22 AM com.mff.ftps.FTPSSLTool main
INFO: # Login Success
TYPE A
200 Type set to A.
PBSZ 0
200 PBSZ Command OK. Protection buffer size set to 0.
PROT P
200 PROT Command OK. Using Private data connection
Jul 30, 2012 9:03:24 AM com.mff.ftps.FTPSSLTool main
INFO: Connected to xxx.xxx.xxx.xxx .
CWD /Data/Inv
Jul 30, 2012 9:03:24 AM com.mff.ftps.FTPSSLTool main
INFO: # Invoked Directory mode
250 Folder changed to "/Data/Inv".
SYST
215 UNIX Type: L8
PASV
227 Entering Passive Mode (216,153,173,246,109,220).
LIST /Data/Inv
150 Opening ASCII mode data connection for file list.
226 Transfer complete. 1430 bytes transferred. 1278 Bps.
Jul 30, 2012 9:03:30 AM com.mff.ftps.FTPSSLTool main
INFO: # FTP Client disconnected

【问题讨论】：

标签： java ssl ftp apache-commons-net ftps

【解决方案1】：

您可以使用setLevel() 设置应用程序的日志级别。 Level 类用于定义应将哪些消息写入日志。您可以设置以下日志级别之一：

Level.SEVERE（最高级别）
Level.WARNING
Level.INFO
Level.CONFIG
Level.FINE
Level.FINER
Level.FINEST

如果您使用LOGGER.setLevel(Level.INFO)，每个高于或等于INFO 的日志级别都将写入日志，即，SEVERE, WARNING and INFO。此外，您还可以使用级别 Level.OFF 和 Level.ALL 来关闭日志记录或记录所有内容。

向您的应用程序添加更高的日志级别，例如logger.setLevel(Level.SEVERE)。

示例

public void writeLog() {
    // Set the LogLevel to Severe, only severe Messages will be written
    LOGGER.setLevel(Level.SEVERE);
    LOGGER.severe("Severe Log");
    LOGGER.warning("Warning Log");
    LOGGER.info("Info Log");
    LOGGER.finest("Really not important");

    // Set the LogLevel to Info, severe, warning and info will be written
    // Finest is still not written
    LOGGER.setLevel(Level.INFO);
    LOGGER.severe("Severe Log");
    LOGGER.warning("Warning Log");
    LOGGER.info("Info Log");
    LOGGER.finest("Really not important");
}

附：小心设置global log level 的logging.properties 文件。

【讨论】：

感谢您的回复。但这会控制apache-commons-net 日志记录吗？您在上面的原始问题中看到的大多数日志行来自apache-commons-net 库，而不是来自我的类文件。正如您所看到的，它从 Keystore 到 cokkies 再到证书链的每一步都打印出来。此时我想控制库的日志记录本身（不是我的程序级日志记录），因为我不想看到太多细节，这些细节通常在调试/开发过程中很有帮助。
基于这个question，我觉得行不通。尝试使用logging.properties file example 描述的所需级别更改您的属性文件。它将覆盖全局属性。

【解决方案2】：

我认为你找错地方了；这些消息不是来自 apache commons net 库。

我认为它们来自您在第一行中看到的IBMJSSEProvider2。根据这个link，您应该能够通过not 设置系统属性javax.net.debug 来禁用它们，或者使用os400 重定向它们。 stdout 和 os400.stderr 属性。

【讨论】：

太棒了！这正是我想要的。我的代码System.setProperty("javax.net.debug", "ssl"); 中有类似的内容，我将其修改为System.setProperty("javax.net.debug", "false");。这大大减少了日志记录，非常感谢。

【解决方案3】：

嗯，我在 Spring、Quartz、Hibernate 等方面也遇到过同样的问题。API 和框架会产生大量日志。

我根据每个包为每个 API 设置自定义级别。

logger.org.spring = 警告
logger.org.hibernate = 调试
logger.org.quartz = 信息
logger.com.myApp = 调试

当然，这不是完整的属性集，但你明白了。您可以使用包名称 - org.apache.commons 并为该包分配日志级别。请注意：该包级别下任何类的任何日志都将配置为与此相同的级别。

我使用 slf4j 而不是 log4j (http://www.slf4j.org/)，而不是 util logger。但我敢肯定，在你的情况下，修复可能会有点扭曲。如果我可能有点大胆，我建议使用 SLF4J。 HTH。

【讨论】：

【解决方案4】：

预计apache-commons-net 日志记录使用commons-logging 或SLF4J - 在没有任何其他控制因素的情况下，这些应该将日志记录路由到java.util.logging。

这里的最终答案是，如果您看到混合在输出文件（而不是控制台）中的日志，那么它们很可能是通过通用记录器路由的。并且java.lang.logging 在这里工作，所以让我们尝试配置。

配置java.util.logging：

创建您的日志记录属性文件，例如myLog.properties，并为不同的包自定义级别。例如，为讨厌的包com.mff.ftps设置一个比INFO更高的级别——比如SEVERE——：

# handlers=java.util.logging.ConsoleHandler, java.util.logging.FileHandler
handlers=java.util.logging.FileHandler

# Set ROOT logger level
.level=INFO
com.mff.ftps.level=SEVERE
# Set any number specifications: <package.path>.level=<LOGLEVEL>

java.util.logging.ConsoleHandler.level=WARNING
java.util.logging.ConsoleHandler.formatter=java.util.logging.SimpleFormatter

java.util.logging.FileHandler.level=FINEST
java.util.logging.FileHandler.pattern=myLogFile.log
java.util.logging.FileHandler.limit=1073741824  # 1MB
java.util.logging.FileHandler.count=2
java.util.logging.FileHandler.formatter=java.util.logging.SimpleFormatter

启动java时，指定日志属性文件：

java -Djava.util.logging.config.file=<pathTo>/myLog.properties -cp ...

或者写代码：

File logPropFile = new File("<pathTo>/myLog.properties");
InputStream logPropStream = new FileInputStream(logPropFile);
try {
    LogManager.getLogManager().readConfiguration(logPropStream);
}
finally {
    logPropStream.close();
}

【讨论】：

谢谢，但解决方案是设置javax.net.debug。