001    /*
002     * Licensed to the Apache Software Foundation (ASF) under one or more
003     * contributor license agreements. See the NOTICE file distributed with
004     * this work for additional information regarding copyright ownership.
005     * The ASF licenses this file to You under the Apache license, Version 2.0
006     * (the "License"); you may not use this file except in compliance with
007     * the License. You may obtain a copy of the License at
008     *
009     *      http://www.apache.org/licenses/LICENSE-2.0
010     *
011     * Unless required by applicable law or agreed to in writing, software
012     * distributed under the License is distributed on an "AS IS" BASIS,
013     * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
014     * See the license for the specific language governing permissions and
015     * limitations under the license.
016     */
017    
018    package org.apache.logging.log4j.perf.jmh;
019    
020    import java.nio.ByteBuffer;
021    import java.text.SimpleDateFormat;
022    import java.util.Calendar;
023    import java.util.Date;
024    import java.util.concurrent.TimeUnit;
025    
026    import org.apache.logging.log4j.core.util.Charsets;
027    import org.openjdk.jmh.annotations.BenchmarkMode;
028    import org.openjdk.jmh.annotations.GenerateMicroBenchmark;
029    import org.openjdk.jmh.annotations.Mode;
030    import org.openjdk.jmh.annotations.OutputTimeUnit;
031    import org.openjdk.jmh.annotations.Scope;
032    import org.openjdk.jmh.annotations.State;
033    
034    /**
035     * Tests performance of various time format implementation.
036     */
037    // ============================== HOW TO RUN THIS TEST: ====================================
038    //
039    // single thread:
040    // java -jar log4j-perf/target/microbenchmarks.jar ".*TimeFormat.*" -f 1 -wi 5 -i 5
041    //
042    // multiple threads (for example, 4 threads):
043    // java -jar log4j-perf/target/microbenchmarks.jar ".*TimeFormat.*" -f 1 -wi 5 -i 5 -t 4 -si true
044    //
045    // Usage help:
046    // java -jar log4j-perf/target/microbenchmarks.jar -help
047    //
048    @State(Scope.Thread)
049    public class TimeFormatBenchmark {
050    
051        SimpleDateFormat simpleDateFormat = new SimpleDateFormat("HH:mm:ss.SSS");
052        long midnightToday = 0;
053        long midnightTomorrow = 0;
054    
055        @State(Scope.Thread)
056        public static class BufferState {
057            ByteBuffer buffer = ByteBuffer.allocate(12);
058        }
059    
060        private long millisSinceMidnight(long now) {
061            if (now >= midnightTomorrow) {
062                midnightToday = calcMidnightMillis(0);
063                midnightTomorrow = calcMidnightMillis(1);
064            }
065            return now - midnightToday;
066        }
067    
068        private long calcMidnightMillis(int addDays) {
069            //Calendar cal = Calendar.getInstance(TimeZone.getTimeZone("UCT"));
070            Calendar cal = Calendar.getInstance();
071            cal.set(Calendar.HOUR_OF_DAY, 0);
072            cal.set(Calendar.MINUTE, 0);
073            cal.set(Calendar.SECOND, 0);
074            cal.set(Calendar.MILLISECOND, 0);
075            cal.add(Calendar.DATE, addDays);
076            return cal.getTimeInMillis();
077        }
078    
079        public static void main(String[] args) {
080            System.out.println(new TimeFormatBenchmark().customFastFormatString(new BufferState()));
081            System.out.println(new TimeFormatBenchmark().customFormatString(new BufferState()));
082        }
083    
084        @GenerateMicroBenchmark
085        @BenchmarkMode(Mode.SampleTime)
086        @OutputTimeUnit(TimeUnit.NANOSECONDS)
087        public void baseline() {
088        }
089    
090        @GenerateMicroBenchmark
091        @BenchmarkMode(Mode.SampleTime)
092        @OutputTimeUnit(TimeUnit.NANOSECONDS)
093        public String simpleDateFormatString() {
094            return simpleDateFormat.format(new Date());
095        }
096    
097        @GenerateMicroBenchmark
098        @BenchmarkMode(Mode.SampleTime)
099        @OutputTimeUnit(TimeUnit.NANOSECONDS)
100        public int simpleDateFormatBytes(BufferState state) {
101            String str = simpleDateFormat.format(new Date());
102            byte[] bytes = str.getBytes(Charsets.UTF_8);
103            state.buffer.clear();
104            state.buffer.put(bytes);
105            return state.buffer.position();
106        }
107    
108        @GenerateMicroBenchmark
109        @BenchmarkMode(Mode.SampleTime)
110        @OutputTimeUnit(TimeUnit.NANOSECONDS)
111        public String customFastFormatString(BufferState state) {
112            state.buffer.clear();
113            fastFormat(System.currentTimeMillis(), state.buffer);
114            return new String(state.buffer.array(), 0, state.buffer.position(), Charsets.UTF_8);
115        }
116    
117        @GenerateMicroBenchmark
118        @BenchmarkMode(Mode.SampleTime)
119        @OutputTimeUnit(TimeUnit.NANOSECONDS)
120        public int customFastFormatBytes(BufferState state) {
121            state.buffer.clear();
122            fastFormat(System.currentTimeMillis(), state.buffer);
123            return state.buffer.position();
124        }
125    
126        @GenerateMicroBenchmark
127        @BenchmarkMode(Mode.SampleTime)
128        @OutputTimeUnit(TimeUnit.NANOSECONDS)
129        public String customFormatString(BufferState state) {
130            state.buffer.clear();
131            format(System.currentTimeMillis(), state.buffer);
132            return new String(state.buffer.array(), 0, state.buffer.position(), Charsets.UTF_8);
133        }
134    
135        @GenerateMicroBenchmark
136        @BenchmarkMode(Mode.SampleTime)
137        @OutputTimeUnit(TimeUnit.NANOSECONDS)
138        public int customFormatBytes(BufferState state) {
139            state.buffer.clear();
140            format(System.currentTimeMillis(), state.buffer);
141            return state.buffer.position();
142        }
143    
144        public ByteBuffer fastFormat(long time, ByteBuffer buffer) {
145            // Calculate values by getting the ms values first and do then
146            // shave off the hour minute and second values with multiplications
147            // and bit shifts instead of simple but expensive divisions.
148    
149            // Get daytime in ms which does fit into an int
150            // int ms = (int) (time % 86400000);
151            int ms = (int) (millisSinceMidnight(time));
152    
153            // well ... it works
154            int hour = (int) (((ms >> 7) * 9773437L) >> 38);
155            ms -= 3600000 * hour;
156    
157            int minute = (int) (((ms >> 5) * 2290650L) >> 32);
158            ms -= 60000 * minute;
159    
160            int second = ((ms >> 3) * 67109) >> 23;
161            ms -= 1000 * second;
162    
163            // Hour
164            // 13/128 is nearly the same as /10 for values up to 65
165            int temp = (hour * 13) >> 7;
166            buffer.put((byte) (temp + '0'));
167    
168            // Do subtract to get remainder instead of doing % 10
169            buffer.put((byte) (hour - 10 * temp + '0'));
170            buffer.put((byte) ':');
171    
172            // Minute
173            // 13/128 is nearly the same as /10 for values up to 65
174            temp = (minute * 13) >> 7;
175            buffer.put((byte) (temp + '0'));
176    
177            // Do subtract to get remainder instead of doing % 10
178            buffer.put((byte) (minute - 10 * temp + '0'));
179            buffer.put((byte) ':');
180    
181            // Second
182            // 13/128 is nearly the same as /10 for values up to 65
183            temp = (second * 13) >> 7;
184            buffer.put((byte) (temp + '0'));
185            buffer.put((byte) (second - 10 * temp + '0'));
186            buffer.put((byte) '.');
187    
188            // Millisecond
189            // 41/4096 is nearly the same as /100
190            temp = (ms * 41) >> 12;
191            buffer.put((byte) (temp + '0'));
192    
193            ms -= 100 * temp;
194            temp = (ms * 205) >> 11; // 205/2048 is nearly the same as /10
195            buffer.put((byte) (temp + '0'));
196    
197            ms -= 10 * temp;
198            buffer.put((byte) (ms + '0'));
199            return buffer;
200        }
201    
202        public ByteBuffer format(long time, ByteBuffer buffer) {
203            // Calculate values by getting the ms values first and do then
204            // calculate the hour minute and second values divisions.
205    
206            // Get daytime in ms which does fit into an int
207            // int ms = (int) (time % 86400000);
208            int ms = (int) (millisSinceMidnight(time));
209    
210            int hours = ms / 3600000;
211            ms -= 3600000 * hours;
212            
213            int minutes = ms / 60000;
214            ms -= 60000 * minutes;
215    
216            int seconds = ms / 1000;
217            ms -= 1000 * seconds;
218    
219            // Hour
220            int temp = hours / 10;
221            buffer.put((byte) (temp + '0'));
222    
223            // Do subtract to get remainder instead of doing % 10
224            buffer.put((byte) (hours - 10 * temp + '0'));
225            buffer.put((byte) ':');
226    
227            // Minute
228            temp = minutes / 10;
229            buffer.put((byte) (temp + '0'));
230    
231            // Do subtract to get remainder instead of doing % 10
232            buffer.put((byte) (minutes - 10 * temp + '0'));
233            buffer.put((byte) ':');
234    
235            // Second
236            temp = seconds / 10;
237            buffer.put((byte) (temp + '0'));
238            buffer.put((byte) (seconds - 10 * temp + '0'));
239            buffer.put((byte) '.');
240    
241            // Millisecond
242            temp = ms / 100;
243            buffer.put((byte) (temp + '0'));
244    
245            ms -= 100 * temp;
246            temp = ms / 10;
247            buffer.put((byte) (temp + '0'));
248    
249            ms -= 10 * temp;
250            buffer.put((byte) (ms + '0'));
251            return buffer;
252        }
253    }