View Javadoc

    1   /*
    2    * Licensed to the Apache Software Foundation (ASF) under one or more
    3    * contributor license agreements.  See the NOTICE file distributed with
    4    * this work for additional information regarding copyright ownership.
    5    * The ASF licenses this file to You under the Apache License, Version 2.0
    6    * (the "License"); you may not use this file except in compliance with
    7    * the License.  You may obtain a copy of the License at
    8    *
    9    *      http://www.apache.org/licenses/LICENSE-2.0
    10   *
    11   * Unless required by applicable law or agreed to in writing, software
    12   * distributed under the License is distributed on an "AS IS" BASIS,
    13   * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
    14   * See the License for the specific language governing permissions and
    15   * limitations under the License.
    16   */
    17  package org.apache.log4j.db;
    18
    19  import junit.framework.Test;
    20  import junit.framework.TestCase;
    21  import junit.framework.TestSuite;
    22  import org.apache.log4j.Hierarchy;
    23  import org.apache.log4j.Level;
    24  import org.apache.log4j.Logger;
    25  import org.apache.log4j.MDC;
    26  import org.apache.log4j.VectorAppender;
    27  import org.apache.log4j.LoggerRepositoryExImpl;
    28  import org.apache.log4j.helpers.Constants;
    29  import org.apache.log4j.xml.DOMConfigurator;
    30  import org.apache.log4j.spi.LocationInfo;
    31  import org.apache.log4j.spi.LoggingEvent;
    32  import org.apache.log4j.spi.RootLogger;
    33  import org.apache.log4j.spi.LoggerRepository;
    34
    35  import java.sql.Connection;
    36  import java.sql.DriverManager;
    37  import java.sql.SQLException;
    38  import java.sql.Statement;
    39  import java.util.Map;
    40  import java.util.Vector;
    41  import java.util.HashMap;
    42  import java.io.InputStream;
    43  import java.io.IOException;
    44
    45
    46  /**
    47   * This test case writes a few events into a databases and reads them
    48   * back comparing the event written and read back.
    49   *
    50   * <p>It relies heavily on the proper configuration of its environment
    51   * in joran config files as well system properties.
    52   * </p>
    53   *
    54   * <p>See also the Ant build file in the tests/ directory.</p>
    55   *
    56   * @author Ceki G&uuml;lc&uuml;
    57   */
    58  public class FullCycleDBTest
    59         extends TestCase {
    60
    61    Vector<LoggingEvent> witnessEvents;
    62    Hierarchy lrWrite;
    63    LoggerRepository lrRead;
    64    String appendConfigFile = null;
    65    String readConfigFile = null;
    66
    67
    68    /*
    69     * @see TestCase#setUp()
    70     */
    71    protected void setUp()
    72           throws Exception {
    73      super.setUp();
    74      appendConfigFile = "append-with-drivermanager1.xml";
    75      readConfigFile = "read-with-drivermanager1.xml";
    76
    77      witnessEvents = new Vector<LoggingEvent>();
    78      lrWrite = new Hierarchy(new RootLogger(Level.DEBUG));
    79      lrRead = new LoggerRepositoryExImpl(new Hierarchy(new RootLogger(Level.DEBUG)));
    80
    81
    82      //
    83      //   attempt to define tables in in-memory database
    84      //      will throw exception if already defined.
    85      //
    86          Class.forName("org.hsqldb.jdbcDriver");
    87        try (Connection connection = DriverManager.getConnection("jdbc:hsqldb:mem:testdb")) {
    88            Statement s = connection.createStatement();
    89            s.executeUpdate("CREATE TABLE logging_event " +
    90                    "( sequence_number   BIGINT NOT NULL, " +
    91                    " timestamp         BIGINT NOT NULL, " +
    92                    " rendered_message  LONGVARCHAR NOT NULL, " +
    93                    " logger_name       VARCHAR NOT NULL, " +
    94                    " level_string      VARCHAR NOT NULL, " +
    95                    " ndc               LONGVARCHAR, " +
    96                    " thread_name       VARCHAR, " +
    97                    " reference_flag    SMALLINT, " +
    98                    " caller_filename   VARCHAR, " +
    99                    " caller_class      VARCHAR, " +
    100                   " caller_method     VARCHAR, " +
    101                   " caller_line       CHAR(4), " +
    102                   " event_id          INT NOT NULL IDENTITY)");
    103           s.executeUpdate("CREATE TABLE logging_event_property " +
    104                   "( event_id	      INT NOT NULL, " +
    105                   " mapped_key        VARCHAR(254) NOT NULL, " +
    106                   " mapped_value      LONGVARCHAR, " +
    107                   " PRIMARY KEY(event_id, mapped_key), " +
    108                   " FOREIGN KEY (event_id) REFERENCES logging_event(event_id))");
    109           s.executeUpdate("CREATE TABLE logging_event_exception" +
    110                   "  ( event_id         INT NOT NULL, " +
    111                   "    i                SMALLINT NOT NULL," +
    112                   "    trace_line       VARCHAR NOT NULL," +
    113                   "    PRIMARY KEY(event_id, i)," +
    114                   "    FOREIGN KEY (event_id) REFERENCES logging_event(event_id))");
    115       } catch (SQLException ex) {
    116           String s = ex.toString();
    117       }
    118
    119   }
    120
    121
    122   /*
    123    * @see TestCase#tearDown()
    124    */
    125   protected void tearDown()
    126          throws Exception {
    127     super.tearDown();
    128     lrRead.shutdown();
    129     witnessEvents = null;
    130   }
    131
    132   public FullCycleDBTest(String arg0) {
    133     super(arg0);
    134   }
    135
    136
    137   /**
    138    * This test starts by writing a single event to a DB using DBAppender
    139    * and then reads it back using DBReceiver.
    140    *
    141    * DB related information is specified within the configuration files.
    142    * @throws Exception on error
    143    */
    144   public void testSingleOutput()
    145          throws Exception {
    146     DOMConfigurator jc1 = new DOMConfigurator();
    147     InputStream is = FullCycleDBTest.class.getResourceAsStream(appendConfigFile);
    148     jc1.doConfigure(is, lrWrite);
    149     is.close();
    150
    151     long startTime = System.currentTimeMillis();
    152     System.out.println("***startTime is  "+startTime);
    153
    154     // Write out just one log message
    155     Logger out = lrWrite.getLogger("testSingleOutput.out");
    156     out.debug("some message"+startTime);
    157
    158     VectorAppender witnessAppender = (VectorAppender) lrWrite.getRootLogger().getAppender("VECTOR");
    159     witnessEvents = witnessAppender.getVector();
    160     assertEquals(1, witnessEvents.size());
    161
    162     // We have to close all appenders before starting to read
    163     lrWrite.shutdown();
    164
    165     // now read it back
    166     readBack(readConfigFile, startTime);
    167
    168   }
    169
    170   /**
    171    * This test starts by writing a single event to a DB using DBAppender
    172    * and then reads it back using DBReceiver.
    173    *
    174    * The written event includes MDC and repository properties as well as
    175    * exception info.
    176    *
    177    * DB related information is specified within the configuration files.
    178    * @throws IOException on error
    179    */
    180   public void testAllFields() throws IOException {
    181     DOMConfigurator jc1 = new DOMConfigurator();
    182     InputStream is = FullCycleDBTest.class.getResourceAsStream(appendConfigFile);
    183     jc1.doConfigure(is, lrWrite);
    184     is.close();
    185
    186     long startTime = System.currentTimeMillis();
    187
    188     // Write out just one log message
    189     MDC.put("key1", "value1-"+startTime);
    190     MDC.put("key2", "value2-"+startTime);
    191     Map mdcMap = MDC.getContext();
    192 //    LogLog.info("**********"+mdcMap.size());
    193
    194     // Write out just one log message
    195     Logger out = lrWrite.getLogger("out"+startTime);
    196
    197     out.debug("some message"+startTime);
    198     MDC.put("key3", "value2-"+startTime);
    199     out.error("some error message"+startTime, new Exception("testing"));
    200
    201     // we clear the MDC to avoid interference with the events read back from
    202     // the db
    203     MDC.remove("key1");
    204     MDC.remove("key2");
    205     MDC.remove("key3");
    206
    207     VectorAppender witnessAppender = (VectorAppender) lrWrite.getRootLogger().getAppender("VECTOR");
    208     witnessEvents = witnessAppender.getVector();
    209     assertEquals(2, witnessEvents.size());
    210
    211     // We have to close all appenders just before starting to read
    212     lrWrite.shutdown();
    213
    214     readBack(readConfigFile, startTime);
    215   }
    216
    217
    218   void readBack(String configfile, long startTime) throws IOException {
    219     DOMConfigurator jc2 = new DOMConfigurator();
    220     InputStream is = FullCycleDBTest.class.getResourceAsStream(configfile);
    221     jc2.doConfigure(is, lrRead);
    222     is.close();
    223
    224     // wait a little to allow events to be read
    225     try { Thread.sleep(3100); } catch(Exception e) {}
    226     VectorAppender va = (VectorAppender) lrRead.getRootLogger().getAppender("VECTOR");
    227     Vector<LoggingEvent> returnedEvents = getRelevantEventsFromVA(va, startTime);
    228
    229     compareEvents(witnessEvents, returnedEvents);
    230
    231   }
    232
    233   void compareEvents(Vector<LoggingEvent> l, Vector<LoggingEvent> r) {
    234     assertNotNull("left vector of events should not be null");
    235     assertEquals(l.size(), r.size());
    236
    237     for(int i = 0; i < r.size(); i++) {
    238       LoggingEvent le = l.get(i);
    239       LoggingEvent re = r.get(i);
    240       assertEquals(le.getMessage(),        re.getMessage());
    241       assertEquals(le.getLoggerName(),     re.getLoggerName());
    242       assertEquals(le.getLevel(),          re.getLevel());
    243       assertEquals(le.getThreadName(), re.getThreadName());
    244       if(re.getTimeStamp() < le.getTimeStamp()) {
    245         fail("Returned event cannot preceed witness timestamp");
    246       }
    247
    248       Map sourceMap = re.getProperties();
    249       Map remap;
    250       if (sourceMap == null) {
    251           remap = new HashMap();
    252       } else {
    253           remap = new HashMap(sourceMap);
    254           if (remap.containsKey(Constants.LOG4J_ID_KEY)) {
    255               remap.remove(Constants.LOG4J_ID_KEY);
    256           }
    257       }
    258       if(le.getProperties() == null || le.getProperties().size() == 0) {
    259         if(remap.size() != 0) {
    260           System.out.println("properties are "+remap);
    261           fail("Returned event should have been empty");
    262         }
    263       } else {
    264         assertEquals(le.getProperties(), remap);
    265       }
    266       comprareStringArrays( le.getThrowableStrRep(),  re.getThrowableStrRep());
    267       compareLocationInfo(le, re);
    268     }
    269   }
    270
    271   void comprareStringArrays(String[] la, String[] ra) {
    272     if((la == null) && (ra == null)) {
    273       return;
    274     }
    275     assertEquals(la.length, ra.length);
    276     for(int i = 0; i < la.length; i++) {
    277       assertEquals(la[i], ra[i]);
    278     }
    279   }
    280
    281   void compareLocationInfo(LoggingEvent l, LoggingEvent r) {
    282     if(l.locationInformationExists()) {
    283       assertEquals(l.getLocationInformation().fullInfo, r.getLocationInformation().fullInfo);
    284     } else {
    285       assertEquals(LocationInfo.NA_LOCATION_INFO, r.getLocationInformation());
    286     }
    287   }
    288
    289   Vector<LoggingEvent> getRelevantEventsFromVA(VectorAppender va, long startTime) {
    290     assertNotNull(va);
    291     Vector<LoggingEvent> v = va.getVector();
    292     Vector<LoggingEvent> r = new Vector<LoggingEvent>();
    293     // remove all elements older than startTime
    294       for (Object aV : v) {
    295           LoggingEvent event = (LoggingEvent) aV;
    296           if (startTime > event.getTimeStamp()) {
    297               System.out.println("***Removing event with timestamp " + event.getTimeStamp());
    298           } else {
    299               System.out.println("***Keeping event with timestamo" + event.getTimeStamp());
    300               r.add(event);
    301           }
    302       }
    303     return r;
    304   }
    305
    306   void dump(Vector v) {
    307       for (Object aV : v) {
    308           LoggingEvent le = (LoggingEvent) aV;
    309           System.out.println("---" + le.getLevel() + " " + le.getLoggerName() + " " + le.getMessage());
    310       }
    311   }
    312
    313   public static Test XXsuite() {
    314     TestSuite suite = new TestSuite();
    315     suite.addTest(new FullCycleDBTest("testSingleOutput"));
    316     suite.addTest(new FullCycleDBTest("testAllFields"));
    317     return suite;
    318   }
    319 }