Carmelo Cascone | 73f4530 | 2019-02-04 23:11:26 -0800 | [diff] [blame] | 1 | /* |
| 2 | * Copyright 2019-present Open Networking Foundation |
| 3 | * |
| 4 | * Licensed under the Apache License, Version 2.0 (the "License"); |
| 5 | * you may not use this file except in compliance with the License. |
| 6 | * You may obtain a copy of the License at |
| 7 | * |
| 8 | * http://www.apache.org/licenses/LICENSE-2.0 |
| 9 | * |
| 10 | * Unless required by applicable law or agreed to in writing, software |
| 11 | * distributed under the License is distributed on an "AS IS" BASIS, |
| 12 | * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. |
| 13 | * See the License for the specific language governing permissions and |
| 14 | * limitations under the License. |
| 15 | */ |
| 16 | |
| 17 | package org.onosproject.grpc.ctl; |
| 18 | |
| 19 | import io.grpc.CallOptions; |
| 20 | import io.grpc.Channel; |
| 21 | import io.grpc.ClientCall; |
| 22 | import io.grpc.ClientInterceptor; |
| 23 | import io.grpc.ForwardingClientCall; |
| 24 | import io.grpc.ForwardingClientCallListener; |
| 25 | import io.grpc.Metadata; |
| 26 | import io.grpc.MethodDescriptor; |
| 27 | import io.grpc.Status; |
| 28 | import io.grpc.protobuf.lite.ProtoLiteUtils; |
Carmelo Cascone | 73f4530 | 2019-02-04 23:11:26 -0800 | [diff] [blame] | 29 | import org.slf4j.Logger; |
| 30 | |
| 31 | import java.io.File; |
| 32 | import java.io.FileWriter; |
| 33 | import java.io.IOException; |
Carmelo Cascone | c2be50a | 2019-04-10 00:15:39 -0700 | [diff] [blame] | 34 | import java.net.URI; |
Carmelo Cascone | 73f4530 | 2019-02-04 23:11:26 -0800 | [diff] [blame] | 35 | import java.text.SimpleDateFormat; |
| 36 | import java.util.Date; |
| 37 | import java.util.StringJoiner; |
| 38 | import java.util.concurrent.atomic.AtomicBoolean; |
| 39 | import java.util.concurrent.atomic.AtomicLong; |
| 40 | |
| 41 | import static java.lang.String.format; |
| 42 | import static org.slf4j.LoggerFactory.getLogger; |
| 43 | |
| 44 | /** |
| 45 | * gRPC client interceptor that logs to file all messages sent and received. |
| 46 | */ |
| 47 | final class GrpcLoggingInterceptor implements ClientInterceptor { |
| 48 | |
| 49 | private static final Metadata.Key<com.google.rpc.Status> GRPC_STATUS_KEY = |
| 50 | Metadata.Key.of( |
| 51 | "grpc-status-details-bin", |
| 52 | ProtoLiteUtils.metadataMarshaller( |
| 53 | com.google.rpc.Status.getDefaultInstance())); |
| 54 | |
| 55 | private static final Logger log = getLogger(GrpcLoggingInterceptor.class); |
| 56 | |
| 57 | private final AtomicLong callIdGenerator = new AtomicLong(); |
Carmelo Cascone | c2be50a | 2019-04-10 00:15:39 -0700 | [diff] [blame] | 58 | private final URI channelUri; |
Carmelo Cascone | 73f4530 | 2019-02-04 23:11:26 -0800 | [diff] [blame] | 59 | private final AtomicBoolean enabled; |
| 60 | |
| 61 | private FileWriter writer; |
| 62 | |
Carmelo Cascone | c2be50a | 2019-04-10 00:15:39 -0700 | [diff] [blame] | 63 | GrpcLoggingInterceptor(URI channelUri, AtomicBoolean enabled) { |
| 64 | this.channelUri = channelUri; |
Carmelo Cascone | 73f4530 | 2019-02-04 23:11:26 -0800 | [diff] [blame] | 65 | this.enabled = enabled; |
Carmelo Cascone | 73f4530 | 2019-02-04 23:11:26 -0800 | [diff] [blame] | 66 | } |
| 67 | |
Carmelo Cascone | 62d5c2e | 2019-03-07 18:53:17 -0800 | [diff] [blame] | 68 | private boolean initWriter() { |
| 69 | if (writer != null) { |
| 70 | return true; |
| 71 | } |
Carmelo Cascone | c2be50a | 2019-04-10 00:15:39 -0700 | [diff] [blame] | 72 | final String safeChName = channelUri.toString() |
| 73 | .replaceAll("[^A-Za-z0-9]", "_").toLowerCase(); |
Carmelo Cascone | 62d5c2e | 2019-03-07 18:53:17 -0800 | [diff] [blame] | 74 | try { |
Carmelo Cascone | c2be50a | 2019-04-10 00:15:39 -0700 | [diff] [blame] | 75 | final File tmpFile = File.createTempFile(safeChName + "_", ".log"); |
Carmelo Cascone | 62d5c2e | 2019-03-07 18:53:17 -0800 | [diff] [blame] | 76 | this.writer = new FileWriter(tmpFile); |
| 77 | log.info("Created gRPC call log file for channel {}: {}", |
Carmelo Cascone | c2be50a | 2019-04-10 00:15:39 -0700 | [diff] [blame] | 78 | channelUri, tmpFile.getAbsolutePath()); |
Carmelo Cascone | 62d5c2e | 2019-03-07 18:53:17 -0800 | [diff] [blame] | 79 | return true; |
| 80 | } catch (IOException e) { |
| 81 | log.error("Unable to initialize gRPC call log writer", e); |
| 82 | } |
| 83 | return false; |
Carmelo Cascone | 73f4530 | 2019-02-04 23:11:26 -0800 | [diff] [blame] | 84 | } |
| 85 | |
| 86 | void close() { |
| 87 | synchronized (this) { |
| 88 | if (writer == null) { |
| 89 | return; |
| 90 | } |
| 91 | try { |
Carmelo Cascone | c2be50a | 2019-04-10 00:15:39 -0700 | [diff] [blame] | 92 | log.info("Closing log writer for {}...", channelUri); |
Carmelo Cascone | 73f4530 | 2019-02-04 23:11:26 -0800 | [diff] [blame] | 93 | writer.close(); |
| 94 | } catch (IOException e) { |
| 95 | log.error("Unable to close gRPC call log writer", e); |
| 96 | } |
| 97 | writer = null; |
| 98 | } |
| 99 | } |
| 100 | |
| 101 | private void write(String message) { |
| 102 | synchronized (this) { |
Carmelo Cascone | 62d5c2e | 2019-03-07 18:53:17 -0800 | [diff] [blame] | 103 | if (!initWriter()) { |
| 104 | return; |
| 105 | } |
| 106 | if (message.length() > 4096) { |
| 107 | message = message.substring(0, 256) + "... TRUNCATED!\n\n"; |
| 108 | } |
| 109 | try { |
| 110 | writer.write(format( |
| 111 | "*** %s - %s", |
| 112 | new SimpleDateFormat("yyyy-MM-dd HH:mm:ss.S") |
| 113 | .format(new Date()), |
| 114 | message)); |
| 115 | } catch (IOException e) { |
| 116 | log.error("Unable to write gRPC call log", e); |
Carmelo Cascone | 73f4530 | 2019-02-04 23:11:26 -0800 | [diff] [blame] | 117 | } |
| 118 | } |
| 119 | } |
| 120 | |
| 121 | @Override |
| 122 | public <ReqT, RespT> ClientCall<ReqT, RespT> interceptCall( |
| 123 | MethodDescriptor<ReqT, RespT> methodDescriptor, |
| 124 | CallOptions callOptions, Channel channel) { |
| 125 | return new ForwardingClientCall.SimpleForwardingClientCall<ReqT, RespT>( |
| 126 | channel.newCall(methodDescriptor, callOptions.withoutWaitForReady())) { |
| 127 | |
| 128 | private final long callId = callIdGenerator.getAndIncrement(); |
| 129 | |
| 130 | @Override |
| 131 | public void sendMessage(ReqT message) { |
| 132 | if (enabled.get()) { |
| 133 | write(format( |
| 134 | "%s >> OUTBOUND >> [callId=%s]\n%s\n", |
| 135 | methodDescriptor.getFullMethodName(), |
| 136 | callId, |
| 137 | message.toString())); |
| 138 | } |
| 139 | super.sendMessage(message); |
| 140 | } |
| 141 | |
| 142 | @Override |
| 143 | public void start(Listener<RespT> responseListener, Metadata headers) { |
| 144 | |
| 145 | if (enabled.get()) { |
| 146 | write(format( |
| 147 | "%s STARTED [callId=%s]\n%s\n\n", |
| 148 | methodDescriptor.getFullMethodName(), |
| 149 | callId, |
| 150 | headers.toString())); |
| 151 | } |
| 152 | |
| 153 | Listener<RespT> listener = new ForwardingClientCallListener<RespT>() { |
| 154 | @Override |
| 155 | protected Listener<RespT> delegate() { |
| 156 | return responseListener; |
| 157 | } |
| 158 | |
| 159 | @Override |
| 160 | public void onMessage(RespT message) { |
| 161 | if (enabled.get()) { |
| 162 | write(format( |
| 163 | "%s << INBOUND << [callId=%s]\n%s\n", |
| 164 | methodDescriptor.getFullMethodName(), |
| 165 | callId, |
| 166 | message.toString())); |
| 167 | } |
| 168 | super.onMessage(message); |
| 169 | } |
| 170 | |
| 171 | @Override |
| 172 | public void onClose(Status status, Metadata trailers) { |
| 173 | if (enabled.get()) { |
| 174 | write(format( |
| 175 | "%s CLOSED [callId=%s]\n%s\n%s\n\n", |
| 176 | methodDescriptor.getFullMethodName(), |
| 177 | callId, |
| 178 | status.toString(), |
| 179 | parseTrailers(trailers))); |
| 180 | } |
| 181 | super.onClose(status, trailers); |
| 182 | } |
| 183 | |
| 184 | private String parseTrailers(Metadata trailers) { |
| 185 | StringJoiner joiner = new StringJoiner("\n"); |
| 186 | joiner.add(trailers.toString()); |
| 187 | // If Google's RPC Status trailers are found, parse them. |
| 188 | final Iterable<com.google.rpc.Status> statuses = trailers.getAll( |
| 189 | GRPC_STATUS_KEY); |
| 190 | if (statuses == null) { |
| 191 | return joiner.toString(); |
| 192 | } |
| 193 | statuses.forEach(s -> joiner.add(s.toString())); |
| 194 | return joiner.toString(); |
| 195 | } |
| 196 | |
| 197 | @Override |
| 198 | public void onHeaders(Metadata headers) { |
| 199 | super.onHeaders(headers); |
| 200 | } |
| 201 | }; |
| 202 | |
| 203 | super.start(listener, headers); |
| 204 | } |
| 205 | }; |
| 206 | } |
| 207 | } |