[提问]JSP中使用Hibernate Filter时出现的一个问题！

在JSP中使用HibernateFilter来关闭Hibernate Session

HibernateFilter.java 代码如下：
[code:1]
public class HibernateFilter implements Filter  {
    private static Log log = LogFactory.getLog(HibernateFilter.class);

    public HibernateFilter() {

    }

    /**
     * init
     *
     * @param filterConfig FilterConfig
     * @throws ServletException
     * @todo Implement this javax.servlet.Filter method
     */
    public void init(FilterConfig filterConfig) throws ServletException {
    }


    /**
     * doFilter
     *
     * @param servletRequest  ServletRequest
     * @param servletResponse ServletResponse
     * @param filterChain     FilterChain
     * @throws IOException
     * @throws ServletException
     * @todo Implement this javax.servlet.Filter method
     */
    public void doFilter(ServletRequest servletRequest, ServletResponse servletResponse, FilterChain filterChain) throws IOException, ServletException {

        try {

            System.out.println("Hibernate Filter Begin!");

            filterChain.doFilter(servletRequest, servletResponse);
        } catch(Exception e){
            e.printStackTrace();
        } finally {
            try {
                HibernateUtil.closeSession();

                System.out.println("Hibernate Filer Page End! [Close Hibernate Session]");

            } catch (Exception exc) {
                log.error("Error closing hibernate session.", exc);
                exc.printStackTrace();
            }
        }
    }

    /**
     * destroy
     *
     * @todo Implement this javax.servlet.Filter method
     */
    public void destroy() {
    }
}
[/code:1]

web.xml 代码如下：
[code:1]
<?xml version="1.0" encoding="ISO-8859-1"?>

<!DOCTYPE web-app
    PUBLIC "-//Sun Microsystems, Inc.//DTD Web Application 2.3//EN"
    "http://java.sun.com/dtd/web-app_2_3.dtd">
<web-app>
<!-- Define servlet-mapped and path-mapped filters -->
    <filter>
        <filter-name>HibernateFilter</filter-name>
        <filter-class>org.earthnut.web.jsp.filter.HibernateFilter</filter-class>
    </filter>

    <filter-mapping>
        <filter-name>HibernateFilter</filter-name>
        <url-pattern>/admin/partyEducation/photo/*</url-pattern>
    </filter-mapping>
</web-app>
[/code:1]

当我访问 /admin/partyEducation/photo/ 　下的一个JSP页面时观察控制台输出如下：
[code:1]
Hibernate Filter Begin!
log4j:WARN No appenders could be found for logger (org.hibernate.cfg.Environment).
log4j:WARN Please initialize the log4j system properly.
Initializing c3p0 pool... com.mchange.v2.c3p0.PoolBackedDataSource@eafb71 [ connectionPoolDataSource -> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@1250ff2 [ acquireIncrement -> 1, acquireRetryAttempts -> 30, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 0, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, idleConnectionTestPeriod -> 0, initialPoolSize -> 5, maxIdleTime -> 1800, maxPoolSize -> 20, maxStatements -> 50, maxStatementsPerConnection -> 0, minPoolSize -> 5, nestedDataSource -> com.mchange.v2.c3p0.DriverManagerDataSource@2515 [ description -> null, driverClass -> null, factoryClassLocation -> null, jdbcUrl -> jdbc:mysql://localhost:3306/hdkwOA, properties -> {useUnicode=true, autoReconnect=true, user=******, password=******, characterEncoding=ISO8859_1} ] , preferredTestQuery -> null, propertyCycle -> 300, testConnectionOnCheckin -> false, testConnectionOnCheckout -> false, usesTraditionalReflectiveProxies -> false ] , factoryClassLocation -> null, numHelperThreads -> 3, poolOwnerIdentityToken -> eafb71 ]
Hibernate: select party_phot0_.sn as sn, party_phot0_.name as name0_, party_phot0_.description as descript3_0_, party_phot0_.publish_date as publish4_0_, party_phot0_.attach_url as attach5_0_, party_phot0_.filename as filename0_, party_phot0_.operator as operator0_, party_phot0_.view_flag as view8_0_, party_phot0_.type as type0_ from party_photo party_phot0_ order by party_phot0_.publish_date desc
Hibernate Filer Page End! [Close Hibernate Session]
Hibernate Filter Begin!
Hibernate Filer Page End! [Close Hibernate Session]
Hibernate Filter Begin!
Hibernate Filer Page End! [Close Hibernate Session]
Hibernate Filter Begin!
Hibernate Filer Page End! [Close Hibernate Session]
Hibernate Filter Begin!
Hibernate Filer Page End! [Close Hibernate Session]
Hibernate Filter Begin!
Hibernate Filer Page End! [Close Hibernate Session]
Hibernate Filter Begin!
Hibernate Filer Page End! [Close Hibernate Session]
Hibernate Filter Begin!
Hibernate Filer Page End! [Close Hibernate Session]
[/code:1]

不知是什么原因导致多次执行HibernateFilter的doFilter方法而多次输出了如下语句：
Hibernate Filter Begin!
Hibernate Filer Page End! [Close Hibernate Session]

？？？
多谢指教

你在filter中用log.info("******")，就不会出现在控制台。

to dengdyj:

感谢你的解答，我试了一下，确实是这样，调用log.info()方法则控制台没有任何输出．

但是我还是不清楚为什么我的程序中每一次JSP页面的交互doFilter方法会多次被调用！

在每次jsp调用时都会经过filter，它是对request，reponse的修改。

to dengdyj:

先前我没有接触过log4j，特意看了一下，如你说的log.info("****")没有输出是因为我的程序中没有提供log4j所需的属性文件，在我正确配置了log4j的属性文件（log4j.properties）之后，发现控制台同样会多次输出log4j的INFO ！

而我给出的程序中只有一次JSP调用，为什么会多次Filter呢？