Develop/spring-data

Spring Data JPA, Querydsl 로깅처리. p6spy pretty하게 설정하기

에디개발자 2020. 11. 13. 10:30
반응형

바로 여기로 오셨다면 이전 글을 참조해주세요. 왜 p6spy를 선택했는지와 분석하는 이유에 대해서 정리해놓았습니다.

이번 글에서는 p6spy를 사용하는데에 편리한 설정들이 뭐가 있는지 알아보는 과정과 적용하는 것까지 정리하겠습니다.

작성된 글의 소스 코드는 github에 올려두었습니다.

JPA, Querydsl 설정 방법은 아래 링크를 참조해주시면 됩니다!

 

JPA에 대해서 궁금하시면?

Querydsl에 대해서 궁금하시면?

나를 닮았다고 한다....

p6spy

분석하기 위해 github에서 클론을 받고 진행하였습니다. 

 

깃헙에 있는 README 내용 중 아래와 같은 부분이 있습니다.

p6spy는 spring-boot-data-source-decorator 중 1가지 입니다.

간략하게 설명이 잘되어있습니다. 대부분의 Connection, Statement, ResultSet 메소드 호출의 인터셉트를 포함하여 SQL 쿼리를 인터셉터한 후 로깅처리하는 기능입니다.

 

사용법

정말 간단하게 사용할 수 있습니다.

build.gradle에 아래 한줄을 추가해주면 됩니다. ( version은 맞춰서 기입해주세요. )

dependencies {
  
	...
  
    implementation 'com.github.gavlyukovskiy:p6spy-spring-boot-starter:1.6.2'

	...
    
}

 

어떻게 사용되는가?

p6spy 소스를 받아 분석을 해보았습니다.

먼저 P6SpyConfiguration.java를 살펴보겠습니다. 

전체 소스 보단 설정 세팅하는 메소드를 살펴보겠습니다.

@PostConstruct
public void init() {
    P6SpyProperties p6spy = dataSourceDecoratorProperties.getP6spy();
    initialP6SpyOptions = findDefinedOptions();
    String customModuleList = initialP6SpyOptions.get("modulelist");
    if (customModuleList != null) {
        log.info("P6Spy modulelist is overridden, some p6spy configuration features will not be applied");
    }
    else {
        List<String> moduleList = new ArrayList<>();
        // default factory, holds P6Spy configuration
        moduleList.add(P6SpyFactory.class.getName());
        if (p6spy.isEnableLogging()) {
            moduleList.add(P6LogFactory.class.getName());
        }
        System.setProperty("p6spy.config.modulelist", String.join(",", moduleList));
    }
    if (!initialP6SpyOptions.containsKey("logMessageFormat")) {
        if (p6spy.getLogFormat() != null) {
            System.setProperty("p6spy.config.logMessageFormat", "com.p6spy.engine.spy.appender.CustomLineFormat");
            System.setProperty("p6spy.config.customLogMessageFormat", p6spy.getLogFormat());
        }
        else if (p6spy.isMultiline()) {
            System.setProperty("p6spy.config.logMessageFormat", "com.p6spy.engine.spy.appender.MultiLineFormat");
        }
    }
    if (p6spy.isEnableLogging() && !initialP6SpyOptions.containsKey("appender")) {
        switch (p6spy.getLogging()) {
            case SYSOUT:
                System.setProperty("p6spy.config.appender", "com.p6spy.engine.spy.appender.StdoutLogger");
                break;
            case SLF4J:
                System.setProperty("p6spy.config.appender", "com.p6spy.engine.spy.appender.Slf4JLogger");
                break;
            case FILE:
                System.setProperty("p6spy.config.appender", "com.p6spy.engine.spy.appender.FileLogger");
                break;
            case CUSTOM:
                System.setProperty("p6spy.config.appender", p6spy.getCustomAppenderClass().getName());
                break;
        }
    }
    if (!initialP6SpyOptions.containsKey("logfile")) {
        System.setProperty("p6spy.config.logfile", p6spy.getLogFile());
    }
    if (p6spy.getLogFilter().getPattern() != null) {
        System.setProperty("p6spy.config.filter", "true");
        System.setProperty("p6spy.config.sqlexpression", p6spy.getLogFilter().getPattern().pattern());
    }
    // If factories were loaded before this method is initialized changing properties will not be applied
    // Changes done in this method could not override anything user specified, therefore it is safe to call reload
    P6ModuleManager.getInstance().reload();
}

