springboot2+logback trampling trip to export logs to oracle Database

Posted by dumbass on Sun, 21 Jul 2019 04:57:50 +0200

background

According to my blogging practice, first explain the background. In the company's system, our configuration files are divided into several parts. Different configuration files have different configuration contents. For the output of logs, different environments need to make different outputs. This is a premise. This article will talk about the output of logs to oracle database is the output of sub-environments. Local test logs are very many, and services are often restarted, debugged, etc. Therefore, the logs of the local environment should not be exported to the database, while the online environment is different, the log output of the online environment is much less than that of the local environment, and the service is not restarted very often. Therefore, there are two points in this paper:

  • How to configure different profile s in the logback configuration file?
  • How to export the log to the database? What pits did this process encounter? How to solve it?

This article will be done in the following software versions. Whether there are differences between different versions has not been tested.

springboot v2.1.0
logback    v1.2.3
oracle     11.2
java       1.8.0_171

Different Environment Configuration of Logback

In China, what I don't know is Baidu. Of course, my first reaction is Baidu first. Sure enough, there are many solutions on the first page. However, through my practice, I have come up with the following useful solutions, which I ultimately adopt. If you see this, you can see. This article can be referred to directly.

There are many opinions on the internet, some of which are files defining multiple logbacks, such as logback-dev.xml and logback-prod.xml, and so on. Then, in application.yml, different log configurations are selected according to different profiles.active s. But I haven't tested it yet. I'll focus on the following methods.

In the same logback configuration file, it can be distinguished according to different <spring Profile>, which can be similar to the following:

    <springProfile name="prod">
        <root level="INFO">
            <appender-ref ref="CONSOLE"/>
            <appender-ref ref="infoAppender"/>
            <appender-ref ref="errorAppender"/>
            <appender-ref ref="DbAppender"/>
        </root>
    </springProfile>
    <springProfile name="dev">
        <root level="INFO">
            <appender-ref ref="CONSOLE"/>
            <!--<appender-ref ref="infoAppender"/>-->
            <!--<appender-ref ref="errorAppender"/>-->
            <appender-ref ref="DbAppender"/>
        </root>
    </springProfile>

Different < spring Profile > tags are used to distinguish between different environments using those appender s, but this does not work when I configure them in the original logback.xml. Open the logback log and find the following error

21:35:42,913 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@64:32 - no applicable action for [springProfile], current ElementPath  is [[configuration][springProfile]]
21:35:42,913 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@65:28 - no applicable action for [root], current ElementPath  is [[configuration][springProfile][root]]
21:35:42,913 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@66:42 - no applicable action for [appender-ref], current ElementPath  is [[configuration][springProfile][root][appender-ref]]
21:35:42,914 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@67:47 - no applicable action for [appender-ref], current ElementPath  is [[configuration][springProfile][root][appender-ref]]
21:35:42,914 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@68:48 - no applicable action for [appender-ref], current ElementPath  is [[configuration][springProfile][root][appender-ref]]
21:35:42,914 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@69:45 - no applicable action for [appender-ref], current ElementPath  is [[configuration][springProfile][root][appender-ref]]
21:35:42,914 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@72:31 - no applicable action for [springProfile], current ElementPath  is [[configuration][springProfile]]
21:35:42,914 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@73:28 - no applicable action for [root], current ElementPath  is [[configuration][springProfile][root]]
21:35:42,914 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@74:42 - no applicable action for [appender-ref], current ElementPath  is [[configuration][springProfile][root][appender-ref]]
21:35:42,914 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@77:45 - no applicable action for [appender-ref], current ElementPath  is [[configuration][springProfile][root][appender-ref]]

The output of the log also follows the default output. Why? When I was puzzled, I suddenly had a brainstorm and began to knock on the blackboard below. Since it's Spring Profile, is it related to Spring? If spring context is not loaded, how do you know which profiles actually work?

To solve this problem, I try to replace logback.xml with logback-spring.xml, restart the application, and find that it can be passed.

logback.xml is loaded in spring boot before the spring context, so when loading the configuration file, it is not known which profile to use, that is to say, the tag < spring Profile > will not work at this stage. logback-spring.xml initializes the spring context first, when < spring Profile > takes effect

Logback outputs logs to the database

I use oracle database here, so make some brief explanations for oracle database, and point out the pits encountered.

Some friends may ask, I want to export the log to the database, then the database table I want to build? How about building it? The answer is no, logback official has to provide the corresponding sql script, directly find the corresponding database script to create it, otherwise you build your own table, logback does not know ah, right. logback database script

Here is the database script for oracle

CREATE SEQUENCE logging_event_id_seq MINVALUE 1 START WITH 1;

