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 }