init() 메소드에서  dataSourceDecoratorProperties.getP6spy()  설정값을 가져옵니다. 그리고 설정값을 System.property에 세팅하는 것을 볼 수 있습니다.

 

DataSourceDecoratorProperties.java

/*
 * Copyright 2017 the original author or authors.
 *
 * Licensed under the Apache License, Version 2.0 (the "License");
 * you may not use this file except in compliance with the License.
 * You may obtain a copy of the License at
 *
 *      http://www.apache.org/licenses/LICENSE-2.0
 *
 * Unless required by applicable law or agreed to in writing, software
 * distributed under the License is distributed on an "AS IS" BASIS,
 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
 * See the License for the specific language governing permissions and
 * limitations under the License.
 */

package com.github.gavlyukovskiy.boot.jdbc.decorator;

import com.github.gavlyukovskiy.boot.jdbc.decorator.dsproxy.DataSourceProxyProperties;
import com.github.gavlyukovskiy.boot.jdbc.decorator.flexypool.FlexyPoolProperties;
import com.github.gavlyukovskiy.boot.jdbc.decorator.p6spy.P6SpyProperties;
import com.github.gavlyukovskiy.cloud.sleuth.SleuthProperties;
import lombok.Getter;
import lombok.Setter;
import org.springframework.boot.context.properties.ConfigurationProperties;
import org.springframework.boot.context.properties.NestedConfigurationProperty;

import java.util.Collection;
import java.util.Collections;

/**
 * Properties for configuring proxy providers.
 *
 * @author Arthur Gavlyukovskiy
 */
@Getter
@Setter
@ConfigurationProperties(prefix = "decorator.datasource")
public class DataSourceDecoratorProperties {

    /**
     * Enables data source decorating.
     */
    private boolean enabled = true;
    /**
     * Beans that won't be decorated.
     */
    private Collection<String> excludeBeans = Collections.emptyList();

    @NestedConfigurationProperty
    private DataSourceProxyProperties datasourceProxy = new DataSourceProxyProperties();

    @NestedConfigurationProperty
    private P6SpyProperties p6spy = new P6SpyProperties();

    @NestedConfigurationProperty
    private FlexyPoolProperties flexyPool = new FlexyPoolProperties();

    @NestedConfigurationProperty
    private SleuthProperties sleuth = new SleuthProperties();
}

@ConfigurationProperties 를 사용해서 설정값을 가져옵니다. 

그러면 내가 p6spy를 사용하려는 프로젝트에서 build.gradle을 추가하고 application.yaml 에 관련 설정을 할때 아래와 같이 하면 됩니다.

 

application.yaml

...

decorator:
  datasource:
    p6spy:
      ...

 

P6SpyProperties.java

이 클래스파일에서 p6spy Default 설정값을 알 수 있습니다.

 

/*
 * Copyright 2017 the original author or authors.
 *
 * Licensed under the Apache License, Version 2.0 (the "License");
 * you may not use this file except in compliance with the License.
 * You may obtain a copy of the License at
 *
 *      http://www.apache.org/licenses/LICENSE-2.0
 *
 * Unless required by applicable law or agreed to in writing, software
 * distributed under the License is distributed on an "AS IS" BASIS,
 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
 * See the License for the specific language governing permissions and
 * limitations under the License.
 */

package com.github.gavlyukovskiy.boot.jdbc.decorator.p6spy;

import com.p6spy.engine.logging.P6LogFactory;
import com.p6spy.engine.spy.appender.FormattedLogger;
import lombok.Getter;
import lombok.Setter;

import java.util.regex.Pattern;

