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   /***
137    * Constructor for DBReeceiverTest.
138    * @param arg0
139    */
140   public FullCycleDBTest(String arg0) {
141     super(arg0);
142   }
143 
144   
145   /***
146    * This test starts by writing a single event to a DB using DBAppender
147    * and then reads it back using DBReceiver.
148    * 
149    * DB related information is specified within the configuration files.
150    * @throws Exception
151    */
152   public void testSingleOutput()
153          throws Exception {
154     DOMConfigurator jc1 = new DOMConfigurator();
155     InputStream is = FullCycleDBTest.class.getResourceAsStream(appendConfigFile);
156     jc1.doConfigure(is, lrWrite);
157     is.close();
158   
159     long startTime = System.currentTimeMillis();
160     System.out.println("***startTime is  "+startTime);
161 
162     // Write out just one log message
163     Logger out = lrWrite.getLogger("testSingleOutput.out");
164     out.debug("some message"+startTime);
165 
166     VectorAppender witnessAppender = (VectorAppender) lrWrite.getRootLogger().getAppender("VECTOR");
167     witnessEvents = witnessAppender.getVector();
168     assertEquals(1, witnessEvents.size());    
169 
170     // We have to close all appenders before starting to read
171     lrWrite.shutdown();
172 
173     // now read it back
174     readBack(readConfigFile, startTime);
175 
176   }
177 
178   /***
179    * This test starts by writing a single event to a DB using DBAppender
180    * and then reads it back using DBReceiver.
181    * 
182    * The written event includes MDC and repository properties as well as
183    * exception info.
184    * 
185    * DB related information is specified within the configuration files.
186    * @throws Exception
187    */
188   public void testAllFields() throws IOException {
189     DOMConfigurator jc1 = new DOMConfigurator();
190     InputStream is = FullCycleDBTest.class.getResourceAsStream(appendConfigFile);
191     jc1.doConfigure(is, lrWrite);
192     is.close();
193   
194     long startTime = System.currentTimeMillis();
195     
196     // Write out just one log message
197     MDC.put("key1", "value1-"+startTime);
198     MDC.put("key2", "value2-"+startTime);
199     Map mdcMap = MDC.getContext();
200 //    LogLog.info("**********"+mdcMap.size());
201     
202     // Write out just one log message
203     Logger out = lrWrite.getLogger("out"+startTime);
204 
205     out.debug("some message"+startTime);
206     MDC.put("key3", "value2-"+startTime);
207     out.error("some error message"+startTime, new Exception("testing"));
208     
209     // we clear the MDC to avoid interference with the events read back from
210     // the db
211     MDC.remove("key1");
212     MDC.remove("key2");
213     MDC.remove("key3");
214 
215     VectorAppender witnessAppender = (VectorAppender) lrWrite.getRootLogger().getAppender("VECTOR");
216     witnessEvents = witnessAppender.getVector();
217     assertEquals(2, witnessEvents.size());    
218 
219     // We have to close all appenders just before starting to read
220     lrWrite.shutdown();
221     
222     readBack(readConfigFile, startTime);
223   }
224 
225 
226   void readBack(String configfile, long startTime) throws IOException {
227     DOMConfigurator jc2 = new DOMConfigurator();
228     InputStream is = FullCycleDBTest.class.getResourceAsStream(configfile);
229     jc2.doConfigure(is, lrRead);
230     is.close();
231     
232     // wait a little to allow events to be read
233     try { Thread.sleep(3100); } catch(Exception e) {}
234     VectorAppender va = (VectorAppender) lrRead.getRootLogger().getAppender("VECTOR");
235     Vector returnedEvents = getRelevantEventsFromVA(va, startTime);
236     
237     compareEvents(witnessEvents, returnedEvents);
238     
239   }
240   
241   void compareEvents(Vector l, Vector r) {
242     assertNotNull("left vector of events should not be null");
243     assertEquals(l.size(), r.size());
244     
245     for(int i = 0; i < r.size(); i++) {
246       LoggingEvent le = (LoggingEvent) l.get(i);
247       LoggingEvent re = (LoggingEvent) r.get(i);
248       assertEquals(le.getMessage(),        re.getMessage());
249       assertEquals(le.getLoggerName(),     re.getLoggerName());
250       assertEquals(le.getLevel(),          re.getLevel());
251       assertEquals(le.getThreadName(), re.getThreadName());
252       if(re.getTimeStamp() < le.getTimeStamp()) {
253         fail("Returned event cannot preceed witness timestamp");
254       }
255 
256       Map sourceMap = re.getProperties();
257       Map remap;
258       if (sourceMap == null) {
259           remap = new HashMap();
260       } else {
261           remap = new HashMap(sourceMap);
262           if (remap.containsKey(Constants.LOG4J_ID_KEY)) {
263               remap.remove(Constants.LOG4J_ID_KEY);
264           }
265       }
266       if(le.getProperties() == null || le.getProperties().size() == 0) {
267         if(remap.size() != 0) {
268           System.out.println("properties are "+remap);
269           fail("Returned event should have been empty");
270         }
271       } else {
272         assertEquals(le.getProperties(), remap);
273       }
274       comprareStringArrays( le.getThrowableStrRep(),  re.getThrowableStrRep());
275       compareLocationInfo(le, re);
276     } 
277   }
278   
279   void comprareStringArrays(String[] la, String[] ra) {
280     if((la == null) && (ra == null)) {
281       return;
282     }
283     assertEquals(la.length, ra.length);
284     for(int i = 0; i < la.length; i++) {
285       assertEquals(la[i], ra[i]);
286     }
287   }
288   
289   void compareLocationInfo(LoggingEvent l, LoggingEvent r) {
290     if(l.locationInformationExists()) {
291       assertEquals(l.getLocationInformation().fullInfo, r.getLocationInformation().fullInfo);
292     } else {
293       assertEquals(LocationInfo.NA_LOCATION_INFO, r.getLocationInformation());
294     }
295   }
296   
297   Vector getRelevantEventsFromVA(VectorAppender va, long startTime) {
298     assertNotNull(va);
299     Vector v = va.getVector();
300     Vector r = new Vector();
301     // remove all elements older than startTime
302     for(Iterator i = v.iterator(); i.hasNext(); ) {
303       LoggingEvent event = (LoggingEvent) i.next();  
304       if(startTime > event.getTimeStamp()) {
305         System.out.println("***Removing event with timestamp "+event.getTimeStamp());
306       } else {
307         System.out.println("***Keeping event with timestamo"+event.getTimeStamp());
308         r.add(event);
309       }
310     }
311     return r;
312   }
313 
314   void dump(Vector v) {
315     for(int i = 0; i < v.size(); i++) {
316       LoggingEvent le = (LoggingEvent) v.get(i);
317       System.out.println("---"+le.getLevel()+" "+le.getLoggerName()+" "+le.getMessage());
318     }
319   }
320   
321   public static Test XXsuite() {
322     TestSuite suite = new TestSuite();
323     suite.addTest(new FullCycleDBTest("testSingleOutput"));
324     suite.addTest(new FullCycleDBTest("testAllFields"));
325     return suite;
326   }
327 }