CREATE TABLE logging_event 
  (
    timestmp         NUMBER(20) NOT NULL,
    formatted_message  VARCHAR2(4000) NOT NULL,
    logger_name       VARCHAR(254) NOT NULL,
    level_string      VARCHAR(254) NOT NULL,
    thread_name       VARCHAR(254),
    reference_flag    SMALLINT,
    arg0              VARCHAR(254),
    arg1              VARCHAR(254),
    arg2              VARCHAR(254),
    arg3              VARCHAR(254),
    caller_filename   VARCHAR(254) NOT NULL,
    caller_class      VARCHAR(254) NOT NULL,
    caller_method     VARCHAR(254) NOT NULL,
    caller_line       CHAR(4) NOT NULL,
    event_id          NUMBER(10) PRIMARY KEY
  );


-- the / suffix may or may not be needed depending on your SQL Client
-- Some SQL Clients, e.g. SQuirrel SQL has trouble with the following
-- trigger creation command, while SQLPlus (the basic SQL Client which
-- ships with Oracle) has no trouble at all.

CREATE TRIGGER logging_event_id_seq_trig
  BEFORE INSERT ON logging_event
  FOR EACH ROW  
  BEGIN  
    SELECT logging_event_id_seq.NEXTVAL 
    INTO   :NEW.event_id 
    FROM   DUAL;  
  END;
/


CREATE TABLE logging_event_property
  (
    event_id	      NUMBER(10) NOT NULL,
    mapped_key        VARCHAR2(254) NOT NULL,
    mapped_value      VARCHAR2(1024),
    PRIMARY KEY(event_id, mapped_key),
    FOREIGN KEY (event_id) REFERENCES logging_event(event_id)
  );
  
CREATE TABLE logging_event_exception
  (
    event_id         NUMBER(10) NOT NULL,
    i                SMALLINT NOT NULL,
    trace_line       VARCHAR2(254) NOT NULL,--# Note here
    PRIMARY KEY(event_id, i),
    FOREIGN KEY (event_id) REFERENCES logging_event(event_id)
  );

The above script will not be a big problem in general, but note that the trace_line field of the log_event_exception table defines 254 lengths. This field is mainly used to record exception stacks. A stack corresponds to a record. Sometimes the stack information is far more than 254. Character, therefore, this length will cause an error that is not long enough. In view of this situation, 1024 lengths are recommended.

Some package name class names are longer stacks, how can it be only 254 lengths?

After creating the data table, the next step is to configure logback-spring.xml. In order to improve the performance, the database connection pool is used. Because the druid is used in the project, the database connection pool in the project is used. After some searching, I got a lot of configuration like the following, uh, uh, uh, uh, uh, uh, uh, uh, uh, uh, uh, uh, uh, uh, uh, uh, uh, uh.

From the above configuration, it is not difficult to see that the configuration of the c3p0 database connection and database dialect, it seems that there is no problem, try it, copy and paste directly into their own configuration files, run ^^ seems not to work! Looking at it carefully again, there seems to be no mistake. It's just that C3P0 has been replaced by Druid.

 <appender name="DbAppender" class="ch.qos.logback.classic.db.DBAppender">
        <connectionSource class="ch.qos.logback.core.db.DataSourceConnectionSource">
            <dataSource class="com.alibaba.druid.pool.DruidDataSource">
                <driverClass>oracle.jdbc.OracleDriver</driverClass>
                <user>username</user>
                <password>pass</password>
                <url>jdbc:oracle:thin:@ip:1521:orcl</url>
                <sqlDialect class="ch.qos.logback.core.db.dialect.OracleDialect"/>
            </dataSource>
        </connectionSource>
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>ERROR</level>
        </filter>
    </appender>

As a result, the report was wrong... Heart-broken

10:25:33,859 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@47:30 - no applicable action for [driverClass], current ElementPath  is [[configuration][appender][connectionSource][dataSource][driverClass]]
10:25:33,864 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@48:23 - no applicable action for [user], current ElementPath  is [[configuration][appender][connectionSource][dataSource][user]]
10:25:33,867 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@51:83 - no applicable action for [sqlDialect], current ElementPath  is [[configuration][appender][connectionSource][dataSource][sqlDialect]]

