deadtrickster / prometheus-cowboy

Expose Prometheus metrics using cowboy/cowboy2
MIT License
21 stars 20 forks source link

New version of cowboy throw exception #3

Open feng19 opened 5 years ago

feng19 commented 5 years ago

Hello, I encountered this problem when I used prometheus-cowboy:

 [error] <0.3255.0> Unhandled exception error:function_clause in cowboy_stream:early_error(1, Reason, PartialReq, Resp, Opts)
Stacktrace: [{prometheus_cowboy2_instrumenter,dispatch_metrics,[#{early_error_time => -576460636993891978,listener_host => {0,0,0,0},listener_port => 6222,partial_req => #{peer => {{192,168,10,86},56467},ref => ws},pid => <0.3255.0>,reason => {connection_error,protocol_error,'The method name must contain only valid token characters. (RFC7230 3.1.1)'},ref => ws,resp_body_length => 0,resp_headers => #{<<"connection">> => <<"close">>,<<"content-length">> => <<"0">>},resp_status => 400,streamid => 1}],[{file,"prometheus_cowboy2_instrumenter.erl"},{line,176}]},{prometheus_cowboy2_instrumenter,observe,1,[{file,"prometheus_cowboy2_instrumenter.erl"},{line,130}]},{cowboy_metrics_h,early_error,5,[{file,"cowboy_metrics_h.erl"},{line,312}]},{cowboy_http,early_error,5,[{...},...]},...]
Reason: {connection_error,protocol_error,'The method name must contain only valid token characters. (RFC7230 3.1.1)'}
PartialReq: #{peer => {{192,168,10,86},56467},ref => ws}
Resp: {response,400,#{<<"connection">> => <<"close">>,<<"content-length">> => <<"0">>},<<>>}
Opts: #{connection_type => supervisor,env => #{dispatch => [{'_',[],[{[],[],bg_ws_handler,[]}]}]},metrics_callback => #Fun<prometheus_cowboy2_instrumenter.observe.1>,stream_handlers => [cowboy_metrics_h,cowboy_stream_h]}

I think this may be related to the cowboy's version what I use. prometheus_cowboy version : 0.1.7 cowboy version : 2.6.1

seanmcevoy commented 3 years ago

i've just seen this same issue testing with cowboy 2.7.0 and prometheus_cowboy 0.1.7 i guess it's some low frequency edge case. i take it there's been no further investigation since this was reported?

seanmcevoy commented 3 years ago

i have some more info on this, in my case at least it looks like arguably user error. but perhaps the cowboy code could be strengthened here too. i think this points to cowboy itself rather than prometheus? will open a ticket there

im writing a test using lhttpc and have a wrapper function that takes in a method and a proplist, it encodes the proplist to json and it becomes the request body.

the problem occurs when the method is one that doesn't need (or shouldn't have?) a body.

this line of code is highlighted in the stacktrace, so i debugged the "Buffer" value: https://github.com/ninenines/cowboy/blob/2.7.0/src/cowboy_http.erl#L310

i make the request:

lhttpc:request( "http://127.0.0.1:8088/v3/myendpoint?arg1=1&arg2=2", "DELETE", [{<<"authorization">>, <<"Bearer ", JWT/binary>>}], <<"[]">>, 1000).

this succeeds with the expected 204 response and cowboy_http.erl#L310 is executed twice:

Buffer = <<"DELETE /v3/myendpoint?arg1=1&arg2=2 HTTP/1.1\r\nauthorization: Bearer XXXXXXXXXXX\r\nHost: 127.0.0.1:8088\r\n\r\n[]">>

Buffer = <<"[]">>

the i immediately make the request:

lhttpc:request( "http://127.0.0.1:8088/v3/myendpoint?arg1=1&arg2=2", "GET", [{<<"authorization">>, <<"Bearer ", JWT/binary>>}], <<"[]">>, 1000).

the client gets an unexpected 400 response and cowboy_http.erl#L310 is executed once with this dodgy looking data that includes the body from the previous response:

Buffer = <<"[]GET /v3/myendpoint?arg1=1&arg2=2 HTTP/1.1\r\nauthorization: Bearer XXXXXXXXXXX\r\nHost: 127.0.0.1:8088\r\n\r\n[]">>

on the server this is accompanied with the error:

10:27:47.825 UTC [error] Unhandled exception error:function_clause in cowboy_stream:early_error(2, Reason, PartialReq, Resp, Opts) Stacktrace: [{prometheus_cowboy2_instrumenter,dispatch_metrics,[#{early_error_time => -576441938946977291,listener_host => {0,0,0,0},listener_port => 8088,partial_req => #{peer => {{127,0,0,1},57589},ref => rest_service_http},pid => <0.3503.0>,reason => {connection_error,protocol_error,'The method name must contain only valid token characters. (RFC7230 3.1.1)'},ref => rest_service_http,resp_body_length => 0,resp_headers => #{<<"connection">> => <<"close">>,<<"content-length">> => <<"0">>},resp_status => 400,streamid => 2}],[{file,"/home/sean/workspace/prime/_build/default/lib/prometheus_cowboy/src/prometheus_cowboy2_instrumenter.erl"},{line,176}]},{prometheus_cowboy2_instrumenter,observe,1,[{file,"/home/sean/workspace/prime/_build/default/lib/prometheus_cowb..."},...]},...] Reason: {connection_error,protocol_error,'The method name must contain only valid token characters. (RFC7230 3.1.1)'}

everything works fine when i fix my code and ensure that these requests are made with no body.