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.

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

0-byte body on sdk 6.12 with android when using HttpLoggingInterceptor #2037

Closed
slowcar opened this issue Jun 5, 2024 · 6 comments · Fixed by microsoft/kiota-java#1537
Closed
Assignees
Labels
type:question An issue that's a question

Comments

@slowcar
Copy link

slowcar commented Jun 5, 2024

I have the issue that the sdk posts no body (again).
Related to #1972 and #1872 that i have posted before.

I can finally reproduce the issue, it occurs when i activate our HttpLoggingInterceptor

sdk is 6.12.0 on android 10, used logging-interceptor is the current version, 4.12.0

Here is our code to create the GraphServiceClient with the logger (simplified):
HttpLoggingInterceptor loggingInterceptor = new HttpLoggingInterceptor(System.out::println); loggingInterceptor.level(HttpLoggingInterceptor.Level.BODY); OkHttpClient.Builder builder = GraphClientFactory.create(); builder.addInterceptor(loggingInterceptor); OkHttpClient okHttpClient = builder.build(); GraphServiceClient client = new GraphServiceClient(authProvider, okHttpClient);

If i set the Level to BASIC or NONE, the request works.
If i change it to BODY again, it fails.

I am trying to retrieve user availability:
`--> POST https://graph.microsoft.com/v1.0/me/calendar/getSchedule
Content-Length: 227
content-type: application/json
authorization: Bearer
prefer: outlook.timezone="UTC"
accept: application/json
SdkVersion: graph-java, graph-java-core/3.1.12 (featureUsage=1203; android/29)
client-request-id: f0b3a2d1-506f-4bbd-9b03-8ba3b71a8085
User-Agent: kiota-java/1.1.12

{"AvailabilityViewInterval":60,"EndTime":{"dateTime":"2024-06-05T13:00:00.000","timeZone":"UTC"},"Schedules":["x@x.x","y@y.y"],"StartTime":{"dateTime":"2024-06-05T12:00:00.000","timeZone":"UTC"}}
--> END POST (0-byte body)`

Is there a different way to log headers and body?

@Ndiritu
Copy link
Contributor

Ndiritu commented Jul 11, 2024

Hi @slowcar. Thanks for following up on this issue.

Setting the level to BODY causes the request to fail because the HttpLoggingInterceptor reads the entire stream's contents without resetting it meaning during sending the stream has no further bytes to be read.

To log the body, you can consider using the NativeResponseHandler to get the raw OkHttp Response object from where you can log the response.request. This would however prevent the normal deserialization process.

@baywet @andrueastman thoughts on logging the request body to the OpenTelemetry spans?

@Ndiritu Ndiritu added the type:question An issue that's a question label Jul 11, 2024
@Ndiritu
Copy link
Contributor

Ndiritu commented Jul 11, 2024

A better alternative could be to extend the HttpLoggingInterceptor and reset the ResponseBody contents stream before continuing down the interceptor chain.

@slowcar
Copy link
Author

slowcar commented Jul 15, 2024

To me it looks like the issue occurs with the request body, not with the response. The request is logged, but can no longer be handled by the graph sdk/kiota?
HttpLoggingInterceptor sees to use a Buffer and requestBody.writeTo(buffer) which should be repeatable

I do not understand why the behavior is different compared to the 5.x sdk where we used httplogginginterceptor without any issue.

@mkomko
Copy link

mkomko commented Jul 24, 2024

I just ran into the same thing and thought that I must be doing something wrong in my own interceptor. But when the same thing happened when using OkHttp's own HttpLoggingInterceptor I got suspicious. Is this a bug in the SDK? What's the solution?
Thanks in advance!

@slowcar
Copy link
Author

slowcar commented Aug 15, 2024

We have removed logging from POST requests as a workaround. Using NativeResponseHandler looks quite complicated and we actually want all the parsing etc.
I tried extending HttpLoggingInterceptor but to no avail.

@mkomko
Copy link

mkomko commented Aug 16, 2024

@baywet @Ndiritu Any update on this? It must be something in the SDK, since OkHttp's own HttpLoggingInterceptor shows that writing to a Buffer should not cause the request body to not be readable again.

It's pretty problematic to not be able to see the request body when reporting issues or analyzing problems.

Thanks in advance!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
type:question An issue that's a question
Projects
None yet
3 participants