anycable / anycable-rails

AnyCable for Ruby on Rails applications
https://anycable.io
MIT License
495 stars 35 forks source link

Permissions Error when Deploying AnyCable to Heroku #175

Closed rmdashrfv closed 2 years ago

rmdashrfv commented 2 years ago

Tell us about your environment

Ruby 3.0.3 Rails 7.0.3.1

Gem versions: anycable 1.2.3 anycable-rails ~> 1.3, >= 1.3.4 grpc ~> 1.37

What did you do?

Tried to deploy to Heroku after following the documentation exactly. Using the procfile provided at the top. https://docs.anycable.io/deployment/heroku?id=heroku-deployment

What did you expect to happen?

The AnyCable server should start and begin listening on the heroku app, as it does in development environments. This is what happens when I run the command locally:

Starting AnyCable RPC server (pid: 82855)
AnyCable version: 1.2.3 (proto_version: v1)
Serving Rails application from ./config/environment.rb
gRPC version: 1.48.0
Broadcasting Redis channel: __anycable__
RPC server is starting...
RPC server is listening on localhost:50051 (workers_num: 30)
Started command: anycable-go (pid: 83264)
  INFO 2022-07-31T13:39:21.104Z context=main Starting AnyCable 1.2.0 (pid: 83264, open file limit: 2560)
  INFO 2022-07-31T13:39:21.104Z context=main Handle WebSocket connections at http://localhost:8080/cable
  INFO 2022-07-31T13:39:21.104Z context=main Handle health connections at http://localhost:8080/health
  INFO 2022-07-31T13:39:21.105Z context=rpc RPC controller initialized: localhost:50051 (concurrency: 28, enable_tls: false, proto_versions: v1)
  INFO 2022-07-31T13:39:21.111Z context=pubsub Subscribed to Redis channel: __anycable__

What actually happened?

The app crashes upon starting. It appears as though there's some issue binding the address 0.0.0.0 in production. Is this due to Heroku not supporting HTTP/2? Or should I pass the --rpc-host flag something very specific? I have been trying to deploy by passing the --rpc-host flag various things and none of them seem to work.

It could be that as Heroku has updated their system, this configuration is no longer allowed? Perhaps downgrading my Heroku stack from 20 to a lower number?

