search

esl / MongoosePush

MongoosePush is a simple Elixir RESTful service allowing to send push notification via FCM and/or APNS.
Apache License 2.0
108 stars 24 forks source link

Unable to communicate to MongoosePush #41

Closed izigibran closed 7 years ago

izigibran commented 7 years ago

I am running MongooseIM and dockerized Push

My config are:

ejabberd.cfg

%%                    ]}.
%%

{http_connections, [{mongoose_push_http,
    [{server, "https://0.0.0.0:8443"}]
}]}.
{mod_pubsub, [
{ignore_pep_from_offline, true},
{last_item_cache, true},
{max_items_node, 1000},
{plugins, [<<"push">>]}
]},

{mod_push, [
{backend, mnesia},
{wpool, [{workers, 200}]},
{plugin_module, mod_push_plugin_default}
]},

{mod_caps, []},

{mod_push_service_mongoosepush, [
{pool_name, mongoose_push_http},
{api_version, "v2"}
]},

Push


 docker run -v `pwd`/priv:/opt/app/priv   -e PUSH_HTTPS_CERTFILE="/opt/app/priv/ssl/rest_cert.pem"   -e PUSH_HTTPS_KEYFILE="/opt/app/priv/ssl/rest_key.pem"   -it --rm mongooseim/mongoose-push:latest
14:59:49.144 [error] Supervisor 'Elixir.Logger.Supervisor' had child 'Elixir.Logger.ErrorHandler' started with 'Elixir.Logger.Watcher':watcher(error_logger, 'Elixir.Logger.ErrorHandler', {true,false,500}) at <0.1109.0> exit with reason normal in context child_terminated
14:59:49.155 [info] Application lager started on node 'mongoose_push@127.0.0.1'
14:59:49.155 [info] Application asn1 started on node 'mongoose_push@127.0.0.1'
14:59:49.156 [info] Application crypto started on node 'mongoose_push@127.0.0.1'
14:59:49.156 [info] Application public_key started on node 'mongoose_push@127.0.0.1'
14:59:49.156 [info] Application ssl started on node 'mongoose_push@127.0.0.1'
14:59:49.156 [info] Application chatterbox started on node 'mongoose_push@127.0.0.1'
14:59:49.156 [info] Application metrics started on node 'mongoose_push@127.0.0.1'
14:59:49.156 [info] Application ssl_verify_fun started on node 'mongoose_push@127.0.0.1'
14:59:49.157 [info] Application certifi started on node 'mongoose_push@127.0.0.1'
14:59:49.157 [info] Application mimerl started on node 'mongoose_push@127.0.0.1'
14:59:49.157 [info] Application idna started on node 'mongoose_push@127.0.0.1'
14:59:49.157 [info] Application hackney started on node 'mongoose_push@127.0.0.1'
14:59:49.157 [info] Application httpoison started on node 'mongoose_push@127.0.0.1'
14:59:49.157 [info] Application pigeon started on node 'mongoose_push@127.0.0.1'
14:59:49.157 [info] Application pobox started on node 'mongoose_push@127.0.0.1'
14:59:49.158 [info] Setup running ...

14:59:49.158 [info]  Setup running ...

14:59:49.159 [info]  Directories verified. Res = :ok

14:59:49.159 [info] Directories verified. Res = ok

14:59:49.159 [info]  Setup finished processing hooks (Mode=:normal)...

14:59:49.159 [info] Setup finished processing hooks (Mode=normal)...
14:59:49.159 [info] Application setup started on node 'mongoose_push@127.0.0.1'
14:59:49.161 [info] Starting reporters with []
14:59:49.161 [info] Application exometer_core started on node 'mongoose_push@127.0.0.1'
14:59:49.161 [info] Application elixometer started on node 'mongoose_push@127.0.0.1'
14:59:49.161 [info] Application exometer started on node 'mongoose_push@127.0.0.1'
14:59:49.162 [info] Application cowlib started on node 'mongoose_push@127.0.0.1'
14:59:49.162 [info] Application ranch started on node 'mongoose_push@127.0.0.1'

