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

`no_matching_pool` error while trying to send notification to fcm #211

Closed alvinlal closed 6 months ago

alvinlal commented 6 months ago

getting the following error while trying to trigger push notification to fcm in dev mode 👇 , not a problem for apns

{"application":"mongoose_push","at":"Elixir.MongoosePush.maybe_log/3:111","category":"generic","device_id":"caU-gnjKS0StKZaW2pjDXg:APA91bEuSU1Oh5A9pnsJPuPqZuelTrHzZYgHyAAt-PYq-iJHTaa88wkmaMCeGWjPPfGcL2OjWLdJgUZ0eIzTYrVxxEwJBKL4X5Mp4QiBQe9gwJcrx1RPPkt1Sphi-pGr5XxBfcQDIqnb","erl_level":"warning","file":"lib/mongoose_push.ex","mode":"dev","pid":"#PID<0.24690.71>","reason":"no_matching_pool","request_id":"F7mMNFl807s7OZsAABvS","result":"error","service":"fcm","severity":"warning","text":"Unable to send the push notification","what":"sending_notification","when":"2024-03-04T11:28:10.032","domain[0]":"elixir"}

this is the docker command i used to up the mongoosepush container 👇

docker run -v /home/ubuntu/app/mongoose-push-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_DEV_KEY_ID="dev key id here" \
  -e PUSH_APNS_DEV_TEAM_ID="dev team id here" \
  -e PUSH_APNS_PROD_KEY_ID="prod key id here" \
  -e PUSH_APNS_PROD_TEAM_ID="prod team id here" \
  -e PUSH_LOGLEVEL="info" \
  -p 8443:8443 \
  -d mongooseim/mongoose-push:latest
pawlooss1 commented 6 months ago

Hi @alvinlal Could you also provide request and response for both fcm and apns?

alvinlal commented 6 months ago

sure @pawlooss1 , here is the request and response for apns taken from the logs👇

request 👇

{
  "application": "phoenix",
  "at": "Elixir.Phoenix.Logger.phoenix_endpoint_start/4:211",
  "erl_level": "info",
  "file": "lib/phoenix/logger.ex",
  "pid": "#PID<0.28473.73>",
  "request_id": "F7nMAxC7_UXzITwAAB1C",
  "severity": "info",
  "text": "POST /v3/notification/8059DAD030E06EDCF13117AE5E2098DB256AF83D271E3AB00AF95F7BF0AA4143B6F29D28B4AD9ED1A82B28E68D74B73A4CF63503B7E9C5A6ED8BB3818C30F3F53AA6CED68804E9DC0B112F5C18E21BFE",
  "what": "",
  "when": "2024-03-05T06:57:27.101",
  "domain[0]": "elixir"
}

response 👇

{
  "application": "phoenix",
  "at": "Elixir.Phoenix.Logger.phoenix_endpoint_stop/4:225",
  "erl_level": "info",
  "file": "lib/phoenix/logger.ex",
  "pid": "#PID<0.28473.73>",
  "request_id": "F7nMAxC7_UXzITwAAB1C",
  "severity": "info",
  "text": "Sent 200 in 540ms",
  "what": "",
  "when": "2024-03-05T06:57:27.641",
  "domain[0]": "elixir"
}

here is the request and response for fcm taken from the logs👇

request 👇

{
  "application": "phoenix",
  "at": "Elixir.Phoenix.Logger.phoenix_endpoint_start/4:211",
  "erl_level": "info",
  "file": "lib/phoenix/logger.ex",
  "pid": "#PID<0.28798.73>",
  "request_id": "F7nMT9JaKCN6xSkAAB2S",
  "severity": "info",
  "text": "POST /v3/notification/e1rQYYFyRbKA0CcXN3lA1M:APA91bFDy3TvgGY5HNHhSNuN_EsNRCsEiYZQN4cC6zjNGDSKMYf7rE4sfPOIhhsFI1z-9ApSF8UTN2Z-QZ35i0akKdD9UiOAPYVY8WBdN3PtZapxNx3M9YSmfqLgRDMp5Ko-Dnlu6ebR",
  "what": "",
  "when": "2024-03-05T07:02:56.767",
  "domain[0]": "elixir"
}

