ntex-rs / ntex

framework for composable networking services
Apache License 2.0
1.98k stars 108 forks source link

Unknown reason of internal server error #423

Closed so-schen closed 1 week ago

so-schen commented 1 week ago

I am trying to investigate the reason behind why ntex reported internal server error in below context. From the traces, I cannot understand what is the error trigger ntex to report it. After this failure, I check the endpoint using curl, it responds OK. This happen when running tests using python reqwest.

31043 [2024-09-18T16:26:06.488567Z+00:00] TRACE ntex::http::service: New http connection, peer address Some(127.0.0.1:53272), in-flight: 1
31044 [2024-09-18T16:26:06.488575Z+00:00] DEBUG ntex_io::ioref: : Start timer Seconds(1)
31045 [2024-09-18T16:26:06.488578Z+00:00] DEBUG ntex_io::timer: : Timer driver does not run, current: 345
31046 [2024-09-18T16:26:06.488582Z+00:00] TRACE ntex::http::h1::dispatcher: : Trying to read http message
31047 [2024-09-18T16:26:06.488596Z+00:00] TRACE ntex_io::tasks: : New 232 bytes available, wakeup dispatcher
31048 [2024-09-18T16:26:06.488599Z+00:00] TRACE ntex::http::h1::dispatcher: : Trying to read http message
31049 [2024-09-18T16:26:06.488604Z+00:00] TRACE ntex::http::h1::dispatcher: : Http message is received:
31050 Request HTTP/1.1 GET:/rpc/v1/transactions/0x555f0a1ac149c4ec81c3546838896a2dd61900b72dda8b86cf1931219f8c1f92
31051   headers:
31052     "accept": "*/*"
31053     "connection": "keep-alive"
31054     "accept-encoding": "gzip, deflate"
31055     "host": "localhost:27000"
31056     "user-agent": "python-requests/2.31.0"
31057  and payload None
31058 [2024-09-18T16:26:06.488806Z+00:00] TRACE ntex::http::h1::dispatcher: : Sending response:
31059 Response HTTP/1.1 500 Internal Server Error
31060   headers:
31061     "content-type": "application/json"
31062   body: Empty
31063  body: Sized(108)
31064 [2024-09-18T16:26:06.488813Z+00:00] TRACE ntex::http::h1::dispatcher: : Got response chunk: 108
31065 [2024-09-18T16:26:06.488814Z+00:00] TRACE ntex::http::h1::dispatcher: : Response payload eof Flags(0x0)
31066 [2024-09-18T16:26:06.488816Z+00:00]  INFO ntex::web::middleware::logger: 127.0.0.1:53272 "GET /rpc/v1/transactions/0x555f0a1ac149c4ec81c3546838896a2dd      61900b72dda8b86cf1931219f8c1f92 HTTP/1.1" 500 108 "-" "python-requests/2.31.0" 0.000203
fafhrd91 commented 1 week ago

could you create reproducible example? I'd like to look

so-schen commented 1 week ago

oh.. sorry just found out it is our endpoint implementation return an error

so-schen commented 1 week ago

But the tag is empty string in this case, would be good that the tag can be shown correctly in below trace 31058 [2024-09-18T16:26:06.488806Z+00:00] TRACE ntex::http::h1::dispatcher: : Sending response:

        log::trace!(
            "{}: Sending response: {:?} body: {:?}",
            self.io.tag(),
            msg,
            body.size()
        );
fafhrd91 commented 1 week ago

I see. you can set tag with https://docs.rs/ntex/latest/ntex/server/struct.ServerBuilder.html#method.set_tag, but it is not exposed from web::server. will fix that

fafhrd91 commented 6 days ago

starting ntex 2.5, it is possible to set server tag