title: 坑爹的poi logging tags:
- poi
- springboot
- exception
- log
- poilogger categories: 工作日志 date: 2017-12-18 10:10:39
背景
随着系统的使用，大量的报表需求的迸发。对于导出excel的需求也进一步扩大。那么该类系统关于poi的相关错误自然也不能忽视！！！
问题
2017-12-06 20:53:08,516 [ERROR] [XNIO-2 task-25] c.f.r.c.WebMvcConfigurer:? 接口 [/report/item/listStatus.xls] 出现异常，方法：com.f6car.report.controller.item.ItemController.statusList，异常摘要：Fail to save: an error occurs while saving the package : The part /docProps/app.xml fail to be saved in the stream with marshaller org.apache.poi.openxml4j.opc.internal.marshallers.DefaultMarshaller@694aa17f
org.apache.poi.openxml4j.exceptions.OpenXML4JRuntimeException: Fail to save: an error occurs while saving the package : The part /docProps/app.xml fail to be saved in the stream with marshaller org.apache.poi.openxml4j.opc.internal.marshallers.DefaultMarshaller@694aa17f
at org.apache.poi.openxml4j.opc.ZipPackage.saveImpl(ZipPackage.java:602)
at org.apache.poi.openxml4j.opc.OPCPackage.save(OPCPackage.java:1557)
at org.apache.poi.POIXMLDocument.write(POIXMLDocument.java:248)
at com.f6car.report.web.converter.ExcelHttpMessageConverter.writeInternal(ExcelHttpMessageConverter.java:100)
at org.springframework.http.converter.AbstractHttpMessageConverter.write(AbstractHttpMessageConverter.java:227)
at com.f6car.report.web.converter.ExcelHttpMessageConverter.write(ExcelHttpMessageConverter.java:153)
at org.springframework.web.servlet.mvc.method.annotation.AbstractMessageConverterMethodProcessor.writeWithMessageConverters(AbstractMessageConverterMethodProcessor.java:231)
at org.springframework.web.servlet.mvc.method.annotation.RequestResponseBodyMethodProcessor.handleReturnValue(RequestResponseBodyMethodProcessor.java:174)
at org.springframework.web.method.support.HandlerMethodReturnValueHandlerComposite.handleReturnValue(HandlerMethodReturnValueHandlerComposite.java:81)
at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:113)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:827)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:738)
at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:967)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:901)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:970)
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:861)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:635)
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:846)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:742)
at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:85)
at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:129)
at org.springframework.boot.web.filter.ApplicationContextHeaderFilter.doFilterInternal(ApplicationContextHeaderFilter.java:55)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:61)
at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125)
at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
at org.apache.shiro.web.servlet.AbstractShiroFilter.executeChain(AbstractShiroFilter.java:449)
at org.apache.shiro.web.servlet.AbstractShiroFilter$1.call(AbstractShiroFilter.java:365)
at org.apache.shiro.subject.support.SubjectCallable.doCall(SubjectCallable.java:90)
at org.apache.shiro.subject.support.SubjectCallable.call(SubjectCallable.java:83)
at org.apache.shiro.subject.support.DelegatingSubject.execute(DelegatingSubject.java:383)
at org.apache.shiro.web.servlet.AbstractShiroFilter.doFilterInternal(AbstractShiroFilter.java:362)
at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125)
at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
at com.alibaba.druid.support.http.WebStatFilter.doFilter(WebStatFilter.java:123)
at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
at org.springframework.boot.actuate.trace.WebRequestTraceFilter.doFilterInternal(WebRequestTraceFilter.java:110)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
at org.springframework.web.filter.HttpPutFormContentFilter.doFilterInternal(HttpPutFormContentFilter.java:108)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:81)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:197)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
at org.springframework.boot.actuate.autoconfigure.MetricsFilter.doFilterInternal(MetricsFilter.java:106)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
at io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:84)
at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
at io.undertow.servlet.handlers.ServletChain$1.handleRequest(ServletChain.java:64)
at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:131)
at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
at io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:292)
at io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:81)
at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:138)
at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135)
at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272)
at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:104)
at io.undertow.server.Connectors.executeRootHandler(Connectors.java:332)
at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:812)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.poi.openxml4j.exceptions.OpenXML4JException: The part /docProps/app.xml fail to be saved in the stream with marshaller org.apache.poi.openxml4j.opc.internal.marshallers.DefaultMarshaller@694aa17f
at org.apache.poi.openxml4j.opc.ZipPackage.saveImpl(ZipPackage.java:590)
... 94 common frames omitted
复制代码某天收到报错如下 ，由于poi各种使用zip方式进行xlsx的输入输出。此处报错也略点莫名其妙
找到对应报错点
if (!defaultPartMarshaller.marshall(part, zos))
throw new OpenXML4JException(
"The part "
+ part.getPartName().getURI()
+ " fail to be saved in the stream with marshaller "
+ defaultPartMarshaller);
复制代码很明显defaultPartMarshaller为DefaultMarshaller 那么defaultPartMarshaller.marshall(part, zos)必然返回了false
那么继续寻找报错点 那么找到ZipPartMarshaller
public boolean marshall(PackagePart part, OutputStream os)
throws OpenXML4JException {
if (!(os instanceof ZipOutputStream)) {
logger.log(POILogger.ERROR,"Unexpected class " + os.getClass().getName());
throw new OpenXML4JException("ZipOutputStream expected !");
// Normally should happen only in developement phase, so just throw
// exception
}
// check if there is anything to save for some parts. We don't do this for all parts as some code
// might depend on empty parts being saved, e.g. some unit tests verify this currently.
if(part.getSize() == 0 && part.getPartName().getName().equals(XSSFRelation.SHARED_STRINGS.getDefaultFileName())) {
return true;
}
ZipOutputStream zos = (ZipOutputStream) os;
ZipEntry partEntry = new ZipEntry(ZipHelper
.getZipItemNameFromOPCName(part.getPartName().getURI()
.getPath()));
try {
// Create next zip entry
zos.putNextEntry(partEntry);
// Saving data in the ZIP file
InputStream ins = part.getInputStream();
byte[] buff = new byte[ZipHelper.READ_WRITE_FILE_BUFFER_SIZE];
while (ins.available() > 0) {
int resultRead = ins.read(buff);
if (resultRead == -1) {
// End of file reached
break;
}
zos.write(buff, 0, resultRead);
}
zos.closeEntry();
} catch (IOException ioe) {
logger.log(POILogger.ERROR,"Cannot write: " + part.getPartName() + ": in ZIP",
ioe);
return false;
}
// Saving relationship part
if (part.hasRelationships()) {
PackagePartName relationshipPartName = PackagingURIHelper
.getRelationshipPartName(part.getPartName());
marshallRelationshipPart(part.getRelationships(),
relationshipPartName, zos);
}
return true;
}
复制代码由上述推测必然是返回false而不是抛出异常 因此可以看到应当是捕获了IOException
那么上述logger为啥没有打出错误日志呢？
private static POILogger logger = POILogFactory.getLogger(ZipPartMarshaller.class);
复制代码poilogger通过POILogFactory获取
/**
* Get a logger, based on a String
*
* @param cat the String that defines the log
*
* @return a POILogger for the specified class
*/
public static POILogger getLogger(final String cat) {
// If we haven't found out what logger to use yet,
// then do so now
// Don't look it up until we're first asked, so
// that our users can set the system property
// between class loading and first use
if(_loggerClassName == null) {
try {
_loggerClassName = System.getProperty("org.apache.poi.util.POILogger");
} catch(Exception e) {
// ignore any exception here
}
// Use the default logger if none specified,
// or none could be fetched
if(_loggerClassName == null) {
_loggerClassName = _nullLogger.getClass().getName();
}
}
// Short circuit for the null logger, which
// ignores all categories
if(_loggerClassName.equals(_nullLogger.getClass().getName())) {
return _nullLogger;
}
// Fetch the right logger for them, creating
// it if that's required
POILogger logger = _loggers.get(cat);
if (logger == null) {
try {
@SuppressWarnings("unchecked")
Class<? extends POILogger> loggerClass =
(Class<? extends POILogger>) Class.forName(_loggerClassName);
logger = loggerClass.newInstance();
logger.initialize(cat);
} catch(Exception e) {
// Give up and use the null logger
logger = _nullLogger;
_loggerClassName = _nullLogger.getClass().getName();
}
// Save for next time
_loggers.put(cat, logger);
}
return logger;
}
}
复制代码很明显当org.apache.poi.util.POILogger未设置时 此时默认返回NullLogger
/**
* A logger class that strives to make it as easy as possible for
* developers to write log calls, while simultaneously making those
* calls as cheap as possible by performing lazy evaluation of the log
* message.<p>
*/
public class NullLogger extends POILogger {
@Override
public void initialize(final String cat) {
// do nothing
}
/**
* Log a message
*
* @param level One of DEBUG, INFO, WARN, ERROR, FATAL
* @param obj1 The object to log.
*/
@Override
public void log(final int level, final Object obj1) {
// do nothing
}
/**
* Log a message
*
* @param level One of DEBUG, INFO, WARN, ERROR, FATAL
* @param obj1 The object to log. This is converted to a string.
* @param exception An exception to be logged
*/
@Override
public void log(int level, Object obj1, final Throwable exception) {
// do nothing
}
/**
* Check if a logger is enabled to log at the specified level
*
* @param level One of DEBUG, INFO, WARN, ERROR, FATAL
*/
@Override
public boolean check(final int level) {
return false;
}
}
复制代码该logger啥都不做 因此我们需要在系统启动时 设置property 为CommonsLogger
By default, logging is disabled in POI. Sometimes it might be useful to enable logging to see some debug messages printed out which can help in analyzing problems.
You can select the logging framework by setting the system property org.apache.poi.util.POILogger during application startup or by calling System.setProperty():
System.setProperty("org.apache.poi.util.POILogger", "org.apache.poi.util.CommonsLogger" ); 复制代码Note: You need to call setProperty() before any POI functionality is invoked as the logger is only initialized during startup.
Available logger implementations
The following logger implementations are provided by POI:
Class
Type
org.apache.poi.util.SystemOutLogger Sends log output to the system console org.apache.poi.util.NullLogger Default logger, does not log anything org.apache.poi.util.CommonsLogger Allows to use Apache Commons Logging for logging. This can use JDK1.4 logging, log4j, logkit, ... org.apache.poi.util.DummyPOILogger Simple logger which will keep all log-lines in memory for later analysis. Used primarily for testing. Note: this may cause a memory leak if used in production application!
知道原因了 ，我们因此将poi的logger默认打开
措施
- 可以在springboot启动时默认设置property
- 可以在参数中配置
我们此处选择方案2 十分简单 在对应的启动参数中增加
-Dorg.apache.poi.util.POILogger=org.apache.poi.util.CommonsLogger
复制代码
扫一扫
568
被折叠的 条评论
为什么被折叠?
到【灌水乐园】发言
