aboutsummaryrefslogtreecommitdiffstats
path: root/vespalog/src/test/java/com/yahoo/log/VespaFormatterTestCase.java
blob: 5a8170d020b3b3602f1ac349e1a23b8289dc3eb6 (plain) (blame)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
// Copyright Vespa.ai. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root.
package com.yahoo.log;

import com.yahoo.log.impl.LogUtils;

import org.junit.Before;
import org.junit.Ignore;
import org.junit.Test;

import java.time.Instant;
import java.util.logging.Level;
import java.util.logging.LogRecord;

import static org.junit.Assert.assertEquals;
import static org.junit.Assert.assertNotNull;
import static org.junit.Assert.assertTrue;
import static org.junit.Assert.fail;

/**
 * @author  Bjorn Borud
 */
@SuppressWarnings({"deprecation", "removal"})
public class VespaFormatterTestCase {

    private String hostname;
    private String pid;
    private String serviceName = "serviceName";
    private String app = "tst";
    private LogRecord testRecord1;
    private LogRecord testRecord2;
    private String expected1;
    private String expected2;
    private String expected3;
    private String expected4;


    @Before
    public void setUp () {
        hostname = LogUtils.getHostName();
        pid = LogUtils.getPID();

        testRecord1 = new LogRecord(Level.INFO, "this is a test");
        testRecord1.setInstant(Instant.ofEpochMilli(1098709021843L));
        testRecord1.setLongThreadID(123L);

        expected1 = "1098709021.843000\t"
            + hostname + "\t"
            + pid
            + "/123" + "\t"
            + "serviceName\t"
            + "tst\t"
            + "info\t"
            + "this is a test\n";

        expected2 = "1098709021.843000\t"
            + hostname + "\t"
            + pid
            + "/123" + "\t"
            + "serviceName\t"
            + "-\t"
            + "info\t"
            + "this is a test\n";


        testRecord2 = new LogRecord(Level.INFO, "this is a test");
        testRecord2.setInstant(Instant.ofEpochMilli(1098709021843L));
        testRecord2.setLongThreadID(123L);
        testRecord2.setLoggerName("org.foo");

        expected3 = "1098709021.843000\t"
            + hostname + "\t"
            + pid
            + "/123" + "\t"
            + "serviceName\t"
            + ".org.foo\t"
            + "info\t"
            + "this is a test\n";

        expected4 = "1098709021.843000\t"
            + hostname + "\t"
            + pid
            + "/123" + "\t"
            + "serviceName\t"
            + "tst.org.foo\t"
            + "info\t"
            + "this is a test\n";
    }

    /**
     * Just make sure that the messages are parsed as expected.
     */
    @Test
    public void testFormatting () {
        VespaFormatter formatter = new VespaFormatter(serviceName, app);
        assertEquals(expected1, formatter.format(testRecord1));
        assertEquals(expected4, formatter.format(testRecord2));

        VespaFormatter fmt2 = new VespaFormatter(serviceName, null);
        assertEquals(expected2, fmt2.format(testRecord1));
        assertEquals(expected3, fmt2.format(testRecord2));
    }


    /**
     * test that {0} etc is replaced properly
     */
    @Test
    public void testTextFormatting () {
        VespaFormatter formatter = new VespaFormatter(serviceName, app);

        LogRecord testRecord = new LogRecord(Level.INFO, "this {1} is {0} test");
        testRecord.setInstant(Instant.ofEpochMilli(1098709021843L));
        testRecord.setLongThreadID(123L);
        testRecord.setLoggerName("org.foo");
        Object[] params = { "a small", "message" };
        testRecord.setParameters(params);

        String expected = "1098709021.843000\t"
                          + hostname + "\t"
                          + pid
                          + "/123" + "\t"
                          + "serviceName\t"
                          + app
                          + ".org.foo\t"
                          + "info\t"
                          + "this message is a small test\n";

        assertEquals(expected, formatter.format(testRecord));
    }

    /**
     * Make sure that the LogMessage parser used in the log server is
     * able to parse these messages too.
     */
    @Test
    public void testParsing () {
        VespaFormatter formatter = new VespaFormatter(serviceName, app);
        LogMessage m;
        try {
            m = LogMessage.parseNativeFormat(expected1.trim());
            assertEquals("this is a test", m.getPayload());

            m = LogMessage.parseNativeFormat(formatter.format(testRecord1).trim());
            assertEquals("this is a test", m.getPayload());

            assertTrue(true);
        }
        catch (InvalidLogFormatException e) {
            System.out.println(e.toString());
            fail();
        }
    }

    /**
     * This method was used for testing the speed of the formatter.
     * We usually do not want to run this in normal testing, it was
     * just added when trying to analyze the abysmal performance of
     * double formatting.
     */
    @Test
    @Ignore
    public void testSpeed () {
        VespaFormatter formatter = new VespaFormatter(serviceName, app);
        int reps = 1000000;
        long start = System.currentTimeMillis();
        for (int i = 0; i < reps; i++) {
            formatter.format(testRecord1);
        }
        long diff = System.currentTimeMillis() - start;
        double dd = (reps / (double) diff);
        System.out.println("Took " + diff + " milliseconds, per ms=" + dd);
    }


    /** test backslash, newline and tab escaping.  one instance of each */
    @Test
    public void testEscaping () {
        String a = "This line contains a \\ backslash and \n newline and \t tab.";
        String b = "This line contains a \\\\ backslash and \\n newline and \\t tab.";
        assertEquals(b, VespaFormat.escape(a));
        assertEquals(a, VespaFormatter.unEscape(b));
    }

    /** test multiple instances of backslash */
    @Test
    public void testMultipleEscaping () {
        String a = "This line contains a \\ backslash and \\ more backslash.";
        String b = "This line contains a \\\\ backslash and \\\\ more backslash.";
        assertEquals(b, VespaFormat.escape(a));
        assertEquals(a, VespaFormatter.unEscape(b));
    }

    @Test
    public void testThrowable () {
        // VespaFormatter formatter = new VespaFormatter(serviceName, app);
        LogRecord r = new LogRecord(Level.INFO, "foo bar");
        r.setThrown(new IllegalStateException("this was fun"));
    }

    /**
     * Got a NullPointerException earlier when trying to format
     * a null message.  Added unit test to make sure this does
     * not happen again.  Makes sure that NullPointerException
     * is not thrown and that the formatted string contains the
     * expected message for saying that there was no log message.
     */
    @Test
    public void testNullMessage () {
        VespaFormatter formatter = new VespaFormatter(serviceName, app);
        LogRecord r = new LogRecord(LogLevel.ERROR, null);
        assertNotNull(r);
        try {
            String s = formatter.format(r);
            assertNotNull(s);
            assertTrue(s.indexOf("(empty)") > 0);
        }
        catch (NullPointerException e) {
            fail("unable to handle null message!");
        }
    }

    @Test
    public void testLowLogLevelExceptionFormatting () {
        VespaFormatter formatter = new VespaFormatter(serviceName, app);
        LogRecord r = new LogRecord(LogLevel.INFO, "meldingen her");
        r.setThrown(new IllegalStateException());
        String result = formatter.format(r);
        assertTrue(formatter.format(r).contains("meldingen her"));
    }

}