/**
 * Properties for configuring p6spy.
 *
 * @author Arthur Gavlyukovskiy
 */
@Getter
@Setter
public class P6SpyProperties {

    /**
     * Enables logging JDBC events.
     *
     * @see P6LogFactory
     */
    private boolean enableLogging = true;
    /**
     * Enables multiline output.
     */
    private boolean multiline = true;
    /**
     * Logging to use for logging queries.
     */
    private P6SpyLogging logging = P6SpyLogging.SLF4J;
    /**
     * Name of log file to use (only with logging=file).
     */
    private String logFile = "spy.log";
    /**
     * Custom log format.
     */
    private String logFormat;

    /**
     * Tracing related properties
     */
    private P6SpyTracing tracing = new P6SpyTracing();

    /**
     * Class file to use (only with logging=custom).
     * The class must implement {@link com.p6spy.engine.spy.appender.FormattedLogger}
     */
    private Class<? extends FormattedLogger> customAppenderClass;

    /**
     * Log filtering related properties.
     */
    private P6SpyLogFilter logFilter = new P6SpyLogFilter();

    public enum P6SpyLogging {
        SYSOUT,
        SLF4J,
        FILE,
        CUSTOM
    }

    @Getter
    @Setter
    public static class P6SpyTracing {
        /**
         * Report the effective sql string (with '?' replaced with real values) to tracing systems.
         * <p>
         * NOTE this setting does not affect the logging message.
         */
        private boolean includeParameterValues = true;
    }

    @Getter
    @Setter
    public static class P6SpyLogFilter {
        /**
         * Use regex pattern to filter log messages. Only matched messages will be logged.
         */
        private Pattern pattern;
    }
}

기본적으로 Slf4j를 사용하네요.

이 설정값들을 참조해서 프로젝트의 상황에 맞게 핸들링하면 되겠네요!

저는 이전글 ( jpa, querydsl 적용 시 로깅 비교. querydsl로 작성한 쿼리 DBMS에서 쉽게 돌리는 방법. 2탄! ) 에서 보신것처럼 쿼리가 한줄로 나오기때문에 가독성을 높이기 위해 설정을 해보겠습니다.

2020-11-11 15:30:13.781  INFO 79365 --- [           main] p6spy                                    : #1605076213781 | took 8ms | statement | connection 2| url jdbc:mysql://localhost:3306/testdb?useSSL=false&serverTimezone=UTC&characterEncoding=utf8
select store0_.id as col_0_0_, createPrefix(store0_.name) as col_1_0_, store0_.address as col_2_0_ from store store0_ where store0_.name=? limit ?
select store0_.id as col_0_0_, createPrefix(store0_.name) as col_1_0_, store0_.address as col_2_0_ from store store0_ where store0_.name='스토어6' limit 1;

 

다시 돌아가서 PsSpyConfiguration.java을 보시면 아래와 같은 코드가 보입니다.

여기를 보니 log의 format을 바꿀수 있을 것 같습니다. 

if (!initialP6SpyOptions.containsKey("logMessageFormat")) {
    if (p6spy.getLogFormat() != null) {
        System.setProperty("p6spy.config.logMessageFormat", "com.p6spy.engine.spy.appender.CustomLineFormat");
        System.setProperty("p6spy.config.customLogMessageFormat", p6spy.getLogFormat());
    }
    else if (p6spy.isMultiline()) {
        System.setProperty("p6spy.config.logMessageFormat", "com.p6spy.engine.spy.appender.MultiLineFormat");
    }
}

먼저 logformat의 기본값은 null이기 때문에 multiline()을 타겠군요.

MuliLineFormat.java 파일을 살펴보겠습니다.

 

/**
 * P6Spy
 *
 * Copyright (C) 2002 - 2020 P6Spy
 *
 * Licensed under the Apache License, Version 2.0 (the "License");
 * you may not use this file except in compliance with the License.
 * You may obtain a copy of the License at
 *
 *      http://www.apache.org/licenses/LICENSE-2.0
 *
 * Unless required by applicable law or agreed to in writing, software
 * distributed under the License is distributed on an "AS IS" BASIS,
 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
 * See the License for the specific language governing permissions and
 * limitations under the License.
 */
