Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

core: added changes to make service config more explicit by logging required info #11917

Open
wants to merge 7 commits into
base: master
Choose a base branch
from
Open

core: added changes to make service config more explicit by logging required info #11917

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
7 commits
Select commit Hold shift + click to select a range
0e425e2
core: added changes to make service config more explicit by logging r…
vinodhabib Feb 21, 2025
c976496
core: Fixed checkstyle violations not found in local build
vinodhabib Feb 21, 2025
a44c350
core: added UT for toString of InternalConfigSelector
vinodhabib Feb 24, 2025
18a69d5
core: added UT for toString of InternalConfigSelector
vinodhabib Feb 24, 2025
140e2f1
core: added UT for toString of ServiceConfigConvertedSelector
vinodhabib Feb 24, 2025
c9ee995
core: updated the variable name and logger message
vinodhabib Feb 25, 2025
e2b489a
core: modified the logger message along with UT changes.
vinodhabib Feb 25, 2025
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
14 changes: 11 additions & 3 deletions core/src/main/java/io/grpc/internal/ManagedChannelImpl.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -145,12 +145,17 @@ final class ManagedChannelImpl extends ManagedChannel implements

private static final ManagedChannelServiceConfig EMPTY_SERVICE_CONFIG =
ManagedChannelServiceConfig.empty();
private static final InternalConfigSelector INITIAL_PENDING_SELECTOR =
static final InternalConfigSelector INITIAL_PENDING_SELECTOR =
new InternalConfigSelector() {
@Override
public Result selectConfig(PickSubchannelArgs args) {
throw new IllegalStateException("Resolution is pending");
}

@Override
public String toString() {
return "Resolution is pending";
}
};
private static final LoadBalancer.PickDetailsConsumer NOOP_PICK_DETAILS_CONSUMER =
new LoadBalancer.PickDetailsConsumer() {};
Expand Down Expand Up @@ -931,9 +936,12 @@ public void run() {
}

// Must run in SynchronizationContext.
void updateConfigSelector(@Nullable InternalConfigSelector config) {
void updateConfigSelector(@Nullable InternalConfigSelector newConfig) {
InternalConfigSelector prevConfig = configSelector.get();
configSelector.set(config);
configSelector.set(newConfig);
channelLogger.log(ChannelLogLevel.INFO,
Copy link
Member

@shivaspeaks shivaspeaks Mar 3, 2025 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This could be right but this can also lead to spamming as config update can happen per RPC.

Perhaps we should discuss/ rethink on the requirement for this logging. Or maybe it will be better if we log only when default config is applied and expected retry config is not applied when retry is enabled and service config is present. And we also need to figure out how it will help the user, about why the given config was not applied! Logging that will be much better.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

gRPC does not log at a default-enabled log level (java.util.logging INFO or higher), unless SEVERE and there's no other way to handle it. However, here you're using the channel logger, which uses FINER java.util.logging level.

In general, I don't think typical logging is appropriate for this issue. (We can have some debug logging, but it'd be mostly for us; users would be unlikely to see it.) I think it'd be best to expose the current service config to channelz, although when I mentioned it to other TLs in the past it didn't gain traction. This "channel logger" does dump things in channelz when configured to do so, and then you can use grpcdebug to see the logs. Not the easiest, but could work. Importantly, we wouldn't want to log when the config is unchanged.

But overall, I think this issue needs a design before an implementation.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Perhaps we should discuss/ rethink on the requirement for this logging.

There was no such requirement of logging specifically.

"Current config is replaced with new config. prevConfig={0}, newConfig={1}",
prevConfig, newConfig);
if (prevConfig == INITIAL_PENDING_SELECTOR && pendingCalls != null) {
for (RealChannel.PendingCall<?, ?> pendingCall : pendingCalls) {
pendingCall.reprocess();
Expand Down
10 changes: 9 additions & 1 deletion core/src/main/java/io/grpc/internal/ManagedChannelServiceConfig.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -402,7 +402,7 @@ static final class ServiceConfigConvertedSelector extends InternalConfigSelector
final ManagedChannelServiceConfig config;

/** Converts the service config to config selector. */
private ServiceConfigConvertedSelector(ManagedChannelServiceConfig config) {
ServiceConfigConvertedSelector(ManagedChannelServiceConfig config) {
this.config = config;
}

Expand All @@ -412,5 +412,13 @@ public Result selectConfig(PickSubchannelArgs args) {
.setConfig(config)
.build();
}

@Override
public String toString() {
return "ServiceConfigConvertedSelector{"
+ "config="
+ config
+ '}';
}
}
}
42 changes: 28 additions & 14 deletions core/src/test/java/io/grpc/internal/ManagedChannelImplTest.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -85,6 +85,7 @@
import io.grpc.InternalChannelz;
import io.grpc.InternalChannelz.ChannelStats;
import io.grpc.InternalChannelz.ChannelTrace;
import io.grpc.InternalChannelz.ChannelTrace.Event;
import io.grpc.InternalChannelz.ChannelTrace.Event.Severity;
import io.grpc.InternalConfigSelector;
import io.grpc.InternalInstrumented;
Expand Down Expand Up @@ -1208,6 +1209,14 @@ public void addressResolutionError_noPriorNameResolution_usesDefaultServiceConfi
.isEmpty();
}

@Test
public void testToStringForInternalConfigSelector() {
String expected = "Resolution is pending";
String actual = ManagedChannelImpl.INITIAL_PENDING_SELECTOR.toString();
// Assert that the actual string equals the expected string
assertEquals("toString() should return 'Resolution is pending'", expected, actual);
}

@Test
public void interceptor() throws Exception {
final AtomicLong atomic = new AtomicLong();
Expand Down Expand Up @@ -3273,7 +3282,7 @@ public void channelTracing_nameResolvedEvent_zeorAndNonzeroBackends() throws Exc
Arrays.asList(new SocketAddress() {}, new SocketAddress() {}))))
.build();
nameResolverFactory.resolvers.get(0).listener.onResult(resolutionResult1);
assertThat(getStats(channel).channelTrace.events).hasSize(prevSize);
assertThat(getStats(channel).channelTrace.events).hasSize(prevSize + 1);

