Smart-proxy prints logs twice

Development
1

Hey,

yesterday I noticed that smart-proxy logs some lines three times for me (develop). Can you confirm? Just run proxy and then do curl http://localhost:8448/features. What I see is:

2020-09-09T13:57:23  [D] accept: 127.0.0.1:34600
2020-09-09T13:57:23  [D] Rack::Handler::WEBrick is invoked.
2020-09-09T13:57:23 2e43c4fc [I] Started GET /features 
2020-09-09T13:57:23 2e43c4fc [I] Started GET /features 
2020-09-09T13:57:23 2e43c4fc [D] Headers: {"HTTP_HOST"=>"localhost:8448", "HTTP_USER_AGENT"=>"curl/7.69.1", "HTTP_ACCEPT"=>"*/*", "HTTP_VERSION"=>"HTTP/1.1"}
2020-09-09T13:57:23 2e43c4fc [D] Headers: {"HTTP_HOST"=>"localhost:8448", "HTTP_USER_AGENT"=>"curl/7.69.1", "HTTP_ACCEPT"=>"*/*", "HTTP_VERSION"=>"HTTP/1.1"}
2020-09-09T13:57:23 2e43c4fc [D] 
2020-09-09T13:57:23 2e43c4fc [D] 
2020-09-09T13:57:23 983ac62b [I] Started GET /features 
2020-09-09T13:57:23 983ac62b [D] Headers: {"HTTP_HOST"=>"localhost:8448", "HTTP_USER_AGENT"=>"curl/7.69.1", "HTTP_ACCEPT"=>"*/*", "HTTP_VERSION"=>"HTTP/1.1"}
2020-09-09T13:57:23 983ac62b [I] Finished GET /features with 200 (0.34 ms)
2020-09-09T13:57:23 983ac62b [I] Finished GET /features with 200 (0.57 ms)
2020-09-09T13:57:23 983ac62b [I] Finished GET /features with 200 (0.57 ms)
2020-09-09T13:57:23  [D] close: 127.0.0.1:34600

Might be some misconfiguration on my side, weird.

2

Could it be related to smart_proxy_dynflow logging stack replacement? I was seeing that same when testing that PR with smart_proxy_dynflow_core running inside smart-proxy (see https://github.com/theforeman/smart_proxy_dynflow/pull/61#pullrequestreview-485842079)

1 Like
3

Thanks that smells like it. Will take a look!