14:59:49.163 [info]  Starting Elixir.MongoosePush.Router with Cowboy on https://0.0.0.0:8443
When I send offline message I get this issue on mongooseIM....
{jid,<<>>,<<...>>,...},mongoose_acc => true,name => <<"iq">>,ref => #Ref<0.0.4.372>,...}
2017-09-08 11:12:52.142 [debug] <0.550.0>@ejabberd_sm:do_route:606 session manager
        from {jid,<<>>,<<"pubsub.localhost">>,<<>>,<<>>,<<"pubsub.localhost">>,<<>>}
        to {jid,<<"user">>,<<"localhost">>,<<>>,<<"user">>,<<"localhost">>,<<>>}
        packet #{attrs => [{<<"id">>,<<"4DB7248A6DF3"...>>},{<<"type">>,<<"result">>}],element => {xmlel,<<"iq">>,[{<<...>>,...},{...}],[{...}]},from => <<"pubsub.localhost">>,from_jid => {jid,<<>>,<<...>>,...},mongoose_acc => true,name => <<"iq">>,ref => #Ref<0.0.4.372>,...}
2017-09-08 11:12:52.142 [debug] <0.550.0>@ejabberd_router:route:476 routing done
2017-09-08 11:12:52.146 [debug] <0.1140.0> Supervisor inet_gethost_native_sup started undefined at pid <0.1141.0>
2017-09-08 11:12:52.146 [debug] <0.35.0> Supervisor kernel_safe_sup started inet_gethost_native:start_link() at pid <0.1140.0>
2017-09-08 11:12:52.157 [error] <0.804.0>@mod_push_service_mongoosepush:http_notification:114 Unable to communicate to MongoosePush service due to econnrefused

Any ideas what can be the issue?

rslota commented 7 years ago

Hi @izigibran ,

The MongoosePush listens on https://0.0.0.0:8443 which is basically a wildcard IPv4 address. You cannot however use this address in your ejabberd.cfg. In the ejabberd.cfg you need to substitute 0.0.0.0 with the docker container's IPv4 address or localhost if you are running docker with -p 8443:8443 option.

Please be aware that if you are running Docker4Mac on Mac machine or an Windows equivalent, changing configuration so that it points to container's IP address won't work (go for -p option and setting 127.0.0.1).

izigibran commented 7 years ago

@rslota thanks! this method worked, however, now I get error logs MongoosePush 

 Reconnecting to push service provider before request
15:32:27.324 [warning] lager_error_logger_h dropped 8 messages in the last second that exceeded the limit of 50 messages/sec

15:32:27.530 [error] SSL: :cipher: ssl_alert.erl:88:Fatal error: unknown ca

15:32:27.530 [error] {:tls_alert, 'unknown ca'}

=CRASH REPORT==== 8-Sep-2017::15:32:27 ===
  crasher:
    initial call: h2_connection:init/1
    pid: <0.1374.0>
    registered_name: []
    exception exit: {tls_alert,"unknown ca"}
      in function  gen_fsm:init_it/6 (gen_fsm.erl, line 335)
    ancestors: [apns_prod_3,'Elixir.MongoosePush.Supervisor',<0.1340.0>]
    messages: []
    links: [<0.1354.0>]
    dictionary: []
    trap_exit: false
    status: running
    heap_size: 987
    stack_size: 27
    reductions: 6036
  neighbours:
15:32:27.530 [error] SSL: cipher: ssl_alert.erl:88:Fatal error: unknown ca
15:32:27.531 [error] CRASH REPORT Process <0.1374.0> with 0 neighbours exited with reason: {tls_alert,"unknown ca"} in gen_fsm:init_it/6 line 335

15:32:27.682 [error] SSL: :cipher: ssl_alert.erl:88:Fatal error: unknown ca
rslota commented 7 years ago

The error you are seeing is due to the fact, that by default both APNS and FCM backends are active. Since you are not using APNS, you could disable it by adding -e PUSH_APNS_ENABLED=false to you docker run command. This is not mandatory however, this crash only affects APNS-related functions that you are not using anyway.

izigibran commented 7 years ago

I am actually trying to integrate APNS and FCM for push Notifications. So I do need them enabled?

rslota commented 7 years ago

If you need APNS as well, you cannot run the MongoosePush without providing APNS dev/production certificates. This is way you are seeing the crash.

Assuming you have APNS cert and key in your $PWD/priv/apns as prod_cert.pem and prod_key.pem, you need to add -e PUSH_APNS_PROD_CERT=/opt/app/priv/apns/prod_cert.pem -e PUSH_APNS_PROD_KEY=/opt/app/priv/apns/prod_key.pem to your docker run command (the paths are to files inside docker container, but you are mounting local $PWD/priv as /opt/app/priv in the container). This is of course assuming you are connecting to production APNS endpoint. If you want to use development endpoint, please consult README.md for the variable names.

rslota commented 7 years ago

Actually, the paths I have used in previous post are the defaults, so just make sure that the certificates are in place and are valid.

izigibran commented 7 years ago

this is what I have on priv folder