prevSize = getStats(channel).channelTrace.events.size();
nameResolverFactory.resolvers.get(0).listener.onError(Status.INTERNAL);
Expand All @@ -3290,7 +3299,7 @@ public void channelTracing_nameResolvedEvent_zeorAndNonzeroBackends() throws Exc
Arrays.asList(new SocketAddress() {}, new SocketAddress() {}))))
.build();
nameResolverFactory.resolvers.get(0).listener.onResult(resolutionResult2);
assertThat(getStats(channel).channelTrace.events).hasSize(prevSize + 1);
assertThat(getStats(channel).channelTrace.events).hasSize(prevSize + 2);
}

@Test
Expand All @@ -3314,7 +3323,7 @@ public void channelTracing_nameResolvedEvent_zeorAndNonzeroBackends_usesListener

channel.syncContext.execute(
() -> nameResolverFactory.resolvers.get(0).listener.onResult2(resolutionResult1));
assertThat(getStats(channel).channelTrace.events).hasSize(prevSize);
assertThat(getStats(channel).channelTrace.events).hasSize(prevSize + 1);

prevSize = getStats(channel).channelTrace.events.size();
channel.syncContext.execute(() ->
Expand All @@ -3340,7 +3349,7 @@ public void channelTracing_nameResolvedEvent_zeorAndNonzeroBackends_usesListener
.build();
channel.syncContext.execute(
() -> nameResolverFactory.resolvers.get(0).listener.onResult2(resolutionResult2));
assertThat(getStats(channel).channelTrace.events).hasSize(prevSize + 1);
assertThat(getStats(channel).channelTrace.events).hasSize(prevSize + 2);
}

