Here's the sample code...
@jkarneges Okay thank you for the assistance! I don't have to fix it ASAP, so I'll probably just wait until you can get to it. I will add an issue on the github repo so that this investigation can be seen by others in the future, and also if it turns out you can't increase the number of allowed headers, then you can share that on the github issue.
hi @ccbeloy, on the surface the code seems fine. maybe an incompatibility between the implementations. can you log the bytes of the client request somewhere? for example run
nc -l {port} and make a non-ssl request to it on localhost. there are only a few ways that error message can happen, and it should be clear from the request what is causing it
2 replies
Hi @jkarneges. I'm trying to replicate examples from the Quickstart guide for Websockets-Over HTTP.
Initial connect and echo work, but pushpin drops the connection in 8-10 seconds.
I noticed one error message in pushpin logs "[DEBUG] 2022-04-22 13:07:09.981 [proxy] wsproxysession: 0x6000032e8680 wscontrol session error
"
Here's my sinatra backend:
require 'sinatra'
post '/stream' do
status 200
data = request.body.read
if !data.index("OPEN").nil?
headers(
'Content-Type' => 'application/websocket-events',
'Sec-WebSocket-Extensions' => 'grip; message-prefix=""'
)
c = 'c:{"type": "subscribe", "channel": "mychannel"}'
body "OPEN\r\nTEXT 2F\r\nc:#{c}\r\n"
else
headers('Content-Type' => 'application/websocket-events')
body data
end
endpushpin version: 1.35.0
I'm connecting with "wscat", but it seems the same result is with curl or normal websocket clients
Any ideas?
Ok. I found the issue in my code. The grip control message was not correctly formed: I included "c:" two times by mistake.
Btw, pushpin logs pointed me to the right direction with this log entry:
[DEBUG] 2022-04-22 16:23:50.306 [handler] grip control message is not valid jsonI may need look into gripcontrol gem again. That should help avoid such silly mistakes going forward.
@jkarneges: Hello, We are trying to setup pushpin and would like to know if it is possible for pushpin stats socket to report websocket message count.
we also recently introduced prometheus metrics. it has to be explicitly enabled via the
prometheus_port setting (see https://pushpin.org/docs/configuration/#pushpinconf-file). it provides aggregate values similar to the report event
So we have been tryin gto use monitorstats.py from the /tools/ to get ws message reporting.
python3 monitorstats.py ipc:///var/run/pushpin/pushpin-stats report
report {'connections': 1, 'duration': 8501, 'from': 'pushpin-handler_90019', 'http-response-sent': 0, 'minutes': 1, 'received': 0, 'sent': 0}
but it doesnt look like ws message count is being reported
also tried python3 monitorstats.py ipc:///var/run/pushpin/pushpin-stats message but it does not seem to be triggering anything even when we connect to ws via pushping using wscat
@jkarneges: should we be listening to ipc:///var/run/pushpin/pushpin-proxy-stats ?
Ideally both. I could parse the log but that seems slow and inefficient at high traffic
I tried that, however that keeps showing 0 even though the ws connection is being proxied and responses received correctly
Note we are doing a WS to ws backend proxy
I was afraid of that, would it be too far of a leap to try to add that? I.e. track down the code in proxy that counts the ws messages and use that to increment the report stats as well as latency.
Or are aware of any plans to add such a feature in the near future?
what do you mean about a latency metric?
Time delta between client request and backend response in a sample period
Getting a metric counting non published messages would be awesome.
Has something changed with in the pushpin code to prevent the pushpin proxy from forwarding on client websocket messages to the backend? I had it all set up and working yesterday but today it appears like the pushpin proxy is not receiving messages form the websocket client. There are no errors thrown in either the pushpin logs or my personal logs . Opening up the websocket connection with pushpin works just fine and it proxies this connection to the backend which accepts the connection, but the websocket client cannot send messages to the server behind to pushpin proxy afterwards. Not sure what happened.
@jkarneges: from time to time, the proxy seems to fail to start. systemctl gives the following message "Failed to start HTTP reverse proxy server for streaming and long-polling services"
stop and restart of the service does not seem to clear things.. is there some sort of lock? thanks
@jkarneges: just wanted to say that we would be willing to beta test a patch to count non-published websocket request and response messages.
Is it reasonable to expect to run the server at debug level 3 for long term provided the logs are rotated often?
We tried that and we are finding that the proxy stops working in the debug mode after an hour or so.
We tried enable level 3 log only for the proxy (others at 1) and it still faces issues. It looks like it stops accepting connection
@jkarneges: as far as i can tell its the log has stopped. when a the new(failed) connection it attempted.
interestingly the update checker continues to log
wscat -c ws://localhost:8000 also hangs
