Skip to content

Commit

Permalink
add VerbosePrinter and verbose output up to verbosity level 5, includ…
Browse files Browse the repository at this point in the history
…ing okhttp event logger and logging decorator for http client
  • Loading branch information
jhump committed Jan 31, 2024
1 parent 3204d07 commit af4822f
Show file tree
Hide file tree
Showing 12 changed files with 395 additions and 23 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -84,7 +84,9 @@ class JavaHelpers {
if (err != null) {
respBuilder.setError(toProtoError(err))
}
builder.setResponse(respBuilder)
val respMsg = respBuilder.build()
result.response.raw = respMsg
builder.setResponse(respMsg)
}
is ClientCompatResponse.Result.ErrorResult -> {
builder.setError(
Expand Down Expand Up @@ -166,6 +168,8 @@ class JavaHelpers {
private class ClientCompatRequestImpl(
private val msg: com.connectrpc.conformance.v1.ClientCompatRequest,
) : ClientCompatRequest {
override val raw: kotlin.Any
get() = msg
override val testName: String
get() = msg.testName
override val service: String
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -23,7 +23,7 @@ fun main(args: Array<String>) {
val loop = ConformanceClientLoop(
JavaHelpers::unmarshalRequest,
JavaHelpers::marshalResponse,
clientArgs.verbosity,
clientArgs.verbose,
)
val client = Client(
args = clientArgs,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -76,7 +76,9 @@ class JavaLiteHelpers {
if (err != null) {
respBuilder.setError(toProtoError(err))
}
builder.setResponse(respBuilder)
val respMsg = respBuilder.build()
result.response.raw = respMsg
builder.setResponse(respMsg)
}
is ClientCompatResponse.Result.ErrorResult -> {
builder.setError(
Expand Down Expand Up @@ -148,6 +150,8 @@ class JavaLiteHelpers {
private class ClientCompatRequestImpl(
private val msg: com.connectrpc.conformance.v1.ClientCompatRequest,
) : ClientCompatRequest {
override val raw: kotlin.Any
get() = msg
override val testName: String
get() = msg.testName
override val service: String
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -23,7 +23,7 @@ fun main(args: Array<String>) {
val loop = ConformanceClientLoop(
JavaLiteHelpers::unmarshalRequest,
JavaLiteHelpers::marshalResponse,
clientArgs.verbosity,
clientArgs.verbose,
)
val client = Client(
args = clientArgs,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -36,6 +36,7 @@ import com.connectrpc.conformance.client.adapt.Invoker
import com.connectrpc.conformance.client.adapt.ResponseStream
import com.connectrpc.conformance.client.adapt.ServerStreamClient
import com.connectrpc.conformance.client.adapt.UnaryClient
import com.connectrpc.http.HTTPClientInterface
import com.connectrpc.impl.ProtocolClient
import com.connectrpc.okhttp.ConnectOkHttpClient
import com.connectrpc.protocols.GETConfiguration
Expand All @@ -45,6 +46,7 @@ import kotlinx.coroutines.coroutineScope
import kotlinx.coroutines.delay
import kotlinx.coroutines.launch
import okhttp3.OkHttpClient
import okhttp3.Protocol
import okhttp3.tls.HandshakeCertificates
import okhttp3.tls.HeldCertificate
import java.security.KeyFactory
Expand Down Expand Up @@ -172,6 +174,10 @@ class Client(
try {
stream.send(msg)
} catch (ex: Exception) {
args.verbose.verbosity(2) {
println("Failed to send request message:")
indent().println(ex.stackTraceToString())
}
numUnsent = req.requestMessages.size - i
break
}
Expand Down Expand Up @@ -277,6 +283,10 @@ class Client(
try {
stream.requests.send(msg)
} catch (ex: Exception) {
args.verbose.verbosity(2) {
println("Failed to send request message:")
indent().println(ex.stackTraceToString())
}
numUnsent = req.requestMessages.size - i
break
}
Expand Down Expand Up @@ -318,6 +328,10 @@ class Client(
try {
stream.requests.send(msg)
} catch (ex: Exception) {
args.verbose.verbosity(2) {
println("Failed to send request message:")
indent().println(ex.stackTraceToString())
}
// Ignore. We should see it again below when we receive the response.
}

Expand Down Expand Up @@ -447,6 +461,11 @@ class Client(
var clientBuilder = OkHttpClient.Builder()
.protocols(asOkHttpProtocols(req.httpVersion, useTls))
.connectTimeout(Duration.ofMinutes(1))

args.verbose.withPrefix("okhttp3 events: ").verbosity(4) {
clientBuilder = clientBuilder.eventListener(OkHttpEventTracer(this))
}

if (useTls) {
val certs = certs(req)
clientBuilder = clientBuilder.sslSocketFactory(certs.sslSocketFactory(), certs.trustManager)
Expand All @@ -469,10 +488,14 @@ class Client(
emptyList()
}
val httpClient = clientBuilder.build()
var connectHttpClient: HTTPClientInterface = ConnectOkHttpClient(httpClient)
args.verbose.withPrefix("http client interface: ").verbosity(3) {
connectHttpClient = TracingHTTPClient(connectHttpClient, this)
}
return Pair(
httpClient,
ProtocolClient(
httpClient = ConnectOkHttpClient(httpClient),
httpClient = connectHttpClient,
ProtocolClientConfig(
host = host,
serializationStrategy = serializationStrategy,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -18,7 +18,7 @@ import com.connectrpc.conformance.client.adapt.UnaryClient.InvokeStyle

data class ClientArgs(
val invokeStyle: InvokeStyle,
val verbosity: Int,
val verbose: VerbosePrinter,
) {
companion object {
fun parseArgs(args: Array<String>): ClientArgs {
Expand Down Expand Up @@ -53,7 +53,18 @@ data class ClientArgs(
}
}
"-v" -> {
verbosity = 1
// see if there's a value
if (i < args.size - 1 && !args[i + 1].startsWith("-")) {
skip = true // consuming next string now
val v = args[i + 1]
val intVal = v.toIntOrNull()
if (intVal == null || intVal < 1 || intVal > 5) {
throw RuntimeException("value for $arg option should be an integer between 1 and 5; instead got '$v'")
}
verbosity = intVal
} else {
verbosity = 1
}
}
"-vv" -> {
verbosity = 2
Expand All @@ -70,7 +81,7 @@ data class ClientArgs(
}
}
}
return ClientArgs(invokeStyle, verbosity)
return ClientArgs(invokeStyle, VerbosePrinter(verbosity, "* client: "))
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -30,39 +30,43 @@ import java.io.OutputStream
class ConformanceClientLoop(
private val requestUnmarshaller: (ByteArray) -> ClientCompatRequest,
private val responseMarshaller: (ClientCompatResponse) -> ByteArray,
private val verbosity: Int = 0,
private val verbose: VerbosePrinter,
) {
fun run(input: InputStream, output: OutputStream, client: Client) = runBlocking {
// TODO: issue RPCs in parallel
while (true) {
var result: ClientCompatResponse.Result
val req = readRequest(input) ?: return@runBlocking // end of stream
if (verbosity > 0) {
System.err.println("* client: read request for test ${req.testName}")
verbose.verbosity(1) {
println("read request for test ${req.testName}")
verbose.verbosity(3) {
println("RPC request:")
indent().println("${req.raw}")
}
}
try {
val resp = client.handle(req)
result = ClientCompatResponse.Result.ResponseResult(resp)
if (verbosity > 0) {
System.err.println("* client: RPC completed for test ${req.testName}")
verbose.verbosity(1) {
println("RPC completed for test ${req.testName}")
}
} catch (e: Exception) {
if (verbosity > 0) {
System.err.println("* client: RPC could not be issued for test ${req.testName}")
e.printStackTrace()
} catch (ex: Exception) {
verbose.verbosity(1) {
println("RPC could not be issued for test ${req.testName}")
indent().println(ex.stackTraceToString())
}
val msg = if (e.message.orEmpty() == "") {
e::class.qualifiedName.orEmpty()
val msg = if (ex.message.orEmpty() == "") {
ex::class.qualifiedName.orEmpty()
} else {
"${e::class.qualifiedName}: ${e.message}"
"${ex::class.qualifiedName}: ${ex.message}"
}
result = ClientCompatResponse.Result.ErrorResult(msg)
}
if (result is ClientCompatResponse.Result.ResponseResult && result.response.error != null) {
if (verbosity > 2) {
verbose.verbosity(2) {
val ex = result.response.error!!
System.err.println("* client: RPC failed with code ${ex.code}")
ex.printStackTrace()
println("RPC failed with code ${ex.code} for test ${req.testName}:")
indent().println(ex.stackTraceToString())
}
}
writeResponse(
Expand All @@ -72,6 +76,12 @@ class ConformanceClientLoop(
result = result,
),
)
if (result is ClientCompatResponse.Result.ResponseResult && result.response.raw != null) {
verbose.verbosity(3) {
println("RPC result:")
indent().println("${result.response.raw}")
}
}
}
}

Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,83 @@
// Copyright 2022-2023 The Connect Authors
//
// 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.connectrpc.conformance.client

import okhttp3.Call
import okhttp3.Connection
import okhttp3.EventListener
import okhttp3.Protocol
import okhttp3.Request
import okhttp3.Response
import java.io.IOException
import java.net.InetSocketAddress
import java.net.Proxy

internal class OkHttpEventTracer(
private val printer: VerbosePrinter.Printer,
) : EventListener() {
override fun connectStart(call: Call, inetSocketAddress: InetSocketAddress, proxy: Proxy) {
printer.printlnWithStackTrace("connecting to $inetSocketAddress...")
}
override fun connectEnd(
call: Call,
inetSocketAddress: InetSocketAddress,
proxy: Proxy,
protocol: Protocol?,
) {
printer.printlnWithStackTrace("connected to $inetSocketAddress")
}
override fun connectFailed(
call: Call,
inetSocketAddress: InetSocketAddress,
proxy: Proxy,
protocol: Protocol?,
ioe: IOException,
) {
printer.printlnWithStackTrace("connect to $inetSocketAddress failed")
}
override fun connectionAcquired(call: Call, connection: Connection) {
printer.printlnWithStackTrace("connection to ${connection.socket().remoteSocketAddress} acquired")
}
override fun requestHeadersStart(call: Call) {
printer.printlnWithStackTrace("writing request headers...")
}
override fun requestHeadersEnd(call: Call, request: Request) {
printer.printlnWithStackTrace("request headers written")
}
override fun requestBodyStart(call: Call) {
printer.printlnWithStackTrace("writing request body...")
}
override fun requestBodyEnd(call: Call, byteCount: Long) {
printer.printlnWithStackTrace("request body written: $byteCount bytes")
}
override fun requestFailed(call: Call, ioe: IOException) {
printer.printlnWithStackTrace("request failed: ${ioe.message}")
}
override fun responseHeadersStart(call: Call) {
printer.printlnWithStackTrace("reading response headers...")
}
override fun responseHeadersEnd(call: Call, response: Response) {
printer.printlnWithStackTrace("response headers read: status code = ${response.code}")
}
override fun responseBodyStart(call: Call) {
printer.printlnWithStackTrace("reading response body...")
}
override fun responseBodyEnd(call: Call, byteCount: Long) {
printer.printlnWithStackTrace("response body read: $byteCount bytes")
}
override fun responseFailed(call: Call, ioe: IOException) {
printer.printlnWithStackTrace("response failed: ${ioe.message}")
}
}
Loading

0 comments on commit af4822f

Please sign in to comment.