Proxy usage is broken since v4.5.0 (switch to axios)

[jbsil]

Description

I am unable to get WebClient to connect using any proxy on versions 4.5.0 or 4.6.0. Proxies work correctly on v4.4.0. I believe this is due to the change from got to axios #620
Also, since RTMClient internally uses a WebClient (for initial authentication?), that also does not work. This is reliably reproducible with multiple proxies.

What type of issue is this? (place an x in one of the [ ])

• bug
• enhancement (feature request)
• question
• documentation related
• testing related
• discussion

Requirements (place an x in each of the [ ])

• I've read and understood the Contributing guidelines and have done my best effort to follow them.
• I've read and agree to the Code of Conduct.
• I've searched for any related issues and avoided creating a duplicate issue.

---

Bug Report

Filling out the following details about bugs will help us solve your issue sooner.

Reproducible in:

@slack/client version: 4.5.0, 4.6.0

node version: 6.11.4

OS version(s): docker hub's node 6-alpine image

Steps to reproduce:

1. Set up an https-proxy-agent
2. Use {agent: proxyAgent} when creating an RTMClient
3. list to .on('hello') and .start() the client

Expected result:

Receive a hello event from Slack

Actual result:

[DEBUG] @slack/client:WebClient0 will perform http request
[DEBUG] @slack/client:WebClient0 http request failed
[DEBUG] @slack/client:WebClient0 will perform http request
[DEBUG] @slack/client:WebClient0 http request failed
[DEBUG] @slack/client:WebClient0 will perform http request
[DEBUG] @slack/client:WebClient0 http request failed

[aoberoi]

Thanks for the info and sorry for the inconvenience, @jbsil. For now, the workaround is to use an earlier version until we can fix this up. We’ll let you know if we need any more info from you.

[aoberoi]

I just heard from another user experiencing this issue. they were able to workaround without downgrading by setting the agent option to an object with key(s) http and/or https.

for example, change {agent: proxyAgent} to {agent: { http: proxyAgent, https: proxyAgent } }.

i just want to be clear, this still sounds like a bug and we should fix it, but i wanted to make the more preferred workaround known.

[DornieDortsch]

Looks like Fix #642 not working for me.

I try to connect with RTMClient behind a http proxy. I use Version 4.8.0 of node-slack-sdk. The Client request fails and retries forever. No error is reported! With Version 4.4.0 everything is OK.

Here is the log when I execute sample Project: https://github.com/DornieDortsch/node-slack-sdk-bug

"@slack/client": "^4.8.0"

> node ./index.js

@slack/client:WebClient0 "initialized"
@slack/client:RTMClient2 "transitioning to state: disconnected"
@slack/client:RTMClient2 "pausing outgoing event queue"
@slack/client:RTMClient2 "initialized"
@slack/client:RTMClient2 "start()"
@slack/client:RTMClient2 "transitioning to state: connecting"
@slack/client:RTMClient2 "transitioning to state: connecting:authenticating"
@slack/client:WebClient0 "apiCall() start"
@slack/client:WebClient0 "shouldAutoPaginate: false"
@slack/client:WebClient0 "will perform http request"
@slack/client:WebClient0 "http response received"
@slack/client:WebClient0 "http request failed"
@slack/client:WebClient0 "will perform http request"
@slack/client:WebClient0 "http response received"
@slack/client:WebClient0 "http request failed"
@slack/client:WebClient0 "will perform http request"
@slack/client:WebClient0 "http response received"
@slack/client:WebClient0 "http request failed"
@slack/client:WebClient0 "will perform http request"
@slack/client:WebClient0 "http response received"
@slack/client:WebClient0 "http request failed"

"@slack/client": "4.4.0"

> node ./index.js

