Moved string-formatting methods from Slog to Slogf.

Slog is a core class provided by frameworks.jar, and these new methods
were causing performance regressions, so they were moved to a
system_server only class.

Bug: 182476140
Bug: 183523451

Test: atest --rebuild-module-info FrameworksMockingServicesTests:SLogfTest

Change-Id: I98cbb122d5410b61812edc85162aa6b10b995fdc
This commit is contained in:
Felipe Leme
2021-04-01 23:32:53 -07:00
committed by Amith Yamasani
parent 82722a0423
commit fec71a7117
4 changed files with 651 additions and 0 deletions

View File

@@ -61,7 +61,10 @@ public final class Slog {
* of the objects for the {@code vargars}, which could affect garbage collection. So, if you're
* calling this method in a critical path, make sure to explicitly do the check before calling
* it.
*
* @deprecated use {@code com.android.server.utils.SLogF} instead.
*/
@Deprecated
public static void v(String tag, String format, @Nullable Object... args) {
if (!Log.isLoggable(tag, Log.VERBOSE)) return;
@@ -87,7 +90,10 @@ public final class Slog {
* of the objects for the {@code vargars}, which could affect garbage collection. So, if you're
* calling this method in a critical path, make sure to explicitly do the check before calling
* it.
*
* @deprecated use {@code com.android.server.utils.SLogF} instead.
*/
@Deprecated
public static void d(String tag, String format, @Nullable Object... args) {
if (!Log.isLoggable(tag, Log.DEBUG)) return;
@@ -112,7 +118,10 @@ public final class Slog {
* of the objects for the {@code vargars}, which could affect garbage collection. So, if you're
* calling this method in a critical path, make sure to explicitly do the check before calling
* it.
*
* @deprecated use {@code com.android.server.utils.SLogF} instead.
*/
@Deprecated
public static void i(String tag, String format, @Nullable Object... args) {
if (!Log.isLoggable(tag, Log.INFO)) return;
@@ -142,7 +151,10 @@ public final class Slog {
* of the objects for the {@code vargars}, which could affect garbage collection. So, if you're
* calling this method in a critical path, make sure to explicitly do the check before calling
* it.
*
* @deprecated use {@code com.android.server.utils.SLogF} instead.
*/
@Deprecated
public static void w(String tag, String format, @Nullable Object... args) {
if (!Log.isLoggable(tag, Log.WARN)) return;
@@ -157,7 +169,10 @@ public final class Slog {
* of the objects for the {@code vargars}, which could affect garbage collection. So, if you're
* calling this method in a critical path, make sure to explicitly do the check before calling
* it.
*
* @deprecated use {@code com.android.server.utils.SLogF} instead.
*/
@Deprecated
public static void w(String tag, Exception exception, String format, @Nullable Object... args) {
if (!Log.isLoggable(tag, Log.WARN)) return;
@@ -183,7 +198,10 @@ public final class Slog {
* of the objects for the {@code vargars}, which could affect garbage collection. So, if you're
* calling this method in a critical path, make sure to explicitly do the check before calling
* it.
*
* @deprecated use {@code com.android.server.utils.SLogF} instead.
*/
@Deprecated
public static void e(String tag, String format, @Nullable Object... args) {
if (!Log.isLoggable(tag, Log.ERROR)) return;
@@ -198,7 +216,10 @@ public final class Slog {
* of the objects for the {@code vargars}, which could affect garbage collection. So, if you're
* calling this method in a critical path, make sure to explicitly do the check before calling
* it.
*
* @deprecated use {@code com.android.server.utils.SLogF} instead.
*/
@Deprecated
public static void e(String tag, Exception exception, String format, @Nullable Object... args) {
if (!Log.isLoggable(tag, Log.ERROR)) return;
@@ -217,14 +238,20 @@ public final class Slog {
/**
* Logs a {@code wtf} message.
*
* @deprecated use {@code com.android.server.utils.SLogF} instead.
*/
@Deprecated
public static void wtf(String tag, String format, @Nullable Object... args) {
wtf(tag, getMessage(format, args));
}
/**
* Logs a {@code wtf} message with an exception.
*
* @deprecated use {@code com.android.server.utils.SLogF} instead.
*/
@Deprecated
public static void wtf(String tag, Exception exception, String format,
@Nullable Object... args) {
wtf(tag, getMessage(format, args), exception);

View File

@@ -66,6 +66,11 @@ filegroup {
visibility: ["//visibility:private"],
}
java_library {
name: "Slogf",
srcs: ["core/java/com/android/server/utils/Slogf.java"],
}
// merge all required services into one jar
// ============================================================
java_library {

View File

@@ -0,0 +1,276 @@
/*
* Copyright (C) 2021 The Android Open Source Project
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package com.android.server.utils;
import android.annotation.Nullable;
import android.os.Trace;
import android.util.Log;
import android.util.Slog;
import android.util.TimingsTraceLog;
import com.android.internal.annotations.GuardedBy;
import java.util.Formatter;
import java.util.Locale;
/**
* Extends {@link Slog} by providing overloaded methods that take string formatting.
*
* <p><strong>Note: </strong>the overloaded methods won't create the formatted message if the
* respective logging level is disabled for the tag, but the compiler will still create an
* intermediate array of the objects for the {@code vargars}, which could affect garbage collection.
* So, if you're calling these method in a critical path, make sure to explicitly check for the
* level before calling them.
*/
public final class Slogf {
@GuardedBy("sMessageBuilder")
private static final StringBuilder sMessageBuilder;
@GuardedBy("sMessageBuilder")
private static final Formatter sFormatter;
static {
TimingsTraceLog t = new TimingsTraceLog("SLog", Trace.TRACE_TAG_SYSTEM_SERVER);
t.traceBegin("static_init");
sMessageBuilder = new StringBuilder();
sFormatter = new Formatter(sMessageBuilder, Locale.ENGLISH);
t.traceEnd();
}
private Slogf() {
throw new UnsupportedOperationException("provides only static methods");
}
/** Same as {@link Log#isLoggable(String, int)}. */
public static boolean isLoggable(String tag, int level) {
return Log.isLoggable(tag, level);
}
/** Same as {@link Slog#v(String, String)}. */
public static int v(String tag, String msg) {
return Slog.v(tag, msg);
}
/** Same as {@link Slog#v(String, String, Throwable)}. */
public static int v(String tag, String msg, Throwable tr) {
return Slog.v(tag, msg, tr);
}
/** Same as {@link Slog#d(String, String)}. */
public static int d(String tag, String msg) {
return Slog.d(tag, msg);
}
/** Same as {@link Slog#d(String, String, Throwable)}. */
public static int d(String tag, String msg, Throwable tr) {
return Slog.d(tag, msg, tr);
}
/** Same as {@link Slog#i(String, String)}. */
public static int i(String tag, String msg) {
return Slog.i(tag, msg);
}
/** Same as {@link Slog#i(String, String, Throwable)}. */
public static int i(String tag, String msg, Throwable tr) {
return Slog.i(tag, msg, tr);
}
/** Same as {@link Slog#w(String, String)}. */
public static int w(String tag, String msg) {
return Slog.w(tag, msg);
}
/** Same as {@link Slog#w(String, String, Throwable)}. */
public static int w(String tag, String msg, Throwable tr) {
return Slog.w(tag, msg, tr);
}
/** Same as {@link Slog#w(String, String)}. */
public static int w(String tag, Throwable tr) {
return Slog.w(tag, tr);
}
/** Same as {@link Slog#e(String, String)}. */
public static int e(String tag, String msg) {
return Slog.e(tag, msg);
}
/** Same as {@link Slog#e(String, String, Throwable)}. */
public static int e(String tag, String msg, Throwable tr) {
return Slog.e(tag, msg, tr);
}
/** Same as {@link Slog#wtf(String, String)}. */
public static int wtf(String tag, String msg) {
return Slog.wtf(tag, msg);
}
/** Same as {@link Slog#wtfQuiet(String, String)}. */
public static void wtfQuiet(String tag, String msg) {
Slog.wtfQuiet(tag, msg);
}
/** Same as {@link Slog#wtfStack(String, String). */
public static int wtfStack(String tag, String msg) {
return Slog.wtfStack(tag, msg);
}
/** Same as {@link Slog#wtf(String, Throwable). */
public static int wtf(String tag, Throwable tr) {
return Slog.wtf(tag, tr);
}
/** Same as {@link Slog#wtf(String, String, Throwable)}. */
public static int wtf(String tag, String msg, Throwable tr) {
return Slog.wtf(tag, msg, tr);
}
/** Same as {@link Slog#println(int, String, String)}. */
public static int println(int priority, String tag, String msg) {
return Slog.println(priority, tag, msg);
}
/**
* Logs a {@link Log.VERBOSE} message.
*
* <p><strong>Note: </strong>the message will only be formatted if {@link Log#VERBOSE} logging
* is enabled for the given {@code tag}, but the compiler will still create an intermediate
* array of the objects for the {@code vargars}, which could affect garbage collection. So, if
* you're calling this method in a critical path, make sure to explicitly do the check before
* calling it.
*/
public static void v(String tag, String format, @Nullable Object... args) {
if (!isLoggable(tag, Log.VERBOSE)) return;
v(tag, getMessage(format, args));
}
/**
* Logs a {@link Log.DEBUG} message.
*
* <p><strong>Note: </strong>the message will only be formatted if {@link Log#DEBUG} logging is
* enabled for the given {@code tag}, but the compiler will still create an intermediate array
* of the objects for the {@code vargars}, which could affect garbage collection. So, if you're
* calling this method in a critical path, make sure to explicitly do the check before calling
* it.
*/
public static void d(String tag, String format, @Nullable Object... args) {
if (!isLoggable(tag, Log.DEBUG)) return;
d(tag, getMessage(format, args));
}
/**
* Logs a {@link Log.INFO} message.
*
* <p><strong>Note: </strong>the message will only be formatted if {@link Log#INFO} logging is
* enabled for the given {@code tag}, but the compiler will still create an intermediate array
* of the objects for the {@code vargars}, which could affect garbage collection. So, if you're
* calling this method in a critical path, make sure to explicitly do the check before calling
* it.
*/
public static void i(String tag, String format, @Nullable Object... args) {
if (!isLoggable(tag, Log.INFO)) return;
i(tag, getMessage(format, args));
}
/**
* Logs a {@link Log.WARN} message.
*
* <p><strong>Note: </strong>the message will only be formatted if {@link Log#WARN} logging is
* enabled for the given {@code tag}, but the compiler will still create an intermediate array
* of the objects for the {@code vargars}, which could affect garbage collection. So, if you're
* calling this method in a critical path, make sure to explicitly do the check before calling
* it.
*/
public static void w(String tag, String format, @Nullable Object... args) {
if (!isLoggable(tag, Log.WARN)) return;
w(tag, getMessage(format, args));
}
/**
* Logs a {@link Log.WARN} message with an exception
*
* <p><strong>Note: </strong>the message will only be formatted if {@link Log#WARN} logging is
* enabled for the given {@code tag}, but the compiler will still create an intermediate array
* of the objects for the {@code vargars}, which could affect garbage collection. So, if you're
* calling this method in a critical path, make sure to explicitly do the check before calling
* it.
*/
public static void w(String tag, Exception exception, String format, @Nullable Object... args) {
if (!isLoggable(tag, Log.WARN)) return;
w(tag, getMessage(format, args), exception);
}
/**
* Logs a {@link Log.ERROR} message.
*
* <p><strong>Note: </strong>the message will only be formatted if {@link Log#ERROR} logging is
* enabled for the given {@code tag}, but the compiler will still create an intermediate array
* of the objects for the {@code vargars}, which could affect garbage collection. So, if you're
* calling this method in a critical path, make sure to explicitly do the check before calling
* it.
*/
public static void e(String tag, String format, @Nullable Object... args) {
if (!isLoggable(tag, Log.ERROR)) return;
e(tag, getMessage(format, args));
}
/**
* Logs a {@link Log.ERROR} message with an exception
*
* <p><strong>Note: </strong>the message will only be formatted if {@link Log#ERROR} logging is
* enabled for the given {@code tag}, but the compiler will still create an intermediate array
* of the objects for the {@code vargars}, which could affect garbage collection. So, if you're
* calling this method in a critical path, make sure to explicitly do the check before calling
* it.
*/
public static void e(String tag, Exception exception, String format, @Nullable Object... args) {
if (!isLoggable(tag, Log.ERROR)) return;
e(tag, getMessage(format, args), exception);
}
/**
* Logs a {@code wtf} message.
*/
public static void wtf(String tag, String format, @Nullable Object... args) {
wtf(tag, getMessage(format, args));
}
/**
* Logs a {@code wtf} message with an exception.
*/
public static void wtf(String tag, Exception exception, String format,
@Nullable Object... args) {
wtf(tag, getMessage(format, args), exception);
}
private static String getMessage(String format, @Nullable Object... args) {
synchronized (sMessageBuilder) {
sFormatter.format(format, args);
String message = sMessageBuilder.toString();
sMessageBuilder.setLength(0);
return message;
}
}
}

View File

@@ -0,0 +1,343 @@
/*
* Copyright (C) 2021 The Android Open Source Project
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package com.android.server.utils;
import static com.android.dx.mockito.inline.extended.ExtendedMockito.doReturn;
import static com.android.dx.mockito.inline.extended.ExtendedMockito.mockitoSession;
import static com.android.dx.mockito.inline.extended.ExtendedMockito.verify;
import static com.google.common.truth.Truth.assertThat;
import static org.mockito.ArgumentMatchers.any;
import static org.mockito.ArgumentMatchers.eq;
import static org.mockito.Mockito.never;
import android.util.Log;
import android.util.Slog;
import org.junit.After;
import org.junit.Before;
import org.junit.Test;
import org.mockito.MockitoSession;
import org.mockito.quality.Strictness;
/**
* Run it as {@code atest FrameworksMockingServicesTests:SlogfTest}
*/
public final class SlogfTest {
private static final String TAG = SlogfTest.class.getSimpleName();
private MockitoSession mSession;
private final Exception mException = new Exception("D'OH!");
@Before
public void setup() {
mSession = mockitoSession()
.initMocks(this)
.mockStatic(Slog.class)
.spyStatic(Slogf.class) // for isLoggable only
.strictness(Strictness.LENIENT)
.startMocking();
}
@After
public void tearDown() {
if (mSession == null) {
Log.w(TAG, "finishSession(): no session");
} else {
mSession.finishMocking();
}
}
@Test
public void testIsLoggable() {
assertThat(Slogf.isLoggable(TAG, Log.VERBOSE)).isEqualTo(Log.isLoggable(TAG, Log.VERBOSE));
}
@Test
public void testV_msg() {
Slogf.v(TAG, "msg");
verify(()-> Slog.v(TAG, "msg"));
}
@Test
public void testV_msgAndException() {
Slogf.v(TAG, "msg", mException);
verify(()-> Slog.v(TAG, "msg", mException));
}
@Test
public void testV_msgFormatted_enabled() {
enableLogging(Log.VERBOSE);
Slogf.v(TAG, "msg in a %s", "bottle");
verify(()-> Slog.v(TAG, "msg in a bottle"));
}
@Test
public void testV_msgFormatted_disabled() {
disableLogging(Log.VERBOSE);
Slogf.v(TAG, "msg in a %s", "bottle");
verify(()-> Slog.v(eq(TAG), any()), never());
}
@Test
public void testD_msg() {
Slogf.d(TAG, "msg");
verify(()-> Slog.d(TAG, "msg"));
}
@Test
public void testD_msgAndException() {
Slogf.d(TAG, "msg", mException);
verify(()-> Slog.d(TAG, "msg", mException));
}
@Test
public void testD_msgFormatted_enabled() {
enableLogging(Log.DEBUG);
Slogf.d(TAG, "msg in a %s", "bottle");
verify(()-> Slog.d(TAG, "msg in a bottle"));
}
@Test
public void testD_msgFormatted_disabled() {
disableLogging(Log.DEBUG);
Slogf.d(TAG, "msg in a %s", "bottle");
verify(()-> Slog.d(eq(TAG), any()), never());
}
@Test
public void testI_msg() {
Slogf.i(TAG, "msg");
verify(()-> Slog.i(TAG, "msg"));
}
@Test
public void testI_msgAndException() {
Slogf.i(TAG, "msg", mException);
verify(()-> Slog.i(TAG, "msg", mException));
}
@Test
public void testI_msgFormatted_enabled() {
enableLogging(Log.INFO);
Slogf.i(TAG, "msg in a %s", "bottle");
verify(()-> Slog.i(TAG, "msg in a bottle"));
}
@Test
public void testI_msgFormatted_disabled() {
disableLogging(Log.INFO);
Slogf.i(TAG, "msg in a %s", "bottle");
verify(()-> Slog.i(eq(TAG), any()), never());
}
@Test
public void testW_msg() {
Slogf.w(TAG, "msg");
verify(()-> Slog.w(TAG, "msg"));
}
@Test
public void testW_msgAndException() {
Slogf.w(TAG, "msg", mException);
verify(()-> Slog.w(TAG, "msg", mException));
}
@Test
public void testW_exception() {
Slogf.w(TAG, mException);
verify(()-> Slog.w(TAG, mException));
}
@Test
public void testW_msgFormatted_enabled() {
enableLogging(Log.WARN);
Slogf.w(TAG, "msg in a %s", "bottle");
verify(()-> Slog.w(TAG, "msg in a bottle"));
}
@Test
public void testW_msgFormatted_disabled() {
disableLogging(Log.WARN);
Slogf.w(TAG, "msg in a %s", "bottle");
verify(()-> Slog.w(eq(TAG), any(String.class)), never());
}
@Test
public void testW_msgFormattedWithException_enabled() {
enableLogging(Log.WARN);
Slogf.w(TAG, mException, "msg in a %s", "bottle");
verify(()-> Slog.w(TAG, "msg in a bottle", mException));
}
@Test
public void testW_msgFormattedWithException_disabled() {
disableLogging(Log.WARN);
Slogf.w(TAG, "msg in a %s", "bottle");
verify(()-> Slog.w(eq(TAG), any(String.class), any(Throwable.class)), never());
}
@Test
public void testE_msg() {
Slogf.e(TAG, "msg");
verify(()-> Slog.e(TAG, "msg"));
}
@Test
public void testE_msgAndException() {
Slogf.e(TAG, "msg", mException);
verify(()-> Slog.e(TAG, "msg", mException));
}
@Test
public void testE_msgFormatted_enabled() {
enableLogging(Log.ERROR);
Slogf.e(TAG, "msg in a %s", "bottle");
verify(()-> Slog.e(TAG, "msg in a bottle"));
}
@Test
public void testE_msgFormatted_disabled() {
disableLogging(Log.ERROR);
Slogf.e(TAG, "msg in a %s", "bottle");
verify(()-> Slog.e(eq(TAG), any()), never());
}
@Test
public void testE_msgFormattedWithException_enabled() {
enableLogging(Log.ERROR);
Slogf.e(TAG, mException, "msg in a %s", "bottle");
verify(()-> Slog.e(TAG, "msg in a bottle", mException));
}
@Test
public void testE_msgFormattedWithException_disabled() {
disableLogging(Log.ERROR);
Slogf.e(TAG, "msg in a %s", "bottle");
verify(()-> Slog.e(eq(TAG), any(String.class), any(Throwable.class)), never());
}
@Test
public void testWtf_msg() {
Slogf.wtf(TAG, "msg");
verify(()-> Slog.wtf(TAG, "msg"));
}
@Test
public void testWtf_msgAndException() {
Slogf.wtf(TAG, "msg", mException);
verify(()-> Slog.wtf(TAG, "msg", mException));
}
@Test
public void testWtf_exception() {
Slogf.wtf(TAG, mException);
verify(()-> Slog.wtf(TAG, mException));
}
@Test
public void testWtf_msgFormatted() {
Slogf.wtf(TAG, "msg in a %s", "bottle");
verify(()-> Slog.wtf(TAG, "msg in a bottle"));
}
@Test
public void testWtfQuiet() {
Slogf.wtfQuiet(TAG, "msg");
verify(()-> Slog.wtfQuiet(TAG, "msg"));
}
@Test
public void testWtfStack() {
Slogf.wtfStack(TAG, "msg");
verify(()-> Slog.wtfStack(TAG, "msg"));
}
@Test
public void testPrintln() {
Slogf.println(42, TAG, "msg");
verify(()-> Slog.println(42, TAG, "msg"));
}
@Test
public void testWtf_msgFormattedWithException() {
Slogf.wtf(TAG, mException, "msg in a %s", "bottle");
verify(()-> Slog.wtf(TAG, "msg in a bottle", mException));
}
private void enableLogging(@Log.Level int level) {
setIsLogging(level, true);
}
private void disableLogging(@Log.Level int level) {
setIsLogging(level, false);
}
private void setIsLogging(@Log.Level int level, boolean value) {
doReturn(value).when(() -> Slogf.isLoggable(TAG, level));
}
}