response block 1 👇

{
  "application": "mongoose_push",
  "at": "Elixir.MongoosePush.push/2:75",
  "category": "generic",
  "device_id": "e1rQYYFyRbKA0CcXN3lA1M:APA91bFDy3TvgGY5HNHhSNuN_EsNRCsEiYZQN4cC6zjNGDSKMYf7rE4sfPOIhhsFI1z-9ApSF8UTN2Z-QZ35i0akKdD9UiOAPYVY8WBdN3PtZapxNx3M9YSmfqLgRDMp5Ko-Dnlu6ebR",
  "erl_level": "error",
  "file": "lib/mongoose_push.ex",
  "mode": "dev",
  "pid": "#PID<0.28798.73>",
  "reason": "no_matching_pool",
  "request_id": "F7nMT9JaKCN6xSkAAB2S",
  "result": "error",
  "service": "fcm",
  "severity": "error",
  "text": "Unable to choose pool",
  "what": "pool_selection",
  "when": "2024-03-05T07:02:56.767",
  "domain[0]": "elixir"
}

response block 2 👇

{
  "application": "phoenix",
  "at": "Elixir.Phoenix.Logger.phoenix_endpoint_stop/4:225",
  "erl_level": "info",
  "file": "lib/phoenix/logger.ex",
  "pid": "#PID<0.28798.73>",
  "request_id": "F7nMT9JaKCN6xSkAAB2S",
  "severity": "info",
  "text": "Sent 400 in 1ms",
  "what": "",
  "when": "2024-03-05T07:02:56.769",
  "domain[0]": "elixir"
}
pawlooss1 commented 6 months ago

Now I see that I did not make it clear but I meant the requests to MongoosePush and response from it. Could you provide them as well? I want to reproduce this issue on my local machine. Nevertheless thank you, these logs could be useful too.

alvinlal commented 6 months ago

@pawlooss1 , i guess i misunderstood , actually the requests are send and triggered from mongooseim xmpp server. Is there any flag that i can turn on on mongoosepush that will log all request and response ?, meanwhile i will check the mongooseim documentation and see if there is a way to view the sent request and responses and get back to you 👍

pawlooss1 commented 6 months ago

Oh, I see. Maybe you could try to set the log level to debug? Probably Phoenix will put some additional logs for each endpoint call.

alvinlal commented 6 months ago

@pawlooss1 , is the parameters object that is shown on the logs after setting the log level to debug helpfull to you ?

fcm 👇

{
  "application": "phoenix",
  "at": "Elixir.Phoenix.Logger.phoenix_router_dispatch_start/4:268",
  "erl_level": "debug",
  "file": "lib/phoenix/logger.ex",
  "pid": "#PID<0.4563.0>",
  "request_id": "F7p0ZU0RwSb3ww8AAAAR",
  "severity": "debug",
  "text": "Processing with MongoosePushWeb.APIv3.NotificationController.send/2\n  Parameters: %{\"data\" => %{\"last-message-body\" => \"{\\\"document_id\\\":null,\\\"message_id\\\":\\\"05fecae4-1809-4818-b345-83b11b2807c2\\\",\\\"text\\\":\\\"Hey\\\",\\\"type\\\":\\\"text\\\"}\", \"last-message-sender\" => \"+916524534311@example.com\", \"message-count\" => 1}, \"device_id\" => \"eL-DHt-3Rum0c2qHDrY0YP:APA91bGD0dnOMU_etDinwKuGXq-CUlGWQ0gFAoNOmq2tY2WY3VlJ0qUiSC0TbJA7eG8bhXP9o7cIf9jJC3u5ytOYqqhE3BzGa0wxt7MB2wGN7T_ew4oXfi2916V8pg9oiwi3Ogre_zQF\", \"mode\" => \"dev\", \"priority\" => \"high\", \"service\" => \"fcm\", \"topic\" => \"com.appname\"}\n  Pipelines: [:api]",
  "what": "",
  "when": "2024-03-07T10:23:06.974",
  "domain[0]": "elixir"
}