package com.p6spy.engine.spy.appender;

/**
 * @author Quinton McCombs 
 * @since 09/2013
 */
public class MultiLineFormat implements MessageFormattingStrategy {

  /**
   * Formats a log message for the logging module
   *
   * @param connectionId the id of the connection
   * @param now          the current ime expressing in milliseconds
   * @param elapsed      the time in milliseconds that the operation took to complete
   * @param category     the category of the operation
   * @param prepared     the SQL statement with all bind variables replaced with actual values
   * @param sql          the sql statement executed
   * @param url          the database url where the sql statement executed
   * @return the formatted log message
   */
  @Override
  public String formatMessage(final int connectionId, final String now, final long elapsed, final String category, final String prepared, final String sql, final String url) {
    return "#" + now + " | took " + elapsed + "ms | " + category + " | connection " + connectionId + "| url " + url + "\n" + prepared + "\n" + sql +";";
  }
}

 

formatMessage 부분에서 실제로 쿼리를 찍어주는 부분이 확인되었습니다. 

그럼 logFormat값을 넣어서 CustomLineFormat.java 파일을 타게 하면 되겠구나! 하고 소스를 봤는데 pretty하게 보여줄 수 있게 할 수 있는 구간이 없네요...

/**
 * P6Spy
 *
 * Copyright (C) 2002 - 2020 P6Spy
 *
 * Licensed under the Apache License, Version 2.0 (the "License");
 * you may not use this file except in compliance with the License.
 * You may obtain a copy of the License at
 *
 *      http://www.apache.org/licenses/LICENSE-2.0
 *
 * Unless required by applicable law or agreed to in writing, software
 * distributed under the License is distributed on an "AS IS" BASIS,
 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
 * See the License for the specific language governing permissions and
 * limitations under the License.
 */
package com.p6spy.engine.spy.appender;

import java.util.regex.Matcher;
import java.util.regex.Pattern;

import com.p6spy.engine.common.P6Util;
import com.p6spy.engine.spy.P6SpyOptions;

/**
 * @author Peter G. Horvath
 * @since 08/2017
 */
public class CustomLineFormat implements MessageFormattingStrategy {

  private static final MessageFormattingStrategy FALLBACK_FORMATTING_STRATEGY = new SingleLineFormat();

  public static final String CONNECTION_ID = "%(connectionId)";
  public static final String CURRENT_TIME = "%(currentTime)";
  public static final String EXECUTION_TIME = "%(executionTime)";
  public static final String CATEGORY = "%(category)";
  public static final String EFFECTIVE_SQL = "%(effectiveSql)";
  public static final String EFFECTIVE_SQL_SINGLELINE = "%(effectiveSqlSingleLine)";
  public static final String SQL = "%(sql)";
  public static final String SQL_SINGLE_LINE = "%(sqlSingleLine)";
  public static final String URL = "%(url)";

  /**
   * Formats a log message for the logging module
   *
   * @param connectionId the id of the connection
   * @param now          the current ime expressing in milliseconds
   * @param elapsed      the time in milliseconds that the operation took to complete
   * @param category     the category of the operation
   * @param prepared     the SQL statement with all bind variables replaced with actual values
   * @param sql          the sql statement executed
   * @param url          the database url where the sql statement executed
   * @return the formatted log message
   */
  @Override
  public String formatMessage(final int connectionId, final String now, final long elapsed, final String category, final String prepared, final String sql, final String url) {

    String customLogMessageFormat = P6SpyOptions.getActiveInstance().getCustomLogMessageFormat();

    if (customLogMessageFormat == null) {
      // Someone forgot to configure customLogMessageFormat: fall back to built-in
      return FALLBACK_FORMATTING_STRATEGY.formatMessage(connectionId, now, elapsed, category, prepared, sql, url);
    }

    return customLogMessageFormat
      .replaceAll(Pattern.quote(CONNECTION_ID), Integer.toString(connectionId))
      .replaceAll(Pattern.quote(CURRENT_TIME), now)
      .replaceAll(Pattern.quote(EXECUTION_TIME), Long.toString(elapsed))
      .replaceAll(Pattern.quote(CATEGORY), category)
      .replaceAll(Pattern.quote(EFFECTIVE_SQL), Matcher.quoteReplacement(prepared))
      .replaceAll(Pattern.quote(EFFECTIVE_SQL_SINGLELINE), Matcher.quoteReplacement(P6Util.singleLine(prepared)))
      .replaceAll(Pattern.quote(SQL), Matcher.quoteReplacement(sql))
      .replaceAll(Pattern.quote(SQL_SINGLE_LINE), Matcher.quoteReplacement(P6Util.singleLine(sql)))
      .replaceAll(Pattern.quote(URL), url);
  }
}

 