@Test
Expand All @@ -3366,8 +3375,13 @@ public void channelTracing_serviceConfigChange() throws Exception {
.setServiceConfig(ConfigOrError.fromConfig(mcsc1))
.build();
nameResolverFactory.resolvers.get(0).listener.onResult(resolutionResult1);
assertThat(getStats(channel).channelTrace.events).hasSize(prevSize + 1);
assertThat(getStats(channel).channelTrace.events.get(prevSize))
assertThat(getStats(channel).channelTrace.events).hasSize(prevSize + 2);

Event configEvent = getStats(channel).channelTrace.events.get(prevSize);

assertThat(configEvent.description)
.contains("Current config is replaced with new config. prevConfig=");
assertThat(getStats(channel).channelTrace.events.get(prevSize + 1))
.isEqualTo(new ChannelTrace.Event.Builder()
.setDescription("Service config changed")
.setSeverity(ChannelTrace.Event.Severity.CT_INFO)
Expand All @@ -3382,7 +3396,7 @@ public void channelTracing_serviceConfigChange() throws Exception {
.setServiceConfig(ConfigOrError.fromConfig(mcsc1))
.build();
nameResolverFactory.resolvers.get(0).listener.onResult(resolutionResult2);
assertThat(getStats(channel).channelTrace.events).hasSize(prevSize);
assertThat(getStats(channel).channelTrace.events).hasSize(prevSize + 1);

prevSize = getStats(channel).channelTrace.events.size();
timer.forwardNanos(1234);
Expand All @@ -3393,8 +3407,8 @@ public void channelTracing_serviceConfigChange() throws Exception {
.setServiceConfig(ConfigOrError.fromConfig(ManagedChannelServiceConfig.empty()))
.build();
nameResolverFactory.resolvers.get(0).listener.onResult(resolutionResult3);
assertThat(getStats(channel).channelTrace.events).hasSize(prevSize + 1);
assertThat(getStats(channel).channelTrace.events.get(prevSize))
assertThat(getStats(channel).channelTrace.events).hasSize(prevSize + 2);
assertThat(getStats(channel).channelTrace.events.get(prevSize + 1))
.isEqualTo(new ChannelTrace.Event.Builder()
.setDescription("Service config changed")
.setSeverity(ChannelTrace.Event.Severity.CT_INFO)
Expand Down Expand Up @@ -3427,8 +3441,8 @@ public void channelTracing_serviceConfigChange_usesListener2OnResult2() throws E

channel.syncContext.execute(() ->
nameResolverFactory.resolvers.get(0).listener.onResult2(resolutionResult1));
assertThat(getStats(channel).channelTrace.events).hasSize(prevSize + 1);
assertThat(getStats(channel).channelTrace.events.get(prevSize))
assertThat(getStats(channel).channelTrace.events).hasSize(prevSize + 2);
assertThat(getStats(channel).channelTrace.events.get(prevSize + 1))
.isEqualTo(new ChannelTrace.Event.Builder()
.setDescription("Service config changed")
.setSeverity(ChannelTrace.Event.Severity.CT_INFO)
Expand All @@ -3444,7 +3458,7 @@ public void channelTracing_serviceConfigChange_usesListener2OnResult2() throws E
.build();
channel.syncContext.execute(() ->
nameResolverFactory.resolvers.get(0).listener.onResult(resolutionResult2));
assertThat(getStats(channel).channelTrace.events).hasSize(prevSize);
assertThat(getStats(channel).channelTrace.events).hasSize(prevSize + 1);

prevSize = getStats(channel).channelTrace.events.size();
timer.forwardNanos(1234);
Expand All @@ -3456,8 +3470,8 @@ public void channelTracing_serviceConfigChange_usesListener2OnResult2() throws E
.build();
channel.syncContext.execute(() ->
nameResolverFactory.resolvers.get(0).listener.onResult(resolutionResult3));
assertThat(getStats(channel).channelTrace.events).hasSize(prevSize + 1);
assertThat(getStats(channel).channelTrace.events.get(prevSize))
assertThat(getStats(channel).channelTrace.events).hasSize(prevSize + 2);
assertThat(getStats(channel).channelTrace.events.get(prevSize + 1))
.isEqualTo(new ChannelTrace.Event.Builder()
.setDescription("Service config changed")
.setSeverity(ChannelTrace.Event.Severity.CT_INFO)
Expand Down
22 changes: 22 additions & 0 deletions core/src/test/java/io/grpc/internal/ManagedChannelServiceConfigTest.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,7 @@
import static io.grpc.MethodDescriptor.MethodType.UNARY;
import static io.grpc.Status.Code.UNAVAILABLE;
import static java.util.concurrent.TimeUnit.MILLISECONDS;
import static org.junit.Assert.assertTrue;
import static org.junit.Assert.fail;

import com.google.common.collect.ImmutableList;
Expand All @@ -31,6 +32,7 @@
import io.grpc.Metadata;
import io.grpc.MethodDescriptor;
import io.grpc.internal.ManagedChannelServiceConfig.MethodInfo;
import io.grpc.internal.ManagedChannelServiceConfig.ServiceConfigConvertedSelector;
import io.grpc.testing.TestMethodDescriptors;
import java.util.Collections;
import java.util.Map;
Expand Down Expand Up @@ -296,6 +298,26 @@ public void retryConfig_AllowPerAttemptRecvTimeoutZero() {
.isNotNull();
}

@Test
public void testToStringForServiceConfigConvertedSelector() {
Map<String, ?> name = ImmutableMap.of("service", "service1", "method", "method1");
Map<String, ?> methodConfig = ImmutableMap.of(
"name", ImmutableList.of(name), "timeout", "1.234s");
Map<String, ?> rawServiceConfig =
ImmutableMap.of("methodConfig", ImmutableList.of(methodConfig));
ManagedChannelServiceConfig serviceConfig =
ManagedChannelServiceConfig.fromServiceConfig(rawServiceConfig, false, 0, 0, null);
ServiceConfigConvertedSelector selector = new ServiceConfigConvertedSelector(serviceConfig);
// Assert the toString method contains the config/structure and other details with data
assertTrue(selector.toString().contains("ServiceConfigConvertedSelector{"));
assertTrue(selector.toString().contains("config"));
assertTrue(selector.toString().contains("ManagedChannelServiceConfig{"));
assertTrue(selector.toString().contains("defaultMethodConfig"));
assertTrue(selector.toString().contains("serviceMethodMap"));
assertTrue(selector.toString().contains("service1/method1"));
assertTrue(selector.toString().contains("serviceMap"));
}

private static MethodDescriptor<?, ?> methodForName(String service, String method) {
return MethodDescriptor.<Void, Void>newBuilder()
.setFullMethodName(service + "/" + method)
Expand Down