PoshBot websocket issues

[RamblingCookieMonster]

Initial activities (e.g. querying users) that hit non real time API endpoints work without issue. Websocket connectivity does not function, breaking poshbot

Expected Behavior

Poshbot works

Current Behavior

Poshbot does not work:

VERBOSE: {"DataTime":"2020-03-04 15:57:37Z","Class":"Bot","Method":"Start","Severity":"Normal","LogLevel":"Info","Message":"Beginning message processing loop","Data":{}}
WARNING: {"DataTime":"2020-03-04 15:57:37Z","Class":"SlackConnection","Method":"ReadReceiveJob","Severity":"Warning","LogLevel":"Info","Message":"Websocket state is [Closed].\nState                  : Closed\r\nClose
Status            : \r\nCloseStatusDescription :","Data":{}}
WARNING: {"DataTime":"2020-03-04 15:57:37Z","Class":"SlackConnection","Method":"ReadReceiveJob","Severity":"Warning","LogLevel":"Info","Message":"Receive job state is [Completed]. Attempting to reconnect...","Data":{
}}
VERBOSE: {"DataTime":"2020-03-04 15:57:42Z","Class":"SlackConnection","Method":"Connect","Severity":"Normal","LogLevel":"Debug","Message":"Connecting to Slack Real Time API","Data":{}}
VERBOSE: {"DataTime":"2020-03-04 15:57:43Z","Class":"SlackConnection","Method":"RtmConnect","Severity":"Normal","LogLevel":"Info","Message":"Successfully authenticated to Slack Real Time API","Data":{}}
VERBOSE: {"DataTime":"2020-03-04 15:57:43Z","Class":"SlackConnection","Method":"StartReceiveJob","Severity":"Normal","LogLevel":"Info","Message":"Started websocket receive job [29]","Data":{}}
WARNING: {"DataTime":"2020-03-04 15:57:44Z","Class":"SlackConnection","Method":"ReadReceiveJob","Severity":"Warning","LogLevel":"Info","Message":"Websocket state is [Closed].\nState                  : Closed\r\nClose
Status            : \r\nCloseStatusDescription :","Data":{}}
WARNING: {"DataTime":"2020-03-04 15:57:44Z","Class":"SlackConnection","Method":"ReadReceiveJob","Severity":"Warning","LogLevel":"Info","Message":"Receive job state is [Completed]. Attempting to reconnect...","Data":{
}}
VERBOSE: {"DataTime":"2020-03-04 15:57:49Z","Class":"SlackConnection","Method":"Connect","Severity":"Normal","LogLevel":"Debug","Message":"Connecting to Slack Real Time API","Data":{}}
VERBOSE: {"DataTime":"2020-03-04 15:57:49Z","Class":"SlackConnection","Method":"RtmConnect","Severity":"Normal","LogLevel":"Info","Message":"Successfully authenticated to Slack Real Time API","Data":{}}
VERBOSE: {"DataTime":"2020-03-04 15:57:49Z","Class":"SlackConnection","Method":"StartReceiveJob","Severity":"Normal","LogLevel":"Info","Message":"Started websocket receive job [31]","Data":{}}
WARNING: {"DataTime":"2020-03-04 15:57:50Z","Class":"SlackConnection","Method":"ReadReceiveJob","Severity":"Warning","LogLevel":"Info","Message":"Websocket state is [Closed].\nState                  : Closed\r\nClose
Status            : \r\nCloseStatusDescription :","Data":{}}
WARNING: {"DataTime":"2020-03-04 15:57:50Z","Class":"SlackConnection","Method":"ReadReceiveJob","Severity":"Warning","LogLevel":"Info","Message":"Receive job state is [Completed]. Attempting to reconnect...","Data":{
}}

Issue appears to be in StartReceiveJob. while ($webSocket.State -eq [System.Net.WebSockets.WebSocketState]::Open) { is never true

Steps to Reproduce (for bugs)

Run the latest poshbot on Windows Server 2012 R2. Unclear whether other newer versions of Windows are affected 4.

Context

Poshbot does not function

Your Environment

• Module version used: 11.6 and 11.8
• Operating System and PowerShell version: Server 2012 R2

Name                           Value                                                                                                                                                                                   
----                           -----                                                                                                                                                                                   
PSVersion                      5.1.14409.1018                                                                                                                                                                          
PSEdition                      Desktop                                                                                                                                                                                 
PSCompatibleVersions           {1.0, 2.0, 3.0, 4.0...}                                                                                                                                                                 
BuildVersion                   10.0.14409.1018                                                                                                                                                                         
CLRVersion                     4.0.30319.34014                                                                                                                                                                         
WSManStackVersion              3.0                                                                                                                                                                                     
PSRemotingProtocolVersion      2.3                                                                                                                                                                                     
SerializationVersion           1.1.0.1     

@ joshcorr also mentioned Server 2016 is impacted (older poshbot version)

Sigh

[devblackops]

Thanks @RamblingCookieMonster. I'll dig in.

[RamblingCookieMonster]

Ahh, I’ve verified with wireshark that the websocket connections are using tlsv1 and thus not functioning now that slack requires tlsv1.2. Not sure how to force tlsv1.2 with websockets (the usual invoke-restmethod calls work without issue)

[joshcorr]

Fixed this in our situation by adding [Net.ServicePointManager]::SecurityProtocol = [Net.SecurityProtocolType]::Tls12 in the following section of code.

[void]StartReceiveJob() {
        $recv = {
            [cmdletbinding()]
            param(
                [parameter(mandatory)]
                $url
            )

            # Connect to websocket
            [Net.ServicePointManager]::SecurityProtocol = [Net.SecurityProtocolType]::Tls12
            Write-Verbose "[SlackBackend:ReceiveJob] Connecting to websocket at [$($url)]"
            [System.Net.WebSockets.ClientWebSocket]$webSocket = New-Object System.Net.WebSockets.ClientWebSocket
            $cts = New-Object System.Threading.CancellationTokenSource

[aewald303]

@joshcorr Good find! Can confirm that also worked in our environment.

[dustman7g]

Unfortunately we are not seeing the same results by adding the TLS 1.2 enforcement in that section of the code. We are running on Window Server 2016, powershell version 5.1, and Module version 11.6.

[RamblingCookieMonster]

The basic idea is that all calls to slack require TLSv1.2. The snippet above resolves the websocket issue, as it runs within a job with separate context (i.e. if you enabled TLSv1.2, it won't be enabled until you add that line in the job code). You also need to set this up for everything else. Later versions of poshbot require psslack 1.0.2, which sets TLSv1.2 when the module loads. You can go that route (upgrade poshbot and thus psslack), or you can add the TLSv1.2 line elsewhere (e.g. in the script you run for the poshbot service).

Lastly - Rather than overriding the existing security protocols, add TLSv1.2 like this, if you don't want to accidentally break services that don't support TLSv1.2:

[Net.ServicePointManager]::SecurityProtocol = [Net.ServicePointManager]::SecurityProtocol -bor [Net.SecurityProtocolType]::Tls12

Cheers!

[TomWoodling]

I have version 0.11.8 of PoshBot and 1.0.2 of PSSlack installed and I still run into this exact problem. I can use the PSSlack commands and they work fine, but none of my bots can establish a connection to Slack wherever I add the TLS1.2 line - tried various locations, even overwriting the 'Connect to Websocket' section in PoshBot.psm1 to include it and still no joy.

[aewald303]

In your logs if you are getting a 426 error from slack you will need to keep the bot off for awhile to allow the rate limit to clear.

Also, I did open a ticket with slack and they sent me this if it's of any worth to the developers.

I checked the logs, and it appears that you're calling our rtm.start API method about 7-10 times/minute, and the rate limit on that method is no more than one request per minute. It's possible that your script is retrying because it isn't able to obtain a successful connection.

Along the same lines, we've determined that the rtm.start API method is less efficient than we'd like so we've asked all developers to migrate over to using our rtm.connect API method instead (https://api.slack.com/methods/rtm.connect). We also announced this in our Platform change log here:

https://api.slack.com/changelog/2017-04-start-using-rtm-connect-and-stop-using-rtm-start

Hopefully, you're able to make that change, and doing that helps to eliminate these errors and additionally improve performance.

[devblackops]

I put a fix https://github.com/poshbotio/PoshBot/commit/1c7e285d627c932a8d12fbe90365da457efd8024 to ensure TLS12 is set in the websocket receive job.

[devblackops]

If anyone still can't connect, even after setting [Net.ServicePointManager]::SecurityProtocol = [Net.ServicePointManager]::SecurityProtocol -bor [Net.SecurityProtocolType]::Tls12 in [void]StartReceiveJob() like @joshcorr noted, here is a minimal repo script to connect to Slack's RTM websocket API and receive messages.

https://gist.github.com/devblackops/28afca76db2e1b5ed4fbd3eedf7c94cc

If this script works and you see messages show up as you type in Slack, then your system is using TLS12.

[tenwiseman]

Hi, brief note to say thanks for the fix 1c7e285. Works fine (PSVersion: 5.1.14409.1005 / Server 2012R2)

[devblackops]

v0.12.0 has been released with the fix!

https://www.powershellgallery.com/packages/PoshBot/0.12.0

[RamblingCookieMonster]

Closing this out, thanks all : D

[dustman7g]

Hello All - I am still having issues after the fix. Has anyone had to do anything else to get this working?

This is the error I am finding. Result : Id : 30 Exception : System.AggregateException: One or more errors occurred. ---> System.Net.WebSockets.WebSocketException: Unable to connect to the remote server ---> System.Net.WebException: The request was aborted: Could not create SSL/TLS secure channel. at System.Net.HttpWebRequest.EndGetResponse(IAsyncResult asyncResult) at System.Threading.Tasks.TaskFactory1.FromAsyncCoreLogic(IAsyncResult iar, Func2 endFunction, Action1 endAction, Task`1 promise, Boolean requiresSynchronization) --- End of stack trace from previous location where exception was thrown

                        at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
                        at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebu
                     ggerNotification(Task task)
                        at 
                     System.Net.WebSockets.ClientWebSocket.<ConnectAsyncCore>d__21.MoveNext()
                        --- End of inner exception stack trace ---
                        at 
                     System.Net.WebSockets.ClientWebSocket.<ConnectAsyncCore>d__21.MoveNext()
                        --- End of inner exception stack trace ---
                     ---> (Inner Exception #0) System.Net.WebSockets.WebSocketException 
                     (0x80004005): Unable to connect to the remote server ---> 
                     System.Net.WebException: The request was aborted: Could not create 
                     SSL/TLS secure channel.
                        at System.Net.HttpWebRequest.EndGetResponse(IAsyncResult asyncResult)
                        at 
                     System.Threading.Tasks.TaskFactory`1.FromAsyncCoreLogic(IAsyncResult 
                     iar, Func`2 endFunction, Action`1 endAction, Task`1 promise, Boolean 
                     requiresSynchronization)
                     --- End of stack trace from previous location where exception was thrown 
                     ---
                        at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
                        at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebu
                     ggerNotification(Task task)
                        at 
                     System.Net.WebSockets.ClientWebSocket.<ConnectAsyncCore>d__21.MoveNext()
                        at System.Net.WebSockets.ClientWebSocket.<ConnectAsyncCore>d__21.MoveN
                     ext()<---

Status : Faulted IsCanceled : False IsCompleted : True CreationOptions : None AsyncState : IsFaulted : True AsyncWaitHandle : System.Threading.ManualResetEvent CompletedSynchronously : False`

[devblackops]

@dustman7g Where are you seeing that error? What OS/PowerShell/PoshBot version?

[dustman7g]

We are running on Window Server 2016, powershell version 5.1, and Module version `v0.12.0.

I am seeing the error in $task in websocket recieve job.

Setup the websocket receive job

[void]StartReceiveJob() {
    $recv = {
        [cmdletbinding()]
        param(
            [parameter(mandatory)]
            $url
        )

        # Slack enforces TLS12 on the websocket API
        [Net.ServicePointManager]::SecurityProtocol = [Net.ServicePointManager]::SecurityProtocol -bor [Net.SecurityProtocolType]::Tls12

        # Connect to websocket
        Write-Verbose "[SlackBackend:ReceiveJob] Connecting to websocket at [$($url)]"
        [System.Net.WebSockets.ClientWebSocket]$webSocket = New-Object System.Net.WebSockets.ClientWebSocket
        $cts = New-Object System.Threading.CancellationTokenSource
        $task = $webSocket.ConnectAsync($url, $cts.Token)`