커스터마이징이 힘들어보여서 새로 만들었습니다.

P6spySqlFormatConfiguration.java 이라는 파일을 만들고 sql을 이쁘게 보일 수 있는 방법이 무엇인가 찾아보았습니다. ( 구글링

결론은 아래와 같습니다.

 

package com.example.querydsl.configuration;

import com.p6spy.engine.common.P6Util;
import com.p6spy.engine.logging.Category;
import com.p6spy.engine.spy.appender.MessageFormattingStrategy;
import org.hibernate.engine.jdbc.internal.FormatStyle;

import java.util.Locale;

public class P6spySqlFormatConfiguration implements MessageFormattingStrategy {
    @Override
    public String formatMessage(int connectionId, String now, long elapsed, String category, String prepared, String sql, String url) {
        sql = formatSql(category, sql);
        return now + "|" + elapsed + "ms|" + category + "|connection " + connectionId + "|" + P6Util.singleLine(prepared) + sql;
    }

    private String formatSql(String category,String sql) {
        if(sql ==null || sql.trim().equals("")) return sql;

        // Only format Statement, distinguish DDL And DML
        if (Category.STATEMENT.getName().equals(category)) {
            String tmpsql = sql.trim().toLowerCase(Locale.ROOT);
            if(tmpsql.startsWith("create") || tmpsql.startsWith("alter") || tmpsql.startsWith("comment")) {
                sql = FormatStyle.DDL.getFormatter().format(sql);
            }else {
                sql = FormatStyle.BASIC.getFormatter().format(sql);
            }
            sql = "|\nHeFormatSql(P6Spy sql,Hibernate format):"+ sql;
        }

        return sql;
    }
}

FormatStyle을 사용하여 sql문에 맞게 pretty하게 변경해줍니다.

 

그리고 실제 logMessageFormat에 적용하는 클래스도 생성해줍니다.

package com.example.querydsl.configuration;

import com.p6spy.engine.spy.P6SpyOptions;
import org.springframework.context.annotation.Configuration;

import javax.annotation.PostConstruct;

@Configuration
public class P6spyLogMessageFormatConfiguration {

    @PostConstruct
    public void setLogMessageFormat() {
        P6SpyOptions.getActiveInstance().setLogMessageFormat(P6spySqlFormatConfiguration.class.getName());
    }
}

 

그리고 결과를 확인해보면 Pretty하게 나타납니다 :) 

2020-11-13 09:07:45.008  INFO 96309 --- [           main] p6spy                                    : 1605226065006|10ms|statement|connection 2|select store0_.id as col_0_0_, createPrefix(store0_.name) as col_1_0_, store0_.address as col_2_0_ from store store0_ where store0_.name=? limit ?|
HeFormatSql(P6Spy sql,Hibernate format):
    select
        store0_.id as col_0_0_,
        createPrefix(store0_.name) as col_1_0_,
        store0_.address as col_2_0_ 
    from
        store store0_ 
    where
        store0_.name='스토어6' limit 1

 

 

 

 

 

 

 

 

 

 

 

 

 

 

 

 

 

반응형