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 }