Invalid Handshake over WS

Ike

Hello, I have been running the below c# code snippet with the .net client SDK (version 5.1.0) against our Lightstreamer server version 7.2.2 and I kept getting invalid handshake and the connection kept switching to HTTP.
I tried ForcedTransport = "WS" and "WS-Streaming" as well but still no luck.

I tried the quickstart example on here, https://sdk.lightstreamer.com/ls-dotnetstandard-client/6.0.0/api/articles/intro.html and it worked fine with me.

Also I have a Java version (similar to the C# code below) and it works fine as well. It connects and I get status WS-Streaming back successfully. Somehow I can't make it work with the following though. Any idea what could be the reason?

using com.lightstreamer.client;
using Lightstreamer.DotNet.Logging.Log;

namespace ConsoleApp;

internal class Program
{
public static void Main()
{
LightstreamerClient.setLoggerProvider(new Log4NetLoggerProviderWrapper());

var client = new LightstreamerClient("https://myurl", "myAdapterSet")
{
connectionDetails =
{
User = "user",
Password = "token"
}
};
}
}

Log;

Session ID value changed to
Server Socket Name value changed to
Client IP value changed to
Server Instance Address value changed to
Opening new session ...
Cookies to be inserted for https://myurl/lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0: <none>
Start message handler
Session ID value changed to Saff0bf8ac9a1ffc2M19aT4954759
Server Instance Address value changed to https://myurl/
Server Socket Name value changed to Lightstreamer HTTP Server
Client IP value changed to xxxxxx
Cookies to be inserted for https://myurl: <none>
WS upgrade error: Invalid handshake response getStatus: 404 Not Found
CONNECTED:STREAM-SENSING
Unable to establish session of the current type. Switching session type WS Streaming->prepare HTTP Streaming
Sending request to the server to force a rebind on the current connection during FIRST_BINDING
Cookies to be inserted for https://myurl/lightstreamer/control.txt?LS_protocol=TLCP-2.1.0: <none>
Batch completed
CONNECTED:STREAM-SENSING
CONNECTED:STREAM-SENSING
Failed to switch session type. Starting new session prepare HTTP Streaming
Closing session new.switch.timeout.timeout.FIRST_BINDING.1
Sending request to the server to destroy the current session during FIRST_BINDING
Reset message handler
Session ID value changed to
Server Socket Name value changed to
Client IP value changed to
Server Instance Address value changed to
Stop Protocol
Protocol dismissed
Closing wsc
Session ID value changed to
Server Socket Name value changed to
Client IP value changed to
Server Instance Address value changed to
Opening new session ...
Cookies to be inserted for https://myurl/lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0: <none>
Start message handler
Session ID value changed to Sd47a36c69c7bcb65M19aT5003510
Server Instance Address value changed to https://myurl/
Server Socket Name value changed to Lightstreamer HTTP Server
Client IP value changed to xxxxxxx
Cookies to be inserted for https://myurl/lightstreamer/bind_session.txt?LS_protocol=TLCP-2.1.0: <none>
Keepalive Interval value changed to 5000
CONNECTED:HTTP-STREAMING
CONNECTED:HTTP-STREAMING
CONNECTED:HTTP-STREAMING

Dario Crivelli

We need to see if and how the request reaches LS Server.
If the Server is under your control, please check the log. The following log configuration is needed:
LightstreamerLogger.connections at INFO level
LightstreamerLogger.connections.http at INFO level
LightstreamerLogger.webServerat DEBUG level

Moreover, even though, as far as we know, there isn't such a bug in .net SDK 5.1.0, please upgrade to 5.1.8 to simplify the scenario.

Ike

New Lightstreamer Client instanced (library version: Lightstreamer.DotNetStandard.Client 5.1.8)
Server Address value changed to https://myurl
Adapter Set value changed to Futures
Forced Transport value changed to
User value changed to
Password value changed
Server Address value changed to https://myurl
Connect requested
SessionManager state change: OFF -> STREAMING_WS
New protocol oid=1
rhb max interval 0
rhb current interval 0
New session oid=1
Session ID value changed to
Server Socket Name value changed to
Client IP value changed to
Server Instance Address value changed to
Opening new session ...
IsOffline check now ...
... online, go!
Create Request: https://myurl
Requested cookies for uri https://myurl/lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0:
cs ---- address: https://myurl/lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0, 52.177.141.126
HTTP transport connection establishing (oid=1): https://myurl:443
/lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0
LS_polling=true&LS_cause=new.api&LS_polling_millis=0&LS_idle_millis=0&LS_cid=jqWtj1twChtfDxikwp1ltvcB4CJCJi kOj2CKDk&LS_myAdapter_set=Futures&LS_user=&LS_password

- target: 52.177.141.126:443 - True(com.lightstreamer.client.transport.providers.netty.NettyFullAddress).
New HTTP channel pool created. Remote address: 52.177.141.126:443
sessionStatusChanged 1, 1
Session state change (1): OFF -> CREATING
phasing : 1 - 1
Status timeout in 4000 [currentConnectTimeout] due to
HTTP channel created [674c2ca9, com.lightstreamer.client.transport.providers.netty.NettyFullAddress]: False
HTTP channel active [674c2ca9]
- acquired! 674c2ca9
Go with the request True
Send Request Task status = RanToCompletion
SetCookie received for uri https://myurl/lightstreamer: -futureslightstreamer=1698240888.178.56570.767405; Expires=Fri, 27-Oct-23 13:34:47 GMT; Max-Age=172800; Path=/; Secure; HttpOnly
Cookies to be saved for https://myurl/lightstreamer: -futureslightstreamer=1698240888.178.56570.767405; Expires=Fri, 27-Oct-23 13:34:47 GMT; Max-Age=172800; Path=/; Secure; HttpOnly
HTTP transport receiving [674c2ca9]:
CONOK,S0abbfd1b7bc558dcM19aT3447185,50000,0,*
SERVNAME,Lightstreamer HTTP Server
CLIENTIP,10.42.51.9
LOOP,0

Readeable bytes: 112
Start: 0
findEol: 0 <> 112
findEol - cr: 45 eol:46
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - CONOK,S0abbfd1b7bc558dcM19aT3447185,50000,0,*
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - CONOK,S0abbfd1b7bc558dcM19aT3447185,50000,0,*
findEol: 47 <> 112
findEol - cr: 81 eol:82
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - SERVNAME,Lightstreamer HTTP Server
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - SERVNAME,Lightstreamer HTTP Server
findEol: 83 <> 112
findEol - cr: 102 eol:103
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - CLIENTIP,10.42.51.9
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - CLIENTIP,10.42.51.9
findEol: 104 <> 112
findEol - cr: 110 eol:111
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - LOOP,0
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - LOOP,0
findEol: 112 <> 112
.:.: False(0)
linePart: 0
Reuse failed for 674c2ca9
HTTP channel inactive [674c2ca9]
... False - False
Socket Closed.
New message (1 - OPENING_STREAM): CONOK,S0abbfd1b7bc558dcM19aT3447185,50000,0,*
OK event while CREATING
Address to use after create: https://myurl
Data event while CREATING
sessionStatusChanged 1, 1
Session state change (1): CREATING -> CREATED
phasing : 2 - 2
Status timeout in 2000 [executionTimeout] due to
Check Point 1a120ak.
SubscriptionManager sessionAlive set to true.
sendAllSubscriptions: 0
sendAllSubscriptions done!
Start message handler
Sending queued messages
Session ID value changed to S0abbfd1b7bc558dcM19aT3447185
Server Instance Address value changed to https://myurl
New message (1 - READING_STREAM): SERVNAME,Lightstreamer HTTP Server
Server Socket Name value changed to Lightstreamer HTTP Server
New message (1 - READING_STREAM): CLIENTIP,10.42.51.9
Client IP value changed to 10.42.51.9
New message (1 - READING_STREAM): LOOP,0
sessionStatusChanged 1, 1
Session state change (1): CREATED -> FIRST_PAUSE
phasing : 3 - 3
Timeout event [noPause] while FIRST_PAUSE cause=
SessionWS state change (1) (sendBind): WS_NOT_CONNECTED -> WS_CONNECTING
Requested cookies for uri https://myurl/lightstreamer: -futureslightstreamer=1698240888.178.56570.767405
New WS channel pool created. Remote address: 52.177.141.126:443
... try get parent pool channel ... com.lightstreamer.client.transport.providers.netty.HttpPoolManager+HttpChannelPool
HTTP channel created [2a2b01d5, com.lightstreamer.client.transport.providers.netty.NettyFullAddress]: False
WebSocket transport - : CONNECTING
Status timeout in 4000 [currentConnectTimeoutWS]
SessionWS state change (1) (sendBind): WS_CONNECTING
HTTP channel active [2a2b01d5]
... Channel [id: 0x2a2b01d5, [::ffff:10.249.0.114]:50962 => [::ffff:52.177.141.126]:443]
Wait WS upgrade completition.
[id: 0x2a2b01d5, [::ffff:10.249.0.114]:50962 => [::ffff:52.177.141.126]:443] is active -> upgrade ...
[id: 0x2a2b01d5, [::ffff:10.249.0.114]:50962 => [::ffff:52.177.141.126]:443] ... wait upgrade ... False
CONNECTED:STREAM-SENSING

Ike

... wsHandshakeHandler ...
... add ws pipeline ...
... ws handshake task: 232 - False - False - False
[id: 0x2a2b01d5, [::ffff:10.249.0.114]:50962 => [::ffff:52.177.141.126]:443] ... wait upgrade 2 ... False
[id: 0x2a2b01d5, [::ffff:10.249.0.114]:50962 => [::ffff:52.177.141.126]:443] ... done False - True
WS Read0 - False - Msg:AggregatedFullHttpResponse(decodeResult: success, version: HTTP/1.1, content: CompositeByteBuffer(ridx: 0, widx: 146, cap: 146, components=1))
HTTP/1.1 404 Not Found
Date:Wed, 25 Oct 2023 13:34:49 GMT
Content-Type:text/html
Content-Length:146
Connection:keep-alive
Strict-Transport-Security:max-age=15724800; includeSubDomains
WS Read0 -- 404 Not Found
WS upgrade error: Invalid handshake response getStatus: 404 Not Found
WS Read0 ----- 404 Not Found
[id: 0x2a2b01d5, [::ffff:10.249.0.114]:50962 :> [::ffff:52.177.141.126]:443] ... wait upgrade 3 ... True
WebSocket transport onOpen: CONNECTED
SessionWS state change (1) (ok): WS_CONNECTING -> WS_CONNECTED
WS transport sending [2a2b01d5]: bind_session
LS_cause=loop1&LS_session=S0abbfd1b7bc558dcM19aT3447185&
sessionStatusChanged 1, 1
Session state change (1): FIRST_PAUSE -> FIRST_BINDING
phasing : 4 - 4
Status timeout in 4000 [bindTimeout] due to
Timeout event [currentConnectTimeoutWS]
CONNECTED:STREAM-SENSING
Timeout event [bindTimeout] while FIRST_BINDING cause=
Unable to establish session of the current type. Switching session type WS Streaming->prepare HTTP Streaming
WebSocket support has been disabled.
SessionManager state change: STREAMING_WS -> SWITCHING_STREAMING_HTTP
Switch requested phase=FIRST_BINDING cause=timeout.FIRST_BINDING.1
Sending request to the server to force a rebind on the current connection during FIRST_BINDING
Ready to dequeue control requests to be sent to server
Requested cookies for uri https://myurl/lightstreamer/control.txt?LS_protocol=TLCP-2.1.0: -futureslightstreamer=1698240888.178.56570.767405
cs ---- address: https://myurl/lightstreamer/control.txt?LS_protocol=TLCP-2.1.0, 52.177.141.126
HTTP transport connection establishing (oid=1): [url]https://futures-lightstreamer-api..com:443[/url]
/lightstreamer/control.txt?LS_protocol=TLCP-2.1.0
LS_reqId=1&LS_op=force_rebind&LS_session=S0abbfd1b7bc558dcM19aT3447185&LS_cause=timeout.FIRST_BINDING.1&

- target: 52.177.141.126:443 - True(com.lightstreamer.client.transport.providers.netty.NettyFullAddress).
HTTP channel created [6cb7edea, com.lightstreamer.client.transport.providers.netty.NettyFullAddress]: False
HTTP channel active [6cb7edea]
- acquired! 6cb7edea
Go with the request True
Send Request Task status = RanToCompletion
HTTP transport receiving [6cb7edea]:
REQOK,1

Readeable bytes: 9
Start: 0
findEol: 0 <> 9
findEol - cr: 7 eol:8
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - REQOK,1
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - REQOK,1
findEol: 9 <> 9
.:.: False(0)
linePart: 0
Reuse failed for 6cb7edea
HTTP channel inactive [6cb7edea]
... False - False
Socket Closed.
Batch completed
OnOk - REQOK,1
CONNECTED:STREAM-SENSING
Failed to switch session type. Starting new session prepare HTTP Streaming
Closing the session.
Closing session new.switch.timeout.timeout.FIRST_BINDING.1
Sending request to the server to destroy the current session during FIRST_BINDING
Pending request - post - 2
WS transport sending [2a2b01d5]: control
LS_reqId=2&LS_op=destroy&LS_cause=new.switch.timeout.timeout.FIRST_BINDING.1&
SubscriptionManager sessionAlive set to false.
pauseAllSubscriptions: 0
pauseAllSubscriptions done!
Reset message handler
Aborting pending messages
SessionManager state change: SWITCHING_STREAMING_HTTP -> SWITCHING_STREAMING_HTTP
Session ID value changed to
Server Socket Name value changed to
Client IP value changed to
Server Instance Address value changed to
sessionStatusChanged 3, 3
Session state change (1): FIRST_BINDING -> SLEEP
phasing : 5 - 5
Stop Protocol
Protocol dismissed
ws closing :com.lightstreamer.client.transport.WebSocket
Closing wsc
WebSocket transport (close): DISCONNECTED
WS disconnect [2a2b01d5]
WS channel closed [2a2b01d5]
ws closing :
SessionManager state change: SWITCHING_STREAMING_HTTP -> STREAMING_HTTP
New protocol oid=2
rhb max interval 0
rhb current interval 0
New session oid=2
Session ID value changed to
Server Socket Name value changed to
Client IP value changed to
Server Instance Address value changed to
Opening new session ...
IsOffline check now ...
... online, go!
Create Request: https://myurl
Requested cookies for uri https://myurl/lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0: -futureslightstreamer=1698240888.178.56570.767405
cs ---- address: https://myurl/lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0, 52.177.141.126
HTTP transport connection establishing (oid=2): [url]https://futures-lightstreamer-api..com:443[/url]
/lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0
LS_polling=true&LS_cause=new.switch.timeout.timeout.FIRST_BINDING.1&LS_polling_millis=0&LS_idle_millis=0&LS_cid=jqWtj1twChtfDxikwp1ltvcB4CJCJi kOj2CKDk&LS_adapter_set=Futures&LS_user=98cddc5d-e4af-49ac-89ec-7f83f8fd22c6:fa097f61-c884-4f80-b35a-b3d4c2ee5872&LS_password=AK-ca2f5093362344959abe5534fd4f49c8&LS_old_session=S0abbfd1b7bc558dcM19aT3447185&

- target: 52.177.141.126:443 - True(com.lightstreamer.client.transport.providers.netty.NettyFullAddress).
sessionStatusChanged 4, 4
Session state change (2): OFF -> CREATING
phasing : 1 - 1
Status timeout in 4000 [currentConnectTimeout] due to
HTTP channel created [6d09d700, com.lightstreamer.client.transport.providers.netty.NettyFullAddress]: False
ReleaseAsync for 2a2b01d5
ReleaseAsync -0- for False
DoReleaseChannel -0- for 2a2b01d5
DoReleaseChannel -1- for myChannelPool
DoReleaseChannel -- True
HTTP channel active [6d09d700]
- acquired! 6d09d700
Go with the request True
Send Request Task status = RanToCompletion
HTTP transport receiving [6d09d700]:
CONOK,Sc08e180f5b179934M19aT3457743,50000,0,*
SERVNAME,Lightstreamer HTTP Server
CLIENTIP,10.42.51.11
LOOP,0

Ike

Readeable bytes: 113
Start: 0
findEol: 0 <> 113
findEol - cr: 45 eol:46
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - CONOK,Sc08e180f5b179934M19aT3457743,50000,0,*
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - CONOK,Sc08e180f5b179934M19aT3457743,50000,0,*
findEol: 47 <> 113
findEol - cr: 81 eol:82
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - SERVNAME,Lightstreamer HTTP Server
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - SERVNAME,Lightstreamer HTTP Server
findEol: 83 <> 113
findEol - cr: 103 eol:104
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - CLIENTIP,10.42.51.11
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - CLIENTIP,10.42.51.11
findEol: 105 <> 113
findEol - cr: 111 eol:112
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - LOOP,0
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - LOOP,0
findEol: 113 <> 113
.:.: False(0)
linePart: 0
Reuse failed for 6d09d700
HTTP channel inactive [6d09d700]
... False - False
Socket Closed.
New message (2 - OPENING_STREAM): CONOK,Sc08e180f5b179934M19aT3457743,50000,0,*
OK event while CREATING
Address to use after create: https://myurl
Data event while CREATING
sessionStatusChanged 4, 4
Session state change (2): CREATING -> CREATED
phasing : 2 - 2
Status timeout in 2000 [executionTimeout] due to
Check Point 1a120ak.
SubscriptionManager sessionAlive set to true.
sendAllSubscriptions: 0
sendAllSubscriptions done!
Start message handler
Sending queued messages
Session ID value changed to Sc08e180f5b179934M19aT3457743
Server Instance Address value changed to https://myurl
New message (2 - READING_STREAM): SERVNAME,Lightstreamer HTTP Server
Server Socket Name value changed to Lightstreamer HTTP Server
New message (2 - READING_STREAM): CLIENTIP,10.42.51.11
Client IP value changed to 10.42.51.11
New message (2 - READING_STREAM): LOOP,0
sessionStatusChanged 4, 4
Session state change (2): CREATED -> FIRST_PAUSE
phasing : 3 - 3
Timeout event [noPause] while FIRST_PAUSE cause=
SessionManager state change: STREAMING_HTTP -> SWITCHING_STREAMING_WS
Switch requested phase=FIRST_PAUSE cause=ip
Switching current session type prepare WS Streaming
SessionManager state change: SWITCHING_STREAMING_WS -> STREAMING_WS
New protocol oid=3
rhb max interval 0
rhb current interval 0
New session oid=3
sessionStatusChanged 5, 6
Session state change (2): FIRST_PAUSE -> OFF
phasing : 4 - 4
Protocol dismissed
sessionStatusChanged 6, 6
Session state change (3): OFF -> FIRST_PAUSE
phasing : 1 - 1
SessionWS state change (3) (sendBind): WS_NOT_CONNECTED -> WS_CONNECTING
Requested cookies for uri https://myurl/lightstreamer: -futureslightstreamer=1698240888.178.56570.767405
... try get parent pool channel ... com.lightstreamer.client.transport.providers.netty.HttpPoolManager+HttpChannelPool
HTTP channel created [2fe8ac2c, com.lightstreamer.client.transport.providers.netty.NettyFullAddress]: False
WebSocket transport - : CONNECTING
Status timeout in 4000 [currentConnectTimeoutWS]
SessionWS state change (3) (sendBind): WS_CONNECTING
HTTP channel active [2fe8ac2c]
... Channel [id: 0x2fe8ac2c, [::ffff:10.249.0.114]:50971 => [::ffff:52.177.141.126]:443]
Wait WS upgrade completition.
[id: 0x2fe8ac2c, [::ffff:10.249.0.114]:50971 => [::ffff:52.177.141.126]:443] is active -> upgrade ...
[id: 0x2fe8ac2c, [::ffff:10.249.0.114]:50971 => [::ffff:52.177.141.126]:443] ... wait upgrade ... False
[id: 0x2fe8ac2c, [::ffff:10.249.0.114]:50971 => [::ffff:52.177.141.126]:443] ... wait upgrade 2 ... False
[id: 0x2fe8ac2c, [::ffff:10.249.0.114]:50971 => [::ffff:52.177.141.126]:443] ... done False - True
CONNECTED:STREAM-SENSING
... wsHandshakeHandler ...
... add ws pipeline ...
... ws handshake task: 542 - False - False - False
WS Read0 - False - Msg:AggregatedFullHttpResponse(decodeResult: success, version: HTTP/1.1, content: CompositeByteBuffer(ridx: 0, widx: 146, cap: 146, components=1))
HTTP/1.1 404 Not Found
Date:Wed, 25 Oct 2023 13:34:59 GMT
Content-Type:text/html
Content-Length:146
Connection:keep-alive
Strict-Transport-Security:max-age=15724800; includeSubDomains
WS Read0 -- 404 Not Found
WS upgrade error: Invalid handshake response getStatus: 404 Not Found
WS Read0 ----- 404 Not Found
[id: 0x2fe8ac2c, [::ffff:10.249.0.114]:50971 :> [::ffff:52.177.141.126]:443] ... wait upgrade 3 ... True
WebSocket handshake error,
SessionWS state change (3) (error): WS_CONNECTING -> WS_BROKEN
Status timeout in 0 [zeroDelay] due to ws.broken.wait
Error event while FIRST_PAUSE reason: network.error tryRecovery=True timeLeft=15000 closedOnServer=False unableToOpen=True wsError=True
WebSocket was broken while we were waiting the first bind
Unable to establish session of the current type. Switching session type WS Streaming->prepare HTTP Streaming
SessionManager state change: STREAMING_WS -> SWITCHING_STREAMING_HTTP
Switch requested phase=FIRST_PAUSE cause=network.error
Switching current session type prepare HTTP Streaming
SessionManager state change: SWITCHING_STREAMING_HTTP -> STREAMING_HTTP
New protocol oid=4
rhb max interval 0
rhb current interval 0
New session oid=4

Ike

sessionStatusChanged 7, 8
Session state change (3): FIRST_PAUSE -> OFF
phasing : 2 - 2
Stop Protocol
Protocol dismissed
ws closing :com.lightstreamer.client.transport.WebSocket
Closing wsc
WebSocket transport (close): DISCONNECTED
ws closing :
sessionStatusChanged 8, 8
Session state change (4): OFF -> FIRST_PAUSE
phasing : 1 - 1
Requested cookies for uri https://myurl/lightstreamer/bind_session.txt?LS_protocol=TLCP-2.1.0: -futureslightstreamer=1698240888.178.56570.767405
cs ---- address: https://myurl/lightstreamer/bind_session.txt?LS_protocol=TLCP-2.1.0, 52.177.141.126
HTTP transport connection establishing (oid=4): [url]https://futures-lightstreamer-api..com:443[/url]
/lightstreamer/bind_session.txt?LS_protocol=TLCP-2.1.0
LS_content_length=50000000&LS_cause=network.error&LS_session=Sc08e180f5b179934M19aT3457743&

- target: 52.177.141.126:443 - True(com.lightstreamer.client.transport.providers.netty.NettyFullAddress).
HTTP channel created [37d56971, com.lightstreamer.client.transport.providers.netty.NettyFullAddress]: False
sessionStatusChanged 8, 8
Session state change (4): FIRST_PAUSE -> FIRST_BINDING
phasing : 2 - 2
Status timeout in 4000 [bindTimeout] due to
HTTP channel active [37d56971]
- acquired! 37d56971
Go with the request True
Send Request Task status = RanToCompletion
HTTP transport receiving [37d56971]:
CONOK,Sc08e180f5b179934M19aT3457743,50000,5000,*
CLIENTIP,10.42.51.9
NOOP,sending placeholder data
NOOP,sending placeholder data
NOOP,sending placeholder data
NOOP,sending placeholde
Readeable bytes: 993
Start: 0
findEol: 0 <> 993
findEol - cr: 48 eol:49
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - CONOK,Sc08e180f5b179934M19aT3457743,50000,5000,*
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - CONOK,Sc08e180f5b179934M19aT3457743,50000,5000,*
findEol: 50 <> 993
findEol - cr: 69 eol:70
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - CLIENTIP,10.42.51.9
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - CLIENTIP,10.42.51.9
findEol: 71 <> 993
findEol - cr: 100 eol:101
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 102 <> 993
findEol - cr: 131 eol:132
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 133 <> 993
findEol - cr: 162 eol:163
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 164 <> 993
findEol - cr: 193 eol:194
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 195 <> 993
findEol - cr: 224 eol:225
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 226 <> 993
findEol - cr: 255 eol:256
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 257 <> 993
findEol - cr: 286 eol:287
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 288 <> 993
findEol - cr: 317 eol:318
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 319 <> 993
findEol - cr: 348 eol:349
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 350 <> 993
findEol - cr: 379 eol:380
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 381 <> 993
findEol - cr: 410 eol:411
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 412 <> 993
findEol - cr: 441 eol:442
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 443 <> 993
findEol - cr: 472 eol:473
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 474 <> 993
findEol - cr: 503 eol:504
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 505 <> 993
findEol - cr: 534 eol:535
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 536 <> 993
findEol - cr: 565 eol:566
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 567 <> 993
findEol - cr: 596 eol:597
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 598 <> 993
findEol - cr: 627 eol:628
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 629 <> 993
findEol - cr: 658 eol:659
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 660 <> 993
findEol - cr: 689 eol:690
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 691 <> 993
findEol - cr: 720 eol:721
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 722 <> 993
findEol - cr: 751 eol:752
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 753 <> 993

Ike

findEol - cr: 782 eol:783
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 784 <> 993
findEol - cr: 813 eol:814
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 815 <> 993
findEol - cr: 844 eol:845
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 846 <> 993
findEol - cr: 875 eol:876
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 877 <> 993
findEol - cr: 906 eol:907
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 908 <> 993
findEol - cr: 937 eol:938
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 939 <> 993
findEol - cr: 968 eol:969
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 970 <> 993
No CR.
findEol - cr: -1 eol:-1
.:.: True(23)
copyLinePart: 0 - 0
HTTP transport receiving [37d56971]:
r data
NOOP,sending placeholder data
NOOP,sending placeholder data
NOOP,sending placeholder data
NOOP,sending placeholder data
Readeable bytes: 1062
Start: 0
findEol: 0 <> 1062
findEol - cr: 6 eol:7
prev line incomplete case B: 7
copyLinePart: 23 - 23
Post copyLinePart hasHead.
toLine: 31
Temp String before: NOOP,sending placeholder data

Temp String after: NOOP,sending placeholder data
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
:.: com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 8 <> 1062
findEol - cr: 37 eol:38
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 39 <> 1062
findEol - cr: 68 eol:69
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 70 <> 1062
findEol - cr: 99 eol:100
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 101 <> 1062
findEol - cr: 130 eol:131
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 132 <> 1062
findEol - cr: 161 eol:162
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 163 <> 1062
findEol - cr: 192 eol:193
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 194 <> 1062
findEol - cr: 223 eol:224
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 225 <> 1062
findEol - cr: 254 eol:255
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 256 <> 1062
findEol - cr: 285 eol:286
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 287 <> 1062
findEol - cr: 316 eol:317
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 318 <> 1062
findEol - cr: 347 eol:348
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 349 <> 1062
findEol - cr: 378 eol:379

Ike

never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 380 <> 1062
findEol - cr: 409 eol:410
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 411 <> 1062
findEol - cr: 440 eol:441
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 442 <> 1062
findEol - cr: 471 eol:472
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 473 <> 1062
findEol - cr: 502 eol:503
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 504 <> 1062
findEol - cr: 533 eol:534
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 535 <> 1062
findEol - cr: 564 eol:565
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 566 <> 1062
findEol - cr: 595 eol:596
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 597 <> 1062
findEol - cr: 626 eol:627
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 628 <> 1062
findEol - cr: 657 eol:658
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 659 <> 1062
findEol - cr: 688 eol:689
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 690 <> 1062
findEol - cr: 719 eol:720
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 721 <> 1062
findEol - cr: 750 eol:751
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 752 <> 1062
findEol - cr: 781 eol:782
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 783 <> 1062
findEol - cr: 812 eol:813
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 814 <> 1062
findEol - cr: 843 eol:844
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 845 <> 1062
findEol - cr: 874 eol:875
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 876 <> 1062
findEol - cr: 905 eol:906
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 907 <> 1062
findEol - cr: 936 eol:937
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 938 <> 1062
findEol - cr: 967 eol:968
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 969 <> 1062
findEol - cr: 998 eol:999
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 1000 <> 1062
findEol - cr: 1029 eol:1030
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 1031 <> 1062
findEol - cr: 1060 eol:1061
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - NOOP,sending placeholder data
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - NOOP,sending placeholder data
findEol: 1062 <> 1062
.:.: False(0)
linePart: 0
HTTP transport receiving [37d56971]:
CONS,unlimited

Readeable bytes: 16
Start: 0
findEol: 0 <> 16
findEol - cr: 14 eol:15
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - CONS,unlimited
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - CONS,unlimited
findEol: 16 <> 16
.:.: False(0)
linePart: 0
New message (4 - OPENING_STREAM): CONOK,Sc08e180f5b179934M19aT3457743,50000,5000,*
OK event while FIRST_BINDING
Address to use after create: https://myurl
Keepalive Interval value changed to 5000
CurrentConnectTimeout: 4328, 4000, 328
Data event while FIRST_BINDING
sessionStatusChanged 8, 8
Session state change (4): FIRST_BINDING -> RECEIVING
phasing : 3 - 3
Offline check 1.
Status timeout in 5000 [keepaliveInterval] due to
Reset currentRetryDelay: 4000
New message (4 - READING_STREAM): CLIENTIP,10.42.51.9
Client IP value changed to 10.42.51.9
New message (4 - READING_STREAM): NOOP,sending placeholder data
New message (4 - READING_STREAM): NOOP,sending placeholder data
New message (4 - READING_STREAM): CONS,unlimited
CONNECTED:HTTP-STREAMING
Timeout event [currentConnectTimeoutWS]
CONNECTED:HTTP-STREAMING
HTTP transport receiving [37d56971]:
PROBE

Readeable bytes: 7
Start: 0
findEol: 0 <> 7
findEol - cr: 5 eol:6
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - PROBE
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - PROBE
findEol: 7 <> 7
.:.: False(0)
linePart: 0
New message (4 - READING_STREAM): PROBE
Data event while RECEIVING
Status timeout in 5000 [keepaliveInterval] due to
Cancellation requested, nothing to do.
CONNECTED:HTTP-STREAMING
HTTP transport receiving [37d56971]:
PROBE

Readeable bytes: 7
Start: 0
findEol: 0 <> 7
findEol - cr: 5 eol:6
never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - PROBE
.:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - PROBE
findEol: 7 <> 7
.:.: False(0)
linePart: 0
New message (4 - READING_STREAM): PROBE
Data event while RECEIVING
Status timeout in 5000 [keepaliveInterval] due to
Cancellation requested, nothing to do.
CONNECTED:HTTP-STREAMING
CONNECTED:HTTP-STREAMING

Giuseppe Corti

Hi Ike,

Unfortunately, switching to version 5.1.8 and enabling client-side DEBUG logging did not change the situation and did not help us understand the reason for the 404 error on the WS upgrade request.
At this point, as my colleague Dario mentioned, it is interesting to understand how the 101 request reaches the Lightstreamer server and whether it does. Can you confirm that you have access to server-side logs?

Ike

I do have access to LS server side logs.

Ike

Any specific message you need me to search for? this is the service request message I see on the server log.

25.Oct.23 20:37:09,597 < INFO> Serving request: /lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0 -->
LS_phase=1301&
LS_cause=new.api&
LS_polling=true&
LS_polling_millis=0&
LS_idle_millis=0&
LS_cid=xxxxxx&
LS_adapter_set=xxxxx&
LS_user=xxxxx
LS_password=[...]& on "Lightstreamer HTTP Server" from 10.42.51.9:52910

Giuseppe Corti

Hi Ike,

With the server log settings suggested in a previous post you should find these logs pertaining to a client session successfully bound to a websocket transport

26-Oct-23 09:32:33,112|INFO |L.connections |ACCEPT POOLED THREAD 8 |Accepted HTTP connection on "Lightstreamer HTTP Server" from 0:0:0:0:0:0:0:1:52916
26-Oct-23 09:32:33,800|INFO |L.requests |SERVER POOLED THREAD 10 |Serving request: /lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0 --> LS_polling=true&LS_cause=new.api&LS_polling_millis=0&LS_idle_millis=0&LS_cid=jqWtj1twChtfDxikwp1ltvcB4CJCJi kOj2CKDk&LS_adapter_set=WELCOME& on "Lightstreamer HTTP Server" from 0:0:0:0:0:0:0:1:52916
26-Oct-23 09:32:33,997|INFO |L.requests |SERVER POOLED THREAD 10 |Starting new session: S132b0001a335379aM2ccT3233994 (dotnet_standard_client 5.1.8 build 109) on "Lightstreamer HTTP Server" from 0:0:0:0:0:0:0:1:52916
26-Oct-23 09:32:34,046|INFO |L.pump |SERVER POOLED THREAD 10 |Session S132b0001a335379aM2ccT3233994 started.
26-Oct-23 09:32:34,077|INFO |L.connections |PUMP POOLED THREAD 8 |Reused HTTP connection on "Lightstreamer HTTP Server" from 0:0:0:0:0:0:0:1:52916
26-Oct-23 09:32:34,151|INFO |L.connections |SERVER POOLED THREAD 10 |Closed HTTP connection with internal cause code: 5 (Interrupted by client) on "Lightstreamer HTTP Server" from 0:0:0:0:0:0:0:1:52916
26-Oct-23 09:32:34,248|INFO |L.connections |ACCEPT POOLED THREAD 8 |Accepted HTTP connection on "Lightstreamer HTTP Server" from 0:0:0:0:0:0:0:1:52917
26-Oct-23 09:32:36,478|INFO |L.connections |ACCEPT POOLED THREAD 8 |Upgraded HTTP connection on subprotocol TLCP-2.1.0 on "Lightstreamer HTTP Server" from 0:0:0:0:0:0:0:1:52917
26-Oct-23 09:32:36,555|INFO |L.requests |SERVER POOLED THREAD 10 |Serving request: bind_session -> LS_cause=loop1&LS_session=S132b0001a335379aM2ccT3233994& on "Lightstreamer HTTP Server" from 0:0:0:0:0:0:0:1:52917
26-Oct-23 09:32:36,559|INFO |L.requests |SERVER POOLED THREAD 10 |Attaching session: S132b0001a335379aM2ccT3233994 on "Lightstreamer HTTP Server" from 0:0:0:0:0:0:0:1:52917

In particular the two lines bolded are the upgrade to websocket of the http channel.
In case the Lightstreamer server responds with a 404 to the upgrade request, instead of the message 'Upgraded HTTP connection on subprotocol TLCP-2.1.0...,' a DEBUG-level message from the 'LightstreamerLogger.webServer' logger should appear with error details.

Ike

Hi Giuseppe,

We set the logs on the server side and here is the log. The log starts from the bottom.

2023-10-26 12:33:40.222
26.Oct.23 17:33:40,222 < INFO> Serving request: /lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0 --> LS_polling=true&LS_cause=new.api&LS_polling_millis=0&LS_idle_millis=0&LS_cid=jqWtj1twChtfDxikwp1ltvcB4CJCJi kOj2CKDk&LS_adapter_set=xxxxx&LS_user=xxxx&LS_password=[...]& on "Lightstreamer HTTP Server" from xxxxx
2023-10-26 12:33:40.222
/lightstreamer/create_session.txt
2023-10-26 12:33:40.222
26.Oct.23 17:33:40,222 <DEBUG> Processing push request on "Lightstreamer HTTP Server" from xxxxx
2023-10-26 12:33:40.222
LS_polling=true&LS_cause=new.api&LS_polling_millis=0&LS_idle_millis=0&LS_cid=jqWtj1twChtfDxikwp1ltvcB4CJCJi kOj2CKDk&LS_adapter_set=xxxxx&LS_user=xxxx&LS_password=xxxxx&
2023-10-26 12:33:40.222
content-type: text/plain; charset=UTF-8
2023-10-26 12:33:40.222
user-agent: Lightstreamer.DotNetStandard.Client 5.1.8
2023-10-26 12:33:40.222
Content-Length: 272
2023-10-26 12:33:40.222
X-Scheme: https
2023-10-26 12:33:40.222
X-Forwarded-Proto: https
2023-10-26 12:33:40.222
X-Forwarded-Port: 443
2023-10-26 12:33:40.222
X-Forwarded-Host: xxxx
2023-10-26 12:33:40.222
X-Forwarded-For: xxxxxx
2023-10-26 12:33:40.222
X-Real-IP: xxxx
2023-10-26 12:33:40.222
X-Request-ID: 3b8bbd185b5540610fa9b045e52c924f
2023-10-26 12:33:40.222
Host: xxxx
2023-10-26 12:33:40.222
POST /lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0 HTTP/1.1
2023-10-26 12:33:40.222
26.Oct.23 17:33:40,221 <DEBUG> Parsing request on "Lightstreamer HTTP Server" from xxxxx
2023-10-26 12:33:40.222
26.Oct.23 17:33:40,221 <DEBUG> Got body of size 272 on "Lightstreamer HTTP Server" from xxxxx
2023-10-26 12:33:40.222
26.Oct.23 17:33:40,221 < INFO> Accepted HTTP connection on "Lightstreamer HTTP Server" from xxxxx
2023-10-26 12:33:40.222
26.Oct.23 17:33:40,221 <DEBUG> Socket accept on "Lightstreamer HTTP Server" from xxxxx
2023-10-26 12:33:38.573
26.Oct.23 17:33:38,572 < INFO> Closed HTTP connection with internal cause code: 10 (Read timed out) on "Lightstreamer HTTP Server" from xxxxx
2023-10-26 12:33:18.185
2023-10-26 17:33:18,184 DEBUG c.l.u.m.j.JMXMetricsCollector [pool-7-thread-5] Collected metrics
2023-10-26 12:33:18.184
2023-10-26 17:33:18,184 DEBUG c.l.u.m.j.JMXMetricsCollector [pool-7-thread-5] Collecting metrics from JMX...
2023-10-26 12:33:11.483
26.Oct.23 17:33:11,483 < INFO> Reused HTTP connection on "Lightstreamer HTTP Server" from xxxxx
2023-10-26 12:33:11.483
OK
2023-10-26 12:33:11.483
x-accel-buffering: no
2023-10-26 12:33:11.483
Content-Length: 4
2023-10-26 12:33:11.483
Date: Thu, 26 Oct 2023 17:33:11 GMT
2023-10-26 12:33:11.483
Content-Type: text/plain; charset=iso-8859-1
2023-10-26 12:33:11.483
Server: Lightstreamer-Server/7.2.2 build 2341 (Lightstreamer Server - www.lightstreamer.com) ENTERPRISE edition
2023-10-26 12:33:11.483
HTTP/1.1 200 OK
2023-10-26 12:33:11.483
26.Oct.23 17:33:11,483 <DEBUG> Writing response on "Lightstreamer HTTP Server" from xxxxx
2023-10-26 12:33:11.483
/lightstreamer/healthcheck
2023-10-26 12:33:11.483
26.Oct.23 17:33:11,482 <DEBUG> Processing push request on "Lightstreamer HTTP Server" from xxxxx
2023-10-26 12:33:11.483
Accept-Encoding: gzip,deflate,identity
2023-10-26 12:33:11.483
User-Agent: Pingdom.com_bot_version_1.4_(http://www.pingdom.com/)
2023-10-26 12:33:11.483
X-Scheme: https
2023-10-26 12:33:11.483
X-Forwarded-Proto: https
2023-10-26 12:33:11.483
X-Forwarded-Port: 443
2023-10-26 12:33:11.483
X-Forwarded-Host: xxxx
2023-10-26 12:33:11.483
X-Forwarded-For: xxxxx
2023-10-26 12:33:11.483
X-Real-IP: xxxxx
2023-10-26 12:33:11.483
X-Request-ID: 4a7ac8ee1e9a2f34c5340e2ca6e44483
2023-10-26 12:33:11.483
Host: xxxx
2023-10-26 12:33:11.483
GET /lightstreamer/healthcheck HTTP/1.1
2023-10-26 12:33:11.483
26.Oct.23 17:33:11,482 <DEBUG> Parsing request on "Lightstreamer HTTP Server" from xxxxx
2023-10-26 12:33:11.483
26.Oct.23 17:33:11,482 < INFO> Accepted HTTP connection on "Lightstreamer HTTP Server" from xxxxx
2023-10-26 12:33:11.483
2023-10-26 12:32:38.573
26.Oct.23 17:32:38,573 < INFO> Closed HTTP connection with internal cause code: 10 (Read timed out) on "Lightstreamer HTTP Server" from xxxxx
2023-10-26 12:32:18.185
2023-10-26 17:32:18,184 DEBUG c.l.u.m.j.JMXMetricsCollector [pool-7-thread-4] Collected metrics
2023-10-26 12:32:18.184
2023-10-26 17:32:18,183 DEBUG c.l.u.m.j.JMXMetricsCollector [pool-7-thread-4] Collecting metrics from JMX...
2023-10-26 12:32:11.403
26.Oct.23 17:32:11,402 < INFO> Reused HTTP connection on "Lightstreamer HTTP Server" from xxxxx
2023-10-26 12:32:11.403
OK
2023-10-26 12:32:11.403
x-accel-buffering: no
2023-10-26 12:32:11.403
Content-Length: 4
2023-10-26 12:32:11.403
Date: Thu, 26 Oct 2023 17:32:11 GMT
2023-10-26 12:32:11.403
Content-Type: text/plain; charset=iso-8859-1
2023-10-26 12:32:11.403
Server: Lightstreamer-Server/7.2.2 build 2341 (Lightstreamer Server - www.lightstreamer.com) ENTERPRISE edition
2023-10-26 12:32:11.403
HTTP/1.1 200 OK
2023-10-26 12:32:11.403
26.Oct.23 17:32:11,402 <DEBUG> Writing response on "Lightstreamer HTTP Server" from xxxxx
2023-10-26 12:32:11.403
/lightstreamer/healthcheck
2023-10-26 12:32:11.403
26.Oct.23 17:32:11,402 <DEBUG> Processing push request on "Lightstreamer HTTP Server" from xxxxx
2023-10-26 12:32:11.403
Accept-Encoding: gzip,deflate,identity
2023-10-26 12:32:11.403
User-Agent: Pingdom.com_bot_version_1.4_(http://www.pingdom.com/)
2023-10-26 12:32:11.403
X-Scheme: https
2023-10-26 12:32:11.403
X-Forwarded-Proto: https
2023-10-26 12:32:11.403
X-Forwarded-Port: 443
2023-10-26 12:32:11.403
X-Forwarded-Host: xxxx
2023-10-26 12:32:11.403
X-Forwarded-For: xxxxxxx
2023-10-26 12:32:11.403
X-Real-IP: xxxxxxx
2023-10-26 12:32:11.403
X-Request-ID: 56526eda9f70d85b7e0831483e09a5f9
2023-10-26 12:32:11.403
Host: xxxx
2023-10-26 12:32:11.403
GET /lightstreamer/healthcheck HTTP/1.1
2023-10-26 12:32:11.403
26.Oct.23 17:32:11,402 <DEBUG> Parsing request on "Lightstreamer HTTP Server" from xxxxx
2023-10-26 12:32:11.402
26.Oct.23 17:32:11,402 < INFO> Accepted HTTP connection on "Lightstreamer HTTP Server" from xxxxx
2023-10-26 12:32:11.402
26.Oct.23 17:32:11,402 <DEBUG> Socket accept on "Lightstreamer HTTP Server" from xxxxx

Ike

here's the rest of it. again it starts from the bottom.

2023-10-26 12:33:51.027
26.Oct.23 17:33:51,026 <DEBUG> Parsing request on "Lightstreamer HTTP Server" from xxxxxxx
2023-10-26 12:33:51.027
26.Oct.23 17:33:51,026 <DEBUG> Got body of size 146 on "Lightstreamer HTTP Server" from xxxxxxx
2023-10-26 12:33:51.027
26.Oct.23 17:33:51,026 < INFO> Accepted HTTP connection on "Lightstreamer HTTP Server" from xxxxxxx
2023-10-26 12:33:51.027
26.Oct.23 17:33:51,026 <DEBUG> Socket accept on "Lightstreamer HTTP Server" from xxxxxxx
2023-10-26 12:33:50.807
26.Oct.23 17:33:50,807 < INFO> Reused HTTP connection on "Lightstreamer HTTP Server" from xxxxxxx
2023-10-26 12:33:50.807
26.Oct.23 17:33:50,806 < INFO> Session S4227a9bb98d54f89M8b3T3350806 started.
2023-10-26 12:33:50.807
26.Oct.23 17:33:50,806 < INFO> Starting new session: S4227a9bb98d54f89M8b3T3350806 (dotnet_standard_client 5.1.8 build 109) on "Lightstreamer HTTP Server" from xxxxxxx
2023-10-26 12:33:50.800
26.Oct.23 17:33:50,800 < INFO> Serving request: /lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0 --> LS_polling=true&LS_cause=new.switch.timeout.timeout.FIRST_BINDING.1&LS_polling_millis=0&LS_idle_millis=0&LS_cid=jqWtj1twChtfDxikwp1ltvcB4CJCJi kOj2CKDk&LS_adapter_set=xxxxx&LS_user=xxxx&LS_password=[...]&LS_old_session=Sf35cb3885663aa23M8b3T3340342& on "Lightstreamer HTTP Server" from xxxxxxx
2023-10-26 12:33:50.800
/lightstreamer/create_session.txt
2023-10-26 12:33:50.800
26.Oct.23 17:33:50,799 <DEBUG> Processing push request on "Lightstreamer HTTP Server" from xxxxxxx
2023-10-26 12:33:50.800
LS_polling=true&LS_cause=new.switch.timeout.timeout.FIRST_BINDING.1&LS_polling_millis=0&LS_idle_millis=0&LS_cid=jqWtj1twChtfDxikwp1ltvcB4CJCJi kOj2CKDk&LS_adapter_set=xxxxx&LS_user=xxxx&LS_password=xxxxx&LS_old_session=Sf35cb3885663aa23M8b3T3340342&
2023-10-26 12:33:50.800
content-type: text/plain; charset=UTF-8
2023-10-26 12:33:50.800
user-agent: Lightstreamer.DotNetStandard.Client 5.1.8
2023-10-26 12:33:50.800
cookie: xxxxx-futureslightstreamer=1698341621.221.22712.173367
2023-10-26 12:33:50.800
Content-Length: 352
2023-10-26 12:33:50.800
X-Scheme: https
2023-10-26 12:33:50.800
X-Forwarded-Proto: https
2023-10-26 12:33:50.800
X-Forwarded-Port: 443
2023-10-26 12:33:50.800
X-Forwarded-Host: xxxx
2023-10-26 12:33:50.800
X-Forwarded-For: 192.111.84.36
2023-10-26 12:33:50.800
X-Real-IP: 192.111.84.36
2023-10-26 12:33:50.800
X-Request-ID: a2bd4f36c384cf443f4ab87e66e89dba
2023-10-26 12:33:50.800
Host: xxxx
2023-10-26 12:33:50.800
POST /lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0 HTTP/1.1
2023-10-26 12:33:50.800
26.Oct.23 17:33:50,799 <DEBUG> Parsing request on "Lightstreamer HTTP Server" from xxxxxxx
2023-10-26 12:33:50.800
26.Oct.23 17:33:50,799 <DEBUG> Got body of size 352 on "Lightstreamer HTTP Server" from xxxxxxx
2023-10-26 12:33:50.800
26.Oct.23 17:33:50,799 < INFO> Accepted HTTP connection on "Lightstreamer HTTP Server" from xxxxxxx
2023-10-26 12:33:50.800
26.Oct.23 17:33:50,799 <DEBUG> Socket accept on "Lightstreamer HTTP Server" from xxxxxxx
2023-10-26 12:33:50.344
26.Oct.23 17:33:50,343 < INFO> Session Sf35cb3885663aa23M8b3T3340342 closed after 10001 ms, initiated on "Lightstreamer HTTP Server" from xxxxx
2023-10-26 12:33:50.344
26.Oct.23 17:33:50,343 < INFO> Closed session Sf35cb3885663aa23M8b3T3340342 with internal cause code: 39/1 (Timeout waiting for client rebind after creation).
2023-10-26 12:33:46.800
26.Oct.23 17:33:46,800 < INFO> Reused HTTP connection on "Lightstreamer HTTP Server" from xxxxx
2023-10-26 12:33:46.800
REQOK,2
2023-10-26 12:33:46.800
x-accel-buffering: no
2023-10-26 12:33:46.800
Content-Length: 9
2023-10-26 12:33:46.800
Date: Thu, 26 Oct 2023 17:33:46 GMT
2023-10-26 12:33:46.800
Expires: Thu, 1 Jan 1970 00:00:00 GMT
2023-10-26 12:33:46.800
Pragma: no-cache
2023-10-26 12:33:46.800
Cache-Control: no-cache
2023-10-26 12:33:46.800
Cache-Control: no-transform
2023-10-26 12:33:46.800
Cache-Control: no-store
2023-10-26 12:33:46.800
Content-Type: text/enriched; charset=ISO-8859-1
2023-10-26 12:33:46.800
Server: Lightstreamer-Server/7.2.2 build 2341 (Lightstreamer Server - www.lightstreamer.com) ENTERPRISE edition
2023-10-26 12:33:46.800
HTTP/1.1 200 OK
2023-10-26 12:33:46.800
26.Oct.23 17:33:46,800 <DEBUG> Writing response on "Lightstreamer HTTP Server" from xxxxx
2023-10-26 12:33:46.800
26.Oct.23 17:33:46,799 < INFO> Forcing rebind on session: Sf35cb3885663aa23M8b3T3340342 on "Lightstreamer HTTP Server" from xxxxx
2023-10-26 12:33:46.800
26.Oct.23 17:33:46,799 < INFO> Serving request: /lightstreamer/control.txt?LS_protocol=TLCP-2.1.0 --> LS_reqId=2&LS_op=force_rebind&LS_session=Sf35cb3885663aa23M8b3T3340342&LS_cause=timeout.FIRST_BINDING.1& on "Lightstreamer HTTP Server" from xxxxx
2023-10-26 12:33:46.800
/lightstreamer/control.txt
2023-10-26 12:33:46.800
26.Oct.23 17:33:46,799 <DEBUG> Processing push request on "Lightstreamer HTTP Server" from xxxxx
2023-10-26 12:33:46.800
LS_reqId=2&LS_op=force_rebind&LS_session=Sf35cb3885663aa23M8b3T3340342&LS_cause=timeout.FIRST_BINDING.1&
2023-10-26 12:33:46.800
content-type: text/plain; charset=UTF-8
2023-10-26 12:33:46.800
user-agent: Lightstreamer.DotNetStandard.Client 5.1.8
2023-10-26 12:33:46.800
cookie: xxxx-futureslightstreamer=1698341621.221.22712.173367
2023-10-26 12:33:46.800
Content-Length: 106
2023-10-26 12:33:46.800
X-Scheme: https
2023-10-26 12:33:46.800
X-Forwarded-Proto: https
2023-10-26 12:33:46.800
X-Forwarded-Port: 443
2023-10-26 12:33:46.800
X-Forwarded-Host: xxxx
2023-10-26 12:33:46.800
X-Forwarded-For: xxxxx
2023-10-26 12:33:46.800
X-Real-IP: xxxxx
2023-10-26 12:33:46.800
X-Request-ID: c4b6b90c953cf976133bea881ea4474e
2023-10-26 12:33:46.800
Host: xxxx
2023-10-26 12:33:46.800
POST /lightstreamer/control.txt?LS_protocol=TLCP-2.1.0 HTTP/1.1
2023-10-26 12:33:46.800
26.Oct.23 17:33:46,799 <DEBUG> Parsing request on "Lightstreamer HTTP Server" from xxxxx
2023-10-26 12:33:46.800
26.Oct.23 17:33:46,799 <DEBUG> Got body of size 106 on "Lightstreamer HTTP Server" from xxxxx
2023-10-26 12:33:46.799
26.Oct.23 17:33:46,799 < INFO> Accepted HTTP connection on "Lightstreamer HTTP Server" from xxxxx
2023-10-26 12:33:46.799
26.Oct.23 17:33:46,799 <DEBUG> Socket accept on "Lightstreamer HTTP Server" from xxxxx
2023-10-26 12:33:40.344
26.Oct.23 17:33:40,343 < INFO> Reused HTTP connection on "Lightstreamer HTTP Server" from xxxxx
2023-10-26 12:33:40.343
26.Oct.23 17:33:40,343 < INFO> Session Sf35cb3885663aa23M8b3T3340342 started.
2023-10-26 12:33:40.343
26.Oct.23 17:33:40,342 < INFO> Starting new session: Sf35cb3885663aa23M8b3T3340342 (dotnet_standard_client 5.1.8 build 109) on "Lightstreamer HTTP Server" from xxxxx

Giuseppe Corti

Hi Ike,

In the log, there is no trace of the WebSocket protocol upgrade requests, neither successful nor any errors.
It's possible that there is an intermediary between your client and the server that intercepts WebSocket requests?
In fact, if, for any reason, WebSocket transport is blocked in your environment, it would be better to force the use of HTTP streaming with this client setting:

client.connectionOptions.ForcedTransport = "HTTP";

https://sdk.lightstreamer.com/ls-dotnetstandard-client/5.1.2/api/api/com.lightstreamer.client.ConnectionOptions.html#com_lightstreamer_client_ConnectionOptions_ForcedTransport

Ike

Hi Giuseppe, we already have JavaScript and Java client that are working fine (streaming WS) against the same server set up, so not sure why it's not working with the.NET client. Anyway, thanks for looking into this.

Ike

Also, we did some testing on the LS dotnet client locally. We were able to get it to upgrade to WS.
Problem occurs when we test with the servers in K8s. Locally we're hitting the local LS server using HTTP. The Azure K8s LS instance is HTTPS. Also there is an Nginx ingress controller in AZ K8s. Those are the only differences we can think of, besides one set of clients are JS/WebBrowsers and the other is C#.

Giuseppe Corti

Hi Ike,

This is strange, from the log you collected so far, it seems that the client send the we upgrade request bur receive a 404 error.
On the server side, it seems that the WebSocket upgrade request was never received.
To try to determine if the problem lies on the client or server side, would you be able to conduct a test by pointing your client to our demo server?
You should set "https://push.lightstreamer.com" as the URL and "WELCOME" as the adapter set.

Ike

Hi Giuseppe,

I got 502 error when I pointed to your demo server.

2023-10-30 09:01:46,581 DEBUG lightstreamer.stream - HTTP transport connection establishing (oid=1): https://push.lightstreamer.com:443
/lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0
LS_polling=true&LS_cause=new.api&LS_polling_millis=0&LS_idle_millis=0&LS_cid=jqWtj1twChtfDxikwp1ltvcB4CJCJi kOj2CKDk&LS_adapter_set=WELCOME&
2023-10-30 09:01:46,582 DEBUG lightstreamer.stream - - target: 34.217.249.182:443 - True(com.lightstreamer.client.transport.providers.netty.NettyFullAddress).
2023-10-30 09:01:46,667 DEBUG lightstreamer.netty.pool - New HTTP channel pool created. Remote address: 34.217.249.182:443
2023-10-30 09:01:46,873 DEBUG lightstreamer.session - sessionStatusChanged 1, 1
2023-10-30 09:01:46,874 DEBUG lightstreamer.session - Session state change (1): OFF -> CREATING
2023-10-30 09:01:46,877 DEBUG lightstreamer.session - phasing : 1 - 1
2023-10-30 09:01:46,881 DEBUG lightstreamer.session - Status timeout in 4000 [currentConnectTimeout] due to
2023-10-30 09:01:46,896 DEBUG lightstreamer.netty.pool - HTTP channel created [2687cef5, com.lightstreamer.client.transport.providers.netty.NettyFullAddress]: False
2023-10-30 09:01:46,975 DEBUG lightstreamer.netty.pool - HTTP channel active [2687cef5]
2023-10-30 09:01:47,006 DEBUG lightstreamer.stream - - acquired! 2687cef5
2023-10-30 09:01:47,013 DEBUG lightstreamer.stream - Go with the request True
2023-10-30 09:01:47,094 DEBUG lightstreamer.stream - Send Request Task status = RanToCompletion
2023-10-30 09:01:47,413 DEBUG lightstreamer.stream - HTTP transport receiving [2687cef5]:
CONOK,S4fb5a355a280f791M90bT0146909,50000,0,*
SERVNAME,Lightstreamer HTTPS Server
CLIENTIP,163.116.133.115
LOOP,0
2023-10-30 09:01:47,415 DEBUG lightstreamer.stream - Readeable bytes: 118
2023-10-30 09:01:47,415 DEBUG lightstreamer.stream - Start: 0
2023-10-30 09:01:47,416 DEBUG lightstreamer.stream - findEol: 0 <> 118
2023-10-30 09:01:47,417 DEBUG lightstreamer.stream - findEol - cr: 45 eol:46
2023-10-30 09:01:47,417 DEBUG lightstreamer.stream - never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - CONOK,S4fb5a355a280f791M90bT0146909,50000,0,*
2023-10-30 09:01:47,418 DEBUG lightstreamer.stream - .:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - CONOK,S4fb5a355a280f791M90bT0146909,50000,0,*
2023-10-30 09:01:47,418 DEBUG lightstreamer.stream - findEol: 47 <> 118
2023-10-30 09:01:47,419 DEBUG lightstreamer.stream - findEol - cr: 82 eol:83
2023-10-30 09:01:47,419 DEBUG lightstreamer.stream - never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - SERVNAME,Lightstreamer HTTPS Server
2023-10-30 09:01:47,419 DEBUG lightstreamer.stream - .:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - SERVNAME,Lightstreamer HTTPS Server
2023-10-30 09:01:47,419 DEBUG lightstreamer.stream - findEol: 84 <> 118
2023-10-30 09:01:47,419 DEBUG lightstreamer.stream - findEol - cr: 108 eol:109
2023-10-30 09:01:47,420 DEBUG lightstreamer.stream - never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - CLIENTIP,163.116.133.115
2023-10-30 09:01:47,420 DEBUG lightstreamer.stream - .:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - CLIENTIP,163.116.133.115
2023-10-30 09:01:47,420 DEBUG lightstreamer.stream - findEol: 110 <> 118
2023-10-30 09:01:47,420 DEBUG lightstreamer.stream - findEol - cr: 116 eol:117
2023-10-30 09:01:47,421 DEBUG lightstreamer.stream - never ending story of a message com.lightstreamer.client.transport.Http+MyHttpListener - LOOP,0
2023-10-30 09:01:47,421 DEBUG lightstreamer.stream - .:. com.lightstreamer.client.transport.providers.netty.NettyRequestListener - LOOP,0
2023-10-30 09:01:47,421 DEBUG lightstreamer.stream - findEol: 118 <> 118
2023-10-30 09:01:47,421 DEBUG lightstreamer.stream - .:.: False(0)
2023-10-30 09:01:47,421 DEBUG lightstreamer.stream - linePart: 0
2023-10-30 09:01:47,422 DEBUG lightstreamer.stream - Reuse failed for 2687cef5
2023-10-30 09:01:47,437 DEBUG lightstreamer.netty.pool - HTTP channel inactive [2687cef5]
2023-10-30 09:01:47,437 DEBUG lightstreamer.netty.pool - ... False - False
2023-10-30 09:01:47,437 DEBUG lightstreamer.netty.pool - Socket Closed.
2023-10-30 09:01:47,441 DEBUG lightstreamer.protocol - New message (1 - OPENING_STREAM): CONOK,S4fb5a355a280f791M90bT0146909,50000,0,*
2023-10-30 09:01:47,444 DEBUG lightstreamer.session - OK event while CREATING
2023-10-30 09:01:47,444 DEBUG lightstreamer.session - Address to use after create: https://push.lightstreamer.com/
2023-10-30 09:01:47,444 DEBUG lightstreamer.session - Data event while CREATING
2023-10-30 09:01:47,444 DEBUG lightstreamer.session - sessionStatusChanged 1, 1
2023-10-30 09:01:47,444 DEBUG lightstreamer.session - Session state change (1): CREATING -> CREATED
2023-10-30 09:01:47,445 DEBUG lightstreamer.session - phasing : 2 - 2
2023-10-30 09:01:47,445 DEBUG lightstreamer.session - Status timeout in 2000 [executionTimeout] due to
2023-10-30 09:01:47,445 DEBUG lightstreamer.session - Check Point 1a120ak.
2023-10-30 09:01:47,445 DEBUG lightstreamer.subscribe - SubscriptionManager sessionAlive set to true.
2023-10-30 09:01:47,446 DEBUG lightstreamer.subscribe - sendAllSubscriptions: 0
2023-10-30 09:01:47,447 DEBUG lightstreamer.subscribe - sendAllSubscriptions done!
2023-10-30 09:01:47,448 INFO lightstreamer.subscribe - Start message handler
2023-10-30 09:01:47,448 DEBUG lightstreamer.subscribe - Sending queued messages
2023-10-30 09:01:47,450 INFO lightstreamer.actions - Session ID value changed to S4fb5a355a280f791M90bT0146909
2023-10-30 09:01:47,450 INFO lightstreamer.actions - Server Instance Address value changed to https://push.lightstreamer.com/
2023-10-30 09:01:47,450 DEBUG lightstreamer.protocol - New message (1 - READING_STREAM): SERVNAME,Lightstreamer HTTPS Server
2023-10-30 09:01:47,451 INFO lightstreamer.actions - Server Socket Name value changed to Lightstreamer HTTPS Server
2023-10-30 09:01:47,451 DEBUG lightstreamer.protocol - New message (1 - READING_STREAM): CLIENTIP,163.116.133.115
2023-10-30 09:01:47,451 INFO lightstreamer.actions - Client IP value changed to 163.116.133.115
2023-10-30 09:01:47,451 DEBUG lightstreamer.protocol - New message (1 - READING_STREAM): LOOP,0
2023-10-30 09:01:47,453 DEBUG lightstreamer.session - sessionStatusChanged 1, 1
2023-10-30 09:01:47,453 DEBUG lightstreamer.session - Session state change (1): CREATED -> FIRST_PAUSE
2023-10-30 09:01:47,453 DEBUG lightstreamer.session - phasing : 3 - 3
2023-10-30 09:01:47,454 DEBUG lightstreamer.session - Timeout event [noPause] while FIRST_PAUSE cause=
2023-10-30 09:01:47,455 DEBUG lightstreamer.session - SessionWS state change (1) (sendBind): WS_NOT_CONNECTED -> WS_CONNECTING
2023-10-30 09:01:47,457 INFO lightstreamer.stream - Requested cookies for uri https://push.lightstreamer.com/lightstreamer:
2023-10-30 09:01:47,460 DEBUG lightstreamer.netty.pool - New WS channel pool created. Remote address: 34.217.249.182:4432023-10-30 09:01:47,462 DEBUG lightstreamer.netty.pool - ... try get parent pool channel ... com.lightstreamer.client.transport.providers.netty.HttpPoolManager+HttpChannelPool
2023-10-30 09:01:47,464 DEBUG lightstreamer.netty.pool - HTTP channel created [63a8f9c9, com.lightstreamer.client.transport.providers.netty.NettyFullAddress]: False
2023-10-30 09:01:47,467 DEBUG lightstreamer.stream - WebSocket transport - : CONNECTING
2023-10-30 09:01:47,467 DEBUG lightstreamer.requests - Status timeout in 4000 [currentConnectTimeoutWS]
2023-10-30 09:01:47,467 DEBUG lightstreamer.session - SessionWS state change (1) (sendBind): WS_CONNECTING
2023-10-30 09:01:47,536 DEBUG lightstreamer.netty.pool - HTTP channel active [63a8f9c9]
2023-10-30 09:01:47,539 DEBUG lightstreamer.netty.pool - ... Channel [id: 0x63a8f9c9, [::ffff:192.168.86.150]:53426 => [::ffff:34.217.249.182]:443]
2023-10-30 09:01:47,540 DEBUG lightstreamer.netty.pool - Wait WS upgrade completition.
2023-10-30 09:01:47,541 DEBUG lightstreamer.netty.pool - [id: 0x63a8f9c9, [::ffff:192.168.86.150]:53426 => [::ffff:34.217.249.182]:443] is active -> upgrade ...
2023-10-30 09:01:47,542 DEBUG lightstreamer.netty.pool - [id: 0x63a8f9c9, [::ffff:192.168.86.150]:53426 => [::ffff:34.217.249.182]:443] ... wait upgrade ... False
CONNECTED:STREAM-SENSING
2023-10-30 09:01:49,554 DEBUG lightstreamer.netty.pool - ... wsHandshakeHandler ...
2023-10-30 09:01:49,557 DEBUG lightstreamer.netty.pool - ... add ws pipeline ...
2023-10-30 09:01:49,576 DEBUG lightstreamer.netty.pool - ... ws handshake task: 212 - False - False - False
2023-10-30 09:01:49,577 DEBUG lightstreamer.netty.pool - [id: 0x63a8f9c9, [::ffff:192.168.86.150]:53426 => [::ffff:34.217.249.182]:443] ... wait upgrade 2 ... False
2023-10-30 09:01:49,581 DEBUG lightstreamer.netty.pool - [id: 0x63a8f9c9, [::ffff:192.168.86.150]:53426 => [::ffff:34.217.249.182]:443] ... done False - True
2023-10-30 09:01:50,448 DEBUG lightstreamer.netty.pool - WS Read0 - False - Msg:AggregatedFullHttpResponse(decodeResult: success, version: HTTP/1.1, content: CompositeByteBuffer(ridx: 0, widx: 1326, cap: 1326, components=2))
HTTP/1.1 502 Bad Gateway
Connection:close
Content-Length:1326
2023-10-30 09:01:50,449 DEBUG lightstreamer.netty.pool - WS Read0 -- 502 Bad Gateway
2023-10-30 09:01:50,452 INFO lightstreamer.netty.pool - WS upgrade error: Invalid handshake response getStatus: 502 Bad Gateway
2023-10-30 09:01:50,452 DEBUG lightstreamer.netty.pool - WS Read0 ----- 502 Bad Gateway

Giuseppe Corti

It seems that in your client's environment, there is something interfering with the WebSocket upgrade requests.

Next Page »