apns 👇

{
  "application": "phoenix",
  "at": "Elixir.Phoenix.Logger.phoenix_router_dispatch_start/4:268",
  "erl_level": "debug",
  "file": "lib/phoenix/logger.ex",
  "pid": "#PID<0.5217.0>",
  "request_id": "F7p0417EFWGRS5gAAACC",
  "severity": "debug",
  "text": "Processing with MongoosePushWeb.APIv3.NotificationController.send/2\n  Parameters: %{\"data\" => %{\"last-message-body\" => \"{\\\"document_id\\\":null,\\\"message_id\\\":\\\"f61b2ed2-9321-4234-bd3d-af161dfbd0eb\\\",\\\"text\\\":\\\"Ok\\\",\\\"type\\\":\\\"text\\\"}\", \"last-message-sender\" => \"+913524453433@example.com\", \"message-count\" => 1}, \"device_id\" => \"80B9449EB85228DD4E522C6DE87A77015149C32716BD49E66FFBB5FA2BDBB90936425AF39530A2FA8C9D668F2FDF72BC5F38FD1CC1433BE8604CB5C0A70606751DAA2BEBE788F7B4A3C227203B136C54\", \"mode\" => \"dev\", \"priority\" => \"high\", \"service\" => \"apns\", \"topic\" => \"com.appname\"}\n  Pipelines: [:api]",
  "what": "",
  "when": "2024-03-07T10:32:08.437",
  "domain[0]": "elixir"
}

with fcm, the logs show the following error (no_matching_pool) 👇

{
  "application": "mongoose_push",
  "at": "Elixir.MongoosePush.push/2:75",
  "category": "generic",
  "device_id": "eL-DHt-3Rum0c2qHDrY0YP:APA91bGD0dnOMU_etDinwKuGXq-CUlGWQ0gFAoNOmq2tY2WY3VlJ0qUiSC0TbJA7eG8bhXP9o7cIf9jJC3u5ytOYqqhE3BzGa0wxt7MB2wGN7T_ew4oXfi2916V8pg9oiwi3Ogre_zQF",
  "erl_level": "error",
  "file": "lib/mongoose_push.ex",
  "mode": "dev",
  "pid": "#PID<0.5122.0>",
  "reason": "no_matching_pool",
  "request_id": "F7p00tHhyjjFZgMAAABy",
  "result": "error",
  "service": "fcm",
  "severity": "error",
  "text": "Unable to choose pool",
  "what": "pool_selection",
  "when": "2024-03-07T10:30:57.355",
  "domain[0]": "elixir"
}

but with apns, everything is fine and i am getting a 200 ok status back

pawlooss1 commented 6 months ago

Thanks for the input @alvinlal I'm pretty sure that those parameters should help me reproduce this issue.

pawlooss1 commented 6 months ago

Ok so the thing is that you're sending a request with mode dev, but currently when configuring MongoosePush with environmental variables there is only one pool with mode prod created. Here is the configuration that defines it config/prod.exs#L46. APNs on the other hand defines both dev and prod pools by default - see config/prod.exs#L57. If you need to have a dev pool configured for FCM then I recommend changing the configuration file in the source and building your own image for now. It shouldn't be complicated, you can refer to the documentation.

Nevertheless I think that current configuration options are not flexible enough. When running outside of docker one can use TOML config but there are other issues with it (see https://github.com/esl/MongoosePush/issues/206). I'll think about making it more user friendly for the next minor release but in order to design it properly this time I won't make any hotfixes for it immediately.

alvinlal commented 6 months ago

thanks so much for your time on this issue @pawlooss1 , i will look at how to configure dev pool for fcm using the configuration file 👍

pawlooss1 commented 4 months ago

FYI @alvinlal we've released a new version of MongoosePush with some fixes in configuration. Also, there is an entry in documentation on how to use TOML config with docker containers - https://esl.github.io/MongoosePush/v2.1.2/docker.html. Here's TOML schema for it https://esl.github.io/MongoosePush/v2.1.2/configuration.html#toml-schema.

alvinlal commented 4 months ago

thanks @pawlooss1 , will check it out 👍