The main reason for error reporting is similar to the Spring Profile above, that is, there is no applicable action... Barbara, it's strange! The latter guess is that because the data source is specified, different data sources have different configurations? When the database connection pool is initialized, when the connection pool is constructed by reflection, no field with the corresponding name is found? So according to the configuration of druid, the following configuration is replaced

 <appender name="DbAppender" class="ch.qos.logback.classic.db.DBAppender">
        <connectionSource class="ch.qos.logback.core.db.DataSourceConnectionSource">
            <dataSource class="com.alibaba.druid.pool.DruidDataSource">
                <driverClassName>oracle.jdbc.OracleDriver</driverClassName>
                <username>username</username>
                <password>pass</password>
                <url>jdbc:oracle:thin:@ip:1521:orcl</url>
                <sqlDialect class="ch.qos.logback.core.db.dialect.OracleDialect"/>
            </dataSource>
        </connectionSource>
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>ERROR</level>
        </filter>
    </appender>

Re-run, although still unsuccessful this time, but the number of errors significantly reduced, only sqlDialect errors... Aha, it seems that the darkness before dawn has been discovered!

For different database connection pools, logback does not know the name of the internal configuration related to jdbc, so when using different database connection pools, configure the dataSource tag according to its internal name! According to this rule, other configurations of some databases, such as the maximum number of connections and the maximum number of free connections, should also be modifiable. I have not tested them.

After struggling for a period of time, I can't imagine why < SQL Dialect > will report an error. Is logback not supporting it? Or? It seems that only by exploring the source code can we know the truth. After looking at the source code of logback, I found out that the truth was finally found in a class called DBUtil!


public class DBUtil extends ContextAwareBase {
    private static final String POSTGRES_PART = "postgresql";
    private static final String MYSQL_PART = "mysql";
    private static final String ORACLE_PART = "oracle";
    // private static final String MSSQL_PART = "mssqlserver4";
    private static final String MSSQL_PART = "microsoft";
    private static final String HSQL_PART = "hsql";
    private static final String H2_PART = "h2";
    private static final String SYBASE_SQLANY_PART = "sql anywhere";
    private static final String SQLITE_PART = "sqlite";

    public static SQLDialectCode discoverSQLDialect(DatabaseMetaData meta) {
        SQLDialectCode dialectCode = SQLDialectCode.UNKNOWN_DIALECT;

        try {

            String dbName = meta.getDatabaseProductName().toLowerCase();

            if (dbName.indexOf(POSTGRES_PART) != -1) {
                return SQLDialectCode.POSTGRES_DIALECT;
            } else if (dbName.indexOf(MYSQL_PART) != -1) {
                return SQLDialectCode.MYSQL_DIALECT;
            } else if (dbName.indexOf(ORACLE_PART) != -1) {
                return SQLDialectCode.ORACLE_DIALECT;
            } else if (dbName.indexOf(MSSQL_PART) != -1) {
                return SQLDialectCode.MSSQL_DIALECT;
            } else if (dbName.indexOf(HSQL_PART) != -1) {
                return SQLDialectCode.HSQL_DIALECT;
            } else if (dbName.indexOf(H2_PART) != -1) {
                return SQLDialectCode.H2_DIALECT;
            } else if (dbName.indexOf(SYBASE_SQLANY_PART) != -1) {
                return SQLDialectCode.SYBASE_SQLANYWHERE_DIALECT;
            } else if (dbName.indexOf(SQLITE_PART) != -1) {
                return SQLDialectCode.SQLITE_DIALECT;
            } else {
                return SQLDialectCode.UNKNOWN_DIALECT;
            }
        } catch (SQLException sqle) {
            // we can't do much here
        }

        return dialectCode;
    }
    // The following code is omitted...
}

The original logback can get the DatabaseMetaData object according to the Connection, and then according to the meta to get which database product is in the end, thus automatically returning the corresponding dialect. In other words, we don't need to configure sqlDialect manually, but we can get it automatically. (Actually, according to jdbcurl, we all know what database it is.) So it's a bit of a snake to set up dialects in it.

Maybe the previous version of history needs to set dialect manually. In the current version, it should be improved. I have not compared the historical source code, just guess! Interested viewers can go to github to compare themselves.

Okay, here we are, the pit is over. Now we paste the appender configuration of logback+druid connection pool. For other database connection pools, I think if you look at the above, how should you configure to avoid falling into the pit?

     <appender name="DbAppender" class="ch.qos.logback.classic.db.DBAppender">
        <connectionSource class="ch.qos.logback.core.db.DataSourceConnectionSource">
            <dataSource class="com.alibaba.druid.pool.DruidDataSource">
                <driverClassName>oracle.jdbc.OracleDriver</driverClassName>
                <username>username</username>
                <password>pass</password>
                <url>jdbc:oracle:thin:@ip:1521:orcl</url>
            </dataSource>
        </connectionSource>
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>ERROR</level>
        </filter>
    </appender>

Topics: Programming Database Spring Oracle xml