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