2022-07-31T13:25:16.269521+00:00 app[web.1]: I, [2022-07-31T09:25:16.269419 #6]  INFO -- : Starting AnyCable RPC server (pid: 6)
2022-07-31T13:25:16.269537+00:00 app[web.1]: I, [2022-07-31T09:25:16.269500 #6]  INFO -- : AnyCable version: 1.2.3 (proto_version: v1)
2022-07-31T13:25:16.269538+00:00 app[web.1]: I, [2022-07-31T09:25:16.269523 #6]  INFO -- : Serving Rails application from ./config/environment.rb
2022-07-31T13:25:16.269617+00:00 app[web.1]: I, [2022-07-31T09:25:16.269592 #6]  INFO -- : gRPC version: 1.48.0
2022-07-31T13:25:16.271116+00:00 app[web.1]: E0731 09:25:16.271076067       6 chttp2_server.cc:1080]      UNKNOWN:No address added out of total 1 resolved for '0.0.0.0' {created_time:"2022-07-31T09:25:16.270715041-04:00", children:[UNKNOWN:Failed to add any wildcard listeners {created_time:"2022-07-31T09:25:16.270705545-04:00", children:[UNKNOWN:Unable to configure socket {fd:7, created_time:"2022-07-31T09:25:16.270653105-04:00", children:[UNKNOWN:Permission denied {created_time:"2022-07-31T09:25:16.270612873-04:00", errno:13, os_error:"Permission denied", syscall:"bind"}]}, UNKNOWN:Unable to configure socket {created_time:"2022-07-31T09:25:16.270701608-04:00", fd:7, children:[UNKNOWN:Permission denied {syscall:"bind", os_error:"Permission denied", errno:13, created_time:"2022-07-31T09:25:16.270695705-04:00"}]}]}]}
2022-07-31T13:25:16.271156+00:00 app[web.1]: could not add port 0.0.0.0 to server, not sure why
2022-07-31T13:25:16.272368+00:00 app[web.1]: /app/vendor/ruby-3.0.3/lib/ruby/3.0.0/forwardable.rb:238:in `add_http2_port'
2022-07-31T13:25:16.272368+00:00 app[web.1]: /app/vendor/ruby-3.0.3/lib/ruby/3.0.0/forwardable.rb:238:in `add_http2_port'
2022-07-31T13:25:16.272370+00:00 app[web.1]: /app/vendor/bundle/ruby/3.0.0/gems/anycable-core-1.2.3/lib/anycable/grpc/server.rb:87:in `block in build_server'
2022-07-31T13:25:16.272370+00:00 app[web.1]: <internal:kernel>:90:in `tap'
2022-07-31T13:25:16.272370+00:00 app[web.1]: /app/vendor/bundle/ruby/3.0.0/gems/anycable-core-1.2.3/lib/anycable/grpc/server.rb:86:in `build_server'
2022-07-31T13:25:16.272371+00:00 app[web.1]: /app/vendor/bundle/ruby/3.0.0/gems/anycable-core-1.2.3/lib/anycable/grpc/server.rb:35:in `initialize'
2022-07-31T13:25:16.272371+00:00 app[web.1]: /app/vendor/bundle/ruby/3.0.0/gems/anycable-core-1.2.3/lib/anycable/grpc.rb:20:in `new'
2022-07-31T13:25:16.272371+00:00 app[web.1]: /app/vendor/bundle/ruby/3.0.0/gems/anycable-core-1.2.3/lib/anycable/grpc.rb:20:in `block in <top (required)>'
2022-07-31T13:25:16.272372+00:00 app[web.1]: /app/vendor/bundle/ruby/3.0.0/gems/anycable-core-1.2.3/lib/anycable/cli.rb:70:in `run'
2022-07-31T13:25:16.272372+00:00 app[web.1]: /app/vendor/bundle/ruby/3.0.0/gems/anycable-core-1.2.3/bin/anycable:7:in `<top (required)>'
2022-07-31T13:25:16.272372+00:00 app[web.1]: /app/vendor/bundle/ruby/3.0.0/bin/anycable:25:in `load'
2022-07-31T13:25:16.272372+00:00 app[web.1]: /app/vendor/bundle/ruby/3.0.0/bin/anycable:25:in `<top (required)>'
2022-07-31T13:25:16.272373+00:00 app[web.1]: /app/vendor/bundle/ruby/3.0.0/gems/bundler-2.3.10/lib/bundler/cli/exec.rb:58:in `load'
2022-07-31T13:25:16.272373+00:00 app[web.1]: /app/vendor/bundle/ruby/3.0.0/gems/bundler-2.3.10/lib/bundler/cli/exec.rb:58:in `kernel_load'
2022-07-31T13:25:16.272373+00:00 app[web.1]: /app/vendor/bundle/ruby/3.0.0/gems/bundler-2.3.10/lib/bundler/cli/exec.rb:23:in `run'
2022-07-31T13:25:16.272373+00:00 app[web.1]: /app/vendor/bundle/ruby/3.0.0/gems/bundler-2.3.10/lib/bundler/cli.rb:483:in `exec'
2022-07-31T13:25:16.272373+00:00 app[web.1]: /app/vendor/bundle/ruby/3.0.0/gems/bundler-2.3.10/lib/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
2022-07-31T13:25:16.272373+00:00 app[web.1]: /app/vendor/bundle/ruby/3.0.0/gems/bundler-2.3.10/lib/bundler/vendor/thor/lib/thor/invocation.rb:127:in `invoke_command'
2022-07-31T13:25:16.272374+00:00 app[web.1]: /app/vendor/bundle/ruby/3.0.0/gems/bundler-2.3.10/lib/bundler/vendor/thor/lib/thor.rb:392:in `dispatch'
2022-07-31T13:25:16.272374+00:00 app[web.1]: /app/vendor/bundle/ruby/3.0.0/gems/bundler-2.3.10/lib/bundler/cli.rb:31:in `dispatch'
2022-07-31T13:25:16.272374+00:00 app[web.1]: /app/vendor/bundle/ruby/3.0.0/gems/bundler-2.3.10/lib/bundler/vendor/thor/lib/thor/base.rb:485:in `start'
2022-07-31T13:25:16.272374+00:00 app[web.1]: /app/vendor/bundle/ruby/3.0.0/gems/bundler-2.3.10/lib/bundler/cli.rb:25:in `start'
2022-07-31T13:25:16.272374+00:00 app[web.1]: /app/vendor/bundle/ruby/3.0.0/gems/bundler-2.3.10/exe/bundle:48:in `block in <top (required)>'
2022-07-31T13:25:16.272374+00:00 app[web.1]: /app/vendor/bundle/ruby/3.0.0/gems/bundler-2.3.10/lib/bundler/friendly_errors.rb:103:in `with_friendly_errors'
2022-07-31T13:25:16.272375+00:00 app[web.1]: /app/vendor/bundle/ruby/3.0.0/gems/bundler-2.3.10/exe/bundle:36:in `<top (required)>'
2022-07-31T13:25:16.272375+00:00 app[web.1]: /app/bin/bundle:3:in `load'
rmdashrfv commented 2 years ago

Upgrading the Heroku Stack from 20 to 22, and ruby version from 3.0.3 to 3.1.2 didn't help in any way.

rmdashrfv commented 2 years ago

I was able to get this error fixed and the process itself to actually run. But the issue is now that Heroku does not support HTTP/2. AnyCable cannot run on Heroku no matter what you do. Don't waste your time folks!

palkan commented 2 years ago

Please, read the documentation carefully.

AnyCable runs on Heroku without any problems. Proved by many production installations. Our demo application also runs on Heroku (latest stack): https://demo.anycable.io/

rmdashrfv commented 2 years ago

@palkan I can send you a video of following the documentation carefully. As you're aware, it doesn't take long to get set up. So far, every engineer I talk to has told me that it's not possible. And after following the docs, I don't know what else to say about it. Happy to update my comment though, if I find otherwise.

I think even the Procfile didn't have the intended effect on Heroku? Or was that just me?

palkan commented 2 years ago

It's not possible to have HTTP2 on Heroku accessible from the outside. But no one can stop us from using it within a dyno. From the docs:

The only way (for now) to run AnyCable applications on Heroku is to have two separate applications sharing some resources: the first one is a typical web application responsible for general HTTP and the second contains AnyCable WebSocket and RPC servers.

"every engineer" != "every good engineer"

I think even the Procfile didn't have the intended effect on Heroku?

My app uses the same Procfile as in the docs; you can find the source code here: https://github.com/anycable/anycable_rails_demo/pull/4

From the exception, it seems that gRPC server tried to listen on the 0.0.0.0. Since you don't specify this address in the Procfile, it could be either defined via env (ANYCABLE_RPC_HOST=0.0.0.0:50051) or in the YML config (or explicitly in the code).

The default value is "127.0.0.1".

You can debug configuration by running the following command: heroku run "bundle exec rails runner 'pp AnyCable.config'" -a your-rpc-app.

rmdashrfv commented 2 years ago

I was able to get the process to spin up and listen with this as the web command in the Procfile: web: ANYCABLE_DEBUG=1 bundle exec anycable --server-command="anycable-go --host=0.0.0.0 --port=$PORT" --rpc-host="0.0.0.0:50051"

If I'm not mistaken, that should satisfy the "ANYCABLE_RPC_HOST" variable requirement. Once I added this, I can confirm that the process spun up properly in debug mode and was listening correctly.

The issue that made me (and others) determine that we weren't able to do it on Heroku was that when a message was sent, it wouldn't actually deliver messages to the client. This is the error that would occur:

2022-07-31T19:45:28.805798+00:00 app[web.1]: 
E 2022-07-31T19:45:28.805Z context=ws Websocket session initialization failed: rpc error: code =
Unavailable desc = last connection error: connection error: desc =
"transport: Error while dialing dial tcp: address 0.0.0.0: missing port in address"

But it did actually receive the message itself:

 D 2022-08-01T00:21:09.013Z context=pubsub Incoming pubsub message from Redis: { ...message_data }

I'm not sure why there's this remaining problem? "Unavailable context=rpc RPC failure: last connection error: connection error: desc = "transport: Error while dialing dial tcp: address 0.0.0.0: missing port in address"

I'll definitely try again. By the way you make it sound, I was close to having it done before I took everything down?

palkan commented 2 years ago

address 0.0.0.0: missing port in address

The error says that is says: the RPC address value for anycable-go is invalid, it must include a port as well. Do you the ANYCABLE_RPC_HOST config var set? You should remove it (as well as --rpc-host="0.0.0.0:50051"). The default values should be enough.

palkan commented 2 years ago

Which anycable-go version do you run?

rmdashrfv commented 2 years ago

I do have ANYCABLE_RPC_HOST config var set (as well as ANYCABLE_HOST), both of which were "0.0.0.0".

I'll remove --rpc-host="0.0.0.0:50051" as well.

I was running the default version. IIRC 1.1.0?

rmdashrfv commented 2 years ago

Hm. It must have been either the addition of --rpc-host="0.0.0.0:50051" or having the ANYCABLE_RPC_HOST variable overwriting something with 0.0.0.0.

It does in fact work now.

Using anycable-go 1.1.0.

"every engineer" != "every good engineer" indeed 🤷‍♂️

rmdashrfv commented 2 years ago

@palkan can you remove the invalid tag. This has been solved.

Thank you very much!