@slack/client:WebClient0 "initialized"
@slack/client:RTMClient2 "transitioning to state: disconnected"
@slack/client:RTMClient2 "pausing outgoing event queue"
@slack/client:RTMClient2 "initialized"
@slack/client:RTMClient2 "start()"
@slack/client:RTMClient2 "transitioning to state: connecting"
@slack/client:RTMClient2 "transitioning to state: connecting:authenticating"
@slack/client:WebClient0 "apiCall() start"
@slack/client:WebClient0 "shouldAutoPaginate: false"
@slack/client:WebClient0 "will perform http request"
@slack/client:WebClient0 "http response received"
@slack/client:RTMClient2 "transitioning to state: connecting:authenticated"
@slack/client:RTMClient2 "transitioning to state: connecting:handshaking"
@slack/client:RTMClient2 "received message on websocket: {\"type\": \"hello\"}"
@slack/client:RTMClient2 "transitioning to state: connected"
Connected!
@slack/client:RTMClient2 "transitioning to state: connected:resuming"
@slack/client:RTMClient2 "transitioning to state: connected:ready"
@slack/client:KeepAlive1 "start monitoring"
@slack/client:KeepAlive1 "setting ping timer"
@slack/client:RTMClient2 "resuming outgoing event queue"
@slack/client:KeepAlive1 "ping timer expired, sending ping"
@slack/client:RTMClient2 "send() in state: connected,ready"
@slack/client:KeepAlive1 "setting ping timer"
@slack/client:RTMClient2 "sending message on websocket: {\"type\":\"ping\",\"id\":1}"
@slack/client:KeepAlive1 "setting pong timer"
@slack/client:RTMClient2 "received message on websocket: {\"type\":\"pong\",\"reply_to\":1}"
@slack/client:KeepAlive1 "received pong, clearing pong timer"
@slack/client:KeepAlive1 "ping timer expired, sending ping"
@slack/client:RTMClient2 "send() in state: connected,ready"
@slack/client:KeepAlive1 "setting ping timer"
@slack/client:RTMClient2 "sending message on websocket: {\"type\":\"ping\",\"id\":2}"
@slack/client:KeepAlive1 "setting pong timer"
@slack/client:RTMClient2 "received message on websocket: {\"type\":\"pong\",\"reply_to\":2}"
@slack/client:KeepAlive1 "received pong, clearing pong timer"
@slack/client:KeepAlive1 "ping timer expired, sending ping"
@slack/client:RTMClient2 "send() in state: connected,ready"
@slack/client:KeepAlive1 "setting ping timer"
@slack/client:RTMClient2 "sending message on websocket: {\"type\":\"ping\",\"id\":3}"
@slack/client:KeepAlive1 "setting pong timer"
@slack/client:RTMClient2 "received message on websocket: {\"type\":\"pong\",\"reply_to\":3}"
@slack/client:KeepAlive1 "received pong, clearing pong timer"
@slack/client:KeepAlive1 "ping timer expired, sending ping"
@slack/client:RTMClient2 "send() in state: connected,ready"
@slack/client:KeepAlive1 "setting ping timer"
@slack/client:RTMClient2 "sending message on websocket: {\"type\":\"ping\",\"id\":4}"
@slack/client:KeepAlive1 "setting pong timer"
@slack/client:RTMClient2 "received message on websocket: {\"type\":\"pong\",\"reply_to\":4}"
@slack/client:KeepAlive1 "received pong, clearing pong timer"

Reproducible in:

@slack/client version: 4.8.0

node version: v8.11.3

OS version(s): macOS 10.14.1

Steps to reproduce:

1. Run sample Project

Expected result:

Connecting to Slack or log error

Actual result:

Not connecting to slack and not reporting error

[aoberoi]

thanks for reporting and providing the sample code @DornieDortsch. i'm reopening the issue now.

this issue will likely get attention from our team in the next week or two. as always, feel free to dig in in the meantime.

[aoberoi]

@DornieDortsch i'm not able to reproduce this one, but let me describe what i'm doing and maybe you can help me see where your set up is different.

i'm using Charles Proxy on my mac, which is using the default proxy configuration (port 8888). i clone your repo, and created a new .env file. i put the following contents in that file:

TOKEN=xoxb-REDACTED
PROXY_URL=http://localhost:8888

then i did an npm install and started the application with node index.js. everything worked.

next, i downgraded to @slack/client@4.4.0 by updating the entry in package.json, wiped out the package-lock.json and the node_modules directory, did another npm install and ran once again using node index.js. everything worked again.

one random thought: if your proxy has its own self-signed certificate, you might need to use the tls options in the SDK to get the code talking to that proxy properly. however, that shouldn't have changed between v4.4.0 and v4.8.0.

[DornieDortsch]

@aoberoi the steps you take to reproduce the error are correct.

I think it's a special problem with my proxy setup. We have to use http proxy for http and https requests. Looks like axios didn't play well with this setup.

I added print to get the error message at WebClient makeRequest function. Here is the message:

http request failed Error: An HTTP protocol error occurred: statusCode = 403

I take some time to get the right axios setup.

[DornieDortsch]

Yeah I found the problem!

There is a "automatic proxy detection" feature at axios library. Therefore axios take the https_proxy environment variable configured on my system. This will interfere with the agent setup. So axios will use https for the proxy host, which is not accessible on my system.

You can reproduce this by setting environment variable https_proxy=http://localhost:8888. If I remove this variable, everething works fine!

Maybe it's a good option to disable automatic proxy detection by default.

axios.create({
    ...
    proxy: false
});

This article bring me on the right path https://janmolak.com/node-js-axios-behind-corporate-proxies-8b17a6f31f9d

PS: Logging the exact error message at debug level would help finding errors faster.

[aoberoi]

@DornieDortsch yay! thanks for digging deeper and sharing your findings back with the rest of us. this is super helpful and it makes sense.

i'm going to make another issue to discuss your suggestion of disabling the automatic proxy detection using the environment variable.

in terms of logging, i'm not sure if its wise to output that level of detail, but i can be convinced. in theory, the promise would be rejected with an error that contains that detail, so you should be able to log it yourself. i think the only reason that wasn't apparent here is because automatic retries were going to occur for the next ~30 minutes before you saw the final rejected error, but this is the expected behavior. i think a good debugging step should have been to turn retries off to see what the underlying error was, but neither of us thought of that. 🤔