$ ls priv/
apns    ssl
localhost:MongoosePush$ ls priv/apns/
dev_cert.pem    dev_key.pem prod_cert.pem   prod_key.pem
localhost:MongoosePush$
izigibran commented 7 years ago

Some progress here 

docker run -p 8443:8443 -v `pwd`/priv:/opt/app/priv   -e PUSH_HTTPS_CERTFILE="/opt/app/priv/ssl/rest_cert.pem"   -e PUSH_HTTPS_KEYFILE="/opt/app/priv/ssl/rest_key.pem" -e PUSH_APNS_PROD_CERT=/opt/app/priv/apns/prod_cert.pem -e PUSH_APNS_PROD_KEY=/opt/app/priv/apns/prod_key.pem   -it --rm mongooseim/mongoose-push:latest
17:04:02.896 [error] Supervisor 'Elixir.Logger.Supervisor' had child 'Elixir.Logger.ErrorHandler' started with 'Elixir.Logger.Watcher':watcher(error_logger, 'Elixir.Logger.ErrorHandler', {true,false,500}) at <0.1109.0> exit with reason normal in context child_terminated
17:04:02.908 [info] Application lager started on node 'mongoose_push@127.0.0.1'
17:04:02.908 [info] Application asn1 started on node 'mongoose_push@127.0.0.1'
17:04:02.908 [info] Application crypto started on node 'mongoose_push@127.0.0.1'
17:04:02.908 [info] Application public_key started on node 'mongoose_push@127.0.0.1'
17:04:02.909 [info] Application ssl started on node 'mongoose_push@127.0.0.1'
17:04:02.909 [info] Application chatterbox started on node 'mongoose_push@127.0.0.1'
17:04:02.909 [info] Application metrics started on node 'mongoose_push@127.0.0.1'
17:04:02.909 [info] Application ssl_verify_fun started on node 'mongoose_push@127.0.0.1'
17:04:02.910 [info] Application certifi started on node 'mongoose_push@127.0.0.1'
17:04:02.910 [info] Application mimerl started on node 'mongoose_push@127.0.0.1'
17:04:02.910 [info] Application idna started on node 'mongoose_push@127.0.0.1'
17:04:02.911 [info] Application hackney started on node 'mongoose_push@127.0.0.1'
17:04:02.911 [info] Application httpoison started on node 'mongoose_push@127.0.0.1'
17:04:02.911 [info] Application pigeon started on node 'mongoose_push@127.0.0.1'
17:04:02.911 [info] Application pobox started on node 'mongoose_push@127.0.0.1'

17:04:02.912 [info]  Setup running ...

17:04:02.912 [info] Setup running ...

17:04:02.913 [info]  Directories verified. Res = :ok

17:04:02.913 [info] Directories verified. Res = ok

17:04:02.913 [info]  Setup finished processing hooks (Mode=:normal)...

17:04:02.913 [info] Setup finished processing hooks (Mode=normal)...
17:04:02.913 [info] Application setup started on node 'mongoose_push@127.0.0.1'
17:04:02.915 [info] Starting reporters with []
17:04:02.915 [info] Application exometer_core started on node 'mongoose_push@127.0.0.1'
17:04:02.916 [info] Application elixometer started on node 'mongoose_push@127.0.0.1'
17:04:02.916 [info] Application exometer started on node 'mongoose_push@127.0.0.1'
17:04:02.916 [info] Application cowlib started on node 'mongoose_push@127.0.0.1'
17:04:02.916 [info] Application ranch started on node 'mongoose_push@127.0.0.1'

17:04:02.917 [info]  Starting Elixir.MongoosePush.Router with Cowboy on https://0.0.0.0:8443

17:04:14.810 [info]  Reconnecting to push service provider before request

17:04:14.810 [error] Invalid configuration.

17:04:14.810 [error] GenServer :apns_prod_4 terminating
** (stop) bad return value: {:stop, {:error, :invalid_config}}
Last message: {:"$gen_cast", {:push, :apns, %Pigeon.APNS.Notification{device_token: "0DC2C9224BD9832E6AC96653F1D75D63E082D01F7487D7AAAFE6CC2E87068898", expiration: nil, id: nil, payload: %{"aps" => %{"alert" => %{"body" => "asdf", "title" => "user2@localhost"}, "badge" => 1, "category" => nil}}, topic: "some_apns_topic"}, #Function<0.127687738/1 in Pigeon.APNS.do_sync_push/2>}}

=CRASH REPORT==== 8-Sep-2017::17:04:14 ===
  crasher:
    initial call: Elixir.Pigeon.APNSWorker:init/1
    pid: <0.1355.0>
    registered_name: apns_prod_4
    exception exit: {bad_return_value,{stop,{error,invalid_config}}}
      in function  gen_server:terminate/7 (gen_server.erl, line 812)
    ancestors: ['Elixir.MongoosePush.Supervisor',<0.1340.0>]
    messages: []
    links: [<0.1341.0>]
    dictionary: []
    trap_exit: true
    status: running
    heap_size: 376
    stack_size: 27
    reductions: 282
  neighbours:
17:04:14.810 [warning] lager_error_logger_h dropped 74 messages in the last second that exceeded the limit of 50 messages/sec

=SUPERVISOR REPORT==== 8-Sep-2017::17:04:14 ===
     Supervisor: {local,'Elixir.MongoosePush.Supervisor'}
     Context:    child_terminated
     Reason:     {bad_return_value,{stop,{error,invalid_config}}}
     Offender:   [{pid,<0.1355.0>},
                  {id,apns_prod_4},
                  {mfargs,
                      {'Elixir.Pigeon.APNSWorker',start_link,
                          [#{cert => nil,certfile => nil,
                             development_endpoint =>
                                 <<"api.development.push.apple.com">>,
                             key => nil,keyfile => nil,mode => prod,
                             name => apns_prod_4,port => 443,
                             production_endpoint => <<"api.push.apple.com">>,
                             use_2197 => false}]}},
                  {restart_type,permanent},
                  {shutdown,5000},
                  {child_type,worker}]

17:04:14.810 [error] gen_server apns_prod_4 terminated with reason: bad return value: {stop,{error,invalid_config}}
17:04:14.811 [error] CRASH REPORT Process apns_prod_4 with 0 neighbours exited with reason: bad return value: {stop,{error,invalid_config}} in gen_server:terminate/7 line 812
17:04:14.812 [error] Supervisor 'Elixir.MongoosePush.Supervisor' had child apns_prod_4 started with 'Elixir.Pigeon.APNSWorker':start_link(#{cert => nil,certfile => nil,development_endpoint => <<"api.development.push.apple.com">>,key => nil,...}) at <0.1355.0> exit with reason bad return value: {stop,{error,invalid_config}} in context child_terminated

17:05:14.811 [warn]  Unable to complete push request due to timeout
izigibran commented 7 years ago

@rslot the last crash report above


17:04:14.811 [error] CRASH REPORT Process apns_prod_4 with 0 neighbours exited with reason: bad return value: {stop,{error,invalid_config}} in gen_server:terminate/7 line 812
17:04:14.812 [error] Supervisor 'Elixir.MongoosePush.Supervisor' had child apns_prod_4 started with 'Elixir.Pigeon.APNSWorker':start_link(#{cert => nil,certfile => nil,development_endpoint => <<"api.development.push.apple.com">>,key => nil,...}) at <0.1355.0> exit with reason bad return value: {stop,{error,invalid_config}} in context child_terminated

Does this mean that the certificate file was not copied?

izigibran commented 7 years ago

Ok now I am running it locally. 

SSL: cipher: ssl_alert.erl:88:Fatal error: decrypt error
11:15:06.772 [error] CRASH REPORT Process <0.1801.0> with 0 neighbours exited with reason: {tls_alert,"decrypt error"} in gen_fsm:init_it/6 line 358

11:15:06.972 [error] SSL: :cipher: ssl_alert.erl:88:Fatal error: decrypt error

=CRASH REPORT==== 11-Sep-2017::11:15:06 ===
  crasher:
    initial call: h2_connection:init/1
    pid: <0.1803.0>
    registered_name: []
    exception exit: {tls_alert,"decrypt error"}
      in function  gen_fsm:init_it/6 (gen_fsm.erl, line 358)
    ancestors: [apns_prod_5,'Elixir.MongoosePush.Supervisor',<0.1395.0>]
    message_queue_len: 0
    messages: []
    links: [<0.1411.0>]
    dictionary: []
    trap_exit: false
    status: running
    heap_size: 987
    stack_size: 27
    reductions: 8391
  neighbours:

11:15:06.972 [error] {:tls_alert, 'decrypt error'}

11:15:06.972 [error] Failed to establish SSL connection. Is the certificate signed for :prod mode?

if the certificate has passphrase, how to provide it?

izigibran commented 7 years ago

Ok, I had to remove passphrase. I think if you are not going to support it you should have it on the documentation.

rslota commented 7 years ago

Hi @izigibran ,

You are totally right. We are not supporting certificate passphrases and we should be clear about it in documentation. I'm going to update docs soon to provide this information.

Thank you!