Recently we started experiencing an issue with the CHT-Rapidpro integration where when one sends a single message to a client from the messages tab in CHT its results into a duplicate flooding of that message in textit forexample when you send Hello Cliff , how are you? to a client via CHT , in Textit you you constantly see that message being sent to the client non-stop like over a 100 times . What could be causing this ?
Here is the message sent from CHT
But here is a screen shot below of the message being duplicated from Text-it
The only way we where able to stop these message from continuing to flood in on the clients phone was to archive the contact in Text-it and delete them in CHT
i have talked to the textit team and they are saying that the duplicate messages are retries from the external system
Hi @cliff
I’m not really sure how this is happening. The CHT should not resend the same message if textit has received it.
Can you check your API logs to see if there are any logged errors?
For example something like: “Empty response received when sending message”.
thanks @diana , thought i see nothing root@a9113a4efbc8:/srv# vi /srv/storage/medic-api/logs/medic-api.log
its just returning blank output
@diana also what are the values in Fauxton for
medic-credentials
rapidpro.app
rapidpro:incoming
rapidpro:outgoing
Are they supposed to point to the api token in Textit ie Token f5e24f098f922f7fa7675b471d529ab0c74c9273
Hi @cliff
There have to be some logs. Can you try using cat
instead of vi
?
Can you ls -la /srv/storage/medic-api/logs/
?
thanks @diana yes we can get into the logs
024-09-25 19:37:56] [stack]: 'StatusCodeError: 400 - {"urns":{"0":["Invalid URN: tel:********. Ensure phone numbers contain country codes."]}}\n at new StatusCodeError (/srv/software/medic-api/md5-cdTbX9bB
8ZfHZmsqbv4Zw==/node_modules/request-promise-core/lib/errors.js:32:15)\n at Request.plumbing.callback (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/node_modules/request-promise-core/lib/plumbing.js:104:
33)\n at Request.RP$callback [as _callback] (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/node_modules/request-promise-core/lib/plumbing.js:46:31)\n at Request.self.callback (/srv/software/medic-api/
md5-cdTbX9bB8ZfHZmsqbv4Zw==/node_modules/request/request.js:185:22)\n at emitTwo (events.js:126:13)\n at Request.emit (events.js:214:7)\n at Request.<anonymous> (/srv/software/medic-api/md5-cdTbX9bB8ZfHZ
msqbv4Zw==/node_modules/request/request.js:1154:10)\n at emitOne (events.js:116:13)\n at Request.emit (events.js:211:7)\n at IncomingMessage.<anonymous> (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw
==/node_modules/request/request.js:1076:12)' }
[2024-09-25 19:37:57] 2024-09-25 19:37:57 ESC[31mERRORESC[39m: Error thrown when trying to send message: { StatusCodeError: 400 - {"urns":{"0":["Invalid URN: tel:********. Ensure phone numbers contain country cod
es."]}}
[2024-09-25 19:37:57] at new StatusCodeError (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/node_modules/request-promise-core/lib/errors.js:32:15)
[2024-09-25 19:37:57] at Request.plumbing.callback (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/node_modules/request-promise-core/lib/plumbing.js:104:33)
[2024-09-25 19:37:57] at Request.RP$callback [as _callback] (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/node_modules/request-promise-core/lib/plumbing.js:46:31)
[2024-09-25 19:37:57] at Request.self.callback (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/node_modules/request/request.js:185:22)
[2024-09-25 19:37:57] at emitTwo (events.js:126:13)
[2024-09-25 19:37:57] at Request.emit (events.js:214:7)
[2024-09-25 19:37:57] at Request.<anonymous> (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/node_modules/request/request.js:1154:10)
[2024-09-25 19:37:57] at emitOne (events.js:116:13)
[2024-09-25 19:37:57] at Request.emit (events.js:211:7)
[2024-09-25 19:37:57] at IncomingMessage.<anonymous> (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/node_modules/request/request.js:1076:12)
[2024-09-25 19:37:57] name: 'StatusCodeError',
[2024-09-25 19:37:57] statusCode: 400,
[2024-09-25 19:37:57] message: '400 - {"urns":{"0":["Invalid URN: tel:********. Ensure phone numbers contain country codes."]}}',
[2024-09-25 19:37:57] error:
[2024-09-25 19:37:57] { urns:
[2024-09-25 19:37:57] { '0':
[2024-09-25 19:37:57] [ 'Invalid URN: tel:********. Ensure phone numbers contain country codes.',
[2024-09-25 19:37:57] [length]: 1 ] } },
[2024-09-25 19:37:57] [stack]: 'StatusCodeError: 400 - {"urns":{"0":["Invalid URN: tel:********. Ensure phone numbers contain country codes."]}}\n at new StatusCodeError (/srv/software/medic-api/md5-cdTbX9bB
8ZfHZmsqbv4Zw==/node_modules/request-promise-core/lib/errors.js:32:15)\n at Request.plumbing.callback (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/node_modules/request-promise-core/lib/plumbing.js:104:
33)\n at Request.RP$callback [as _callback] (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/node_modules/request-promise-core/lib/plumbing.js:46:31)\n at Request.self.callback (/srv/software/medic-api/
md5-cdTbX9bB8ZfHZmsqbv4Zw==/node_modules/request/request.js:185:22)\n at emitTwo (events.js:126:13)\n at Request.emit (events.js:214:7)\n at Request.<anonymous> (/srv/software/medic-api/md5-cdTbX9bB8ZfHZ
msqbv4Zw==/node_modules/request/request.js:1154:10)\n at emitOne (events.js:116:13)\n at Request.emit (events.js:211:7)\n at IncomingMessage.<anonymous> (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw
==/node_modules/request/request.js:1076:12)' }
[2024-09-25 19:37:57] 2024-09-25 19:37:57 ESC[31mERRORESC[39m: Error thrown when trying to send message: { TypeError: Cannot read property 'state' of undefined
[2024-09-25 19:37:57] at getStateUpdate (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:79:17)
[2024-09-25 19:37:57] at request.post.then.result (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:107:14)
[2024-09-25 19:37:57] at <anonymous>
[2024-09-25 19:37:57] at process._tickCallback (internal/process/next_tick.js:188:7)
[2024-09-25 19:37:57] [stack]: 'TypeError: Cannot read property \'state\' of undefined\n at getStateUpdate (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:79:17)\n at request
.post.then.result (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:107:14)\n at <anonymous>\n at process._tickCallback (internal/process/next_tick.js:188:7)',
[2024-09-25 19:37:57] [message]: 'Cannot read property \'state\' of undefined' }
[2024-09-25 19:37:57] 2024-09-25 19:37:57 ESC[31mERRORESC[39m: Error thrown when trying to send message: { TypeError: Cannot read property 'state' of undefined
[2024-09-25 19:37:57] at getStateUpdate (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:79:17)
[2024-09-25 19:37:57] at request.post.then.result (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:107:14)
[2024-09-25 19:37:57] at <anonymous>
[2024-09-25 19:37:57] at process._tickCallback (internal/process/next_tick.js:188:7)
[2024-09-25 19:37:57] [stack]: 'TypeError: Cannot read property \'state\' of undefined\n at getStateUpdate (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:79:17)\n at request
.post.then.result (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:107:14)\n at <anonymous>\n at process._tickCallback (internal/process/next_tick.js:188:7)',
[2024-09-25 19:37:57] [message]: 'Cannot read property \'state\' of undefined' }
[2024-09-25 19:37:57] 2024-09-25 19:37:57 ESC[31mERRORESC[39m: Error thrown when trying to send message: { TypeError: Cannot read property 'state' of undefined
[2024-09-25 19:37:57] at getStateUpdate (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:79:17)
[2024-09-25 19:37:57] at request.post.then.result (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:107:14)
[2024-09-25 19:37:57] at <anonymous>
[2024-09-25 19:37:57] at process._tickCallback (internal/process/next_tick.js:188:7)
[2024-09-25 19:37:57] [stack]: 'TypeError: Cannot read property \'state\' of undefined\n at getStateUpdate (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:79:17)\n at request
.post.then.result (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:107:14)\n at <anonymous>\n at process._tickCallback (internal/process/next_tick.js:188:7)',
[2024-09-25 19:37:57] [message]: 'Cannot read property \'state\' of undefined' }
[2024-09-25 19:37:58] 2024-09-25 19:37:58 ESC[31mERRORESC[39m: Error thrown when trying to send message: { TypeError: Cannot read property 'state' of undefined
[2024-09-25 19:37:58] at getStateUpdate (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:79:17)
[2024-09-25 19:37:58] at request.post.then.result (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:107:14)
[2024-09-25 19:37:58] at <anonymous>
[2024-09-25 19:37:58] at process._tickCallback (internal/process/next_tick.js:188:7)
[2024-09-25 19:37:58] [stack]: 'TypeError: Cannot read property \'state\' of undefined\n at getStateUpdate (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:79:17)\n at request
.post.then.result (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:107:14)\n at <anonymous>\n at process._tickCallback (internal/process/next_tick.js:188:7)',
[2024-09-25 19:37:58] [message]: 'Cannot read property \'state\' of undefined' }
We believe all of them do have a country code
So it looks like textit returns an error when we try to send the message, that will make API retry sending the same message later, but the message somehow still makes it to textit?
I’m going to create an issue to handle this error better in API.
thanks @diana for this and i there a workaround this in the mean time to keep going on ?
I was thinking or re-starting the the docker services
Restarting the services won’t help. Just delete the messages when you see this happening again.
I believe this was caused by an invalid formatted phone number.
Can you try sending with a valid phone number and seeing if this re-occurs?
The message from textis is Ensure phone numbers contain country codes
, so make sure the number is complete.
Thanks Diana for your quick help! I’ve been supporting Cliff on this and can’t seem to find the faulty message. Can you think of an easy way to find which message is causing this error? Can API be restarted in a more verbose way? Alternatively we can remove messages one by one until we find the bad one.
Also, perhaps that way we could see what the message status is that results in the undefined state.
I thought the tel:********
in the log was hiding a number… but I found a tombstone of a message in couch with that exact same “number”. Perhaps there is another message lying around that is still trying to be sent from the same number. Either way, it sounds like the rapidpro service might be better able to handle this scenario, so thanks Diana for opening an issue for that.
thanks @diana , going to cross check and ensure that though the wired bit here is that things have been working fine more than two days back with the same phone numbers
Found the culprits!
The messages were going out as auto responses to automated messages from a phone number ********
.
Given that we don’t have control of the declared phone number for the incoming messages, is there a good way to avoid this scenario in the future?
thanks @marc now that this one has been fixed we running into
2024-09-25 20:56:56] 2024-09-25 20:56:56 ESC[32mINFOESC[39m: Sending 14 messages
[2024-09-25 20:56:57] 2024-09-25 20:56:57 ESC[31mERRORESC[39m: Error thrown when trying to send message: { TypeError: Cannot read property 'state' of undefined
[2024-09-25 20:56:57] at getStateUpdate (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:79:17)
[2024-09-25 20:56:57] at request.post.then.result (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:107:14)
[2024-09-25 20:56:57] at <anonymous>
[2024-09-25 20:56:57] at process._tickCallback (internal/process/next_tick.js:188:7)
[2024-09-25 20:56:57] [stack]: 'TypeError: Cannot read property \'state\' of undefined\n at getStateUpdate (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:79:17)\n at request.post.then.result (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:107:14)\n at <anonymous>\n at process._tickCallback (internal/process/next_tick.js:188:7)',
[2024-09-25 20:56:57] [message]: 'Cannot read property \'state\' of undefined' }
[2024-09-25 20:56:57] 2024-09-25 20:56:57 ESC[31mERRORESC[39m: Error thrown when trying to send message: { TypeError: Cannot read property 'state' of undefined
[2024-09-25 20:56:57] at getStateUpdate (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:79:17)
[2024-09-25 20:56:57] at request.post.then.result (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:107:14)
[2024-09-25 20:56:57] at <anonymous>
[2024-09-25 20:56:57] at process._tickCallback (internal/process/next_tick.js:188:7)
[2024-09-25 20:56:57] [stack]: 'TypeError: Cannot read property \'state\' of undefined\n at getStateUpdate (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:79:17)\n at request.post.then.result (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:107:14)\n at <anonymous>\n at process._tickCallback (internal/process/next_tick.js:188:7)',
[2024-09-25 20:56:57] [message]: 'Cannot read property \'state\' of undefined' }
[2024-09-25 20:56:57] 2024-09-25 20:56:57 ESC[31mERRORESC[39m: Error thrown when trying to send message: { TypeError: Cannot read property 'state' of undefined
[2024-09-25 20:56:57] at getStateUpdate (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:79:17)
[2024-09-25 20:56:57] at request.post.then.result (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:107:14)
[2024-09-25 20:56:57] at <anonymous>
[2024-09-25 20:56:57] at process._tickCallback (internal/process/next_tick.js:188:7)
[2024-09-25 20:56:57] [stack]: 'TypeError: Cannot read property \'state\' of undefined\n at getStateUpdate (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:79:17)\n at request.post.then.result (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:107:14)\n at <anonymous>\n at process._tickCallback (internal/process/next_tick.js:188:7)',
[2024-09-25 20:56:57] [message]: 'Cannot read property \'state\' of undefined' }
[2024-09-25 20:56:57] 2024-09-25 20:56:57 ESC[31mERRORESC[39m: Error thrown when trying to send message: { TypeError: Cannot read property 'state' of undefined
[2024-09-25 20:56:57] at getStateUpdate (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:79:17)
[2024-09-25 20:56:57] at request.post.then.result (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:107:14)
[2024-09-25 20:56:57] at <anonymous>
[2024-09-25 20:56:57] at process._tickCallback (internal/process/next_tick.js:188:7)
[2024-09-25 20:56:57] [stack]: 'TypeError: Cannot read property \'state\' of undefined\n at getStateUpdate (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:79:17)\n at request.post.then.result (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:107:14)\n at <anonymous>\n at process._tickCallback (internal/process/next_tick.js:188:7)',
[2024-09-25 20:56:57] [message]: 'Cannot read property \'state\' of undefined' }
[2024-09-25 20:56:58] 2024-09-25 20:56:58 ESC[31mERRORESC[39m: Error thrown when trying to send message: { TypeError: Cannot read property 'state' of undefined
[2024-09-25 20:56:58] at getStateUpdate (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:79:17)
[2024-09-25 20:56:58] at request.post.then.result (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:107:14)
[2024-09-25 20:56:58] at <anonymous>
[2024-09-25 20:56:58] at process._tickCallback (internal/process/next_tick.js:188:7)
[2024-09-25 20:56:58] [stack]: 'TypeError: Cannot read property \'state\' of undefined\n at getStateUpdate (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:79:17)\n at request.post.then.result (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:107:14)\n at <anonymous>\n at process._tickCallback (internal/process/next_tick.js:188:7)',
[2024-09-25 20:56:58] [message]: 'Cannot read property \'state\' of undefined' }
[2024-09-25 20:56:58] RES 9db0399e-3bbd-4366-a7a6-542a21304b64 41.77.13.138 - GET /medic-user-medic-meta/_changes?include_docs=true&feed=longpoll&heartbeat=10000&since=1418-g1AAAAJjeJyd0L0KwjAQAOBgBV19An0CySVNEyf7JtokLaVUnZz1NZx0dBNxECedfA19k5qfjkVoObiDO-7juBIhNMwDjUZqs1W5ljEQPsUmoDSjXoLkuKqqIg-Sy8o0BokmVEhoWvjDyInJcl5Ldy9JwEzwtlJspUUtXZ0008CFkm2lpZV2tXRwEmMZUNn2pnXfZLQ3xWBHq92cRoCHKtWdtJPXnlY7Oy3FIQjMOmkvr32s9nZahqmCkHbSvl5zf3s4jUcZSXnUtFf8AMZro9g&limit=25 HTTP/1.0 200 - 10208.196 ms
[2024-09-25 20:56:58] RES 191aa389-59cc-4574-a9cf-68021a45cc48 41.77.13.138 - GET /medic/_changes?feed=longpoll&heartbeat=10000&since=9823-g1AAAAJ7eJyd0EsKwjAQANBgW-1WELd6AmkSkzYrexPNp6GUaleuXOhN9CZ6EdGb1DQpdFOEloEZSGYezJQAgDD3FJjL6ixzJVKI4k1kApbma8KBWNV1XeSeAMB_H83bTCINIYd9M38ksTZZ7DostFjCKNGUDsXSBtt32NJiEd3KDOKh2KHBrh1WWQxlRBGtB2In32RwM8V4dwcGCwtiLEicyFHgw4HPFry422mBkFajwJcDP-3KgQWV6cQsHgV-HdjecModyHhEBOsbLX5pNaFR&limit=25 HTTP/1.0 200 - 10210.898 ms
[2024-09-25 20:56:58] 2024-09-25 20:56:58 ESC[31mERRORESC[39m: Error thrown when trying to send message: { TypeError: Cannot read property 'state' of undefined
[2024-09-25 20:56:58] at getStateUpdate (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:79:17)
[2024-09-25 20:56:58] at request.post.then.result (/srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js:107:14)
[2024-09-25 20:56:58] at <anonymous>
so we are still experiencing the throttling issue
cc @diana
This is unfortunate. It looks like the format for the response from textit has changed compared to when our integration was implemented.
@diana could you kindly expound more on what you by this . Do you you mean the format of the phone number
Looks like the code is trying to access the state
property of a variable that is currently undefined
probably from the function getStateUpdate
located at /srv/software/medic-api/md5-cdTbX9bB8ZfHZmsqbv4Zw==/src/services/rapidpro.js
on line 79.
The function is called within a promise chain after a request.post
call at line 107 of the same file multiple times (for each message being sent).
The logs show multiple occurrences of this error, suggesting that the problem might be recurring during the execution of the same function multiple times (for each message being sent).
So there are two things we have noticed:
- When RapidPro is throttling messages and returning 429, the response does not contain a state, which is expected by the rapidpro service. This adds errors to the log files, but doesn’t seem to affect performance.
- We still have messages that are resent every minute because their status is not updated in db, even when properly sent by RapidPro.
For now, only the second is problematic. If message states are not saved properly, it seems as though this warning would be thrown though. Are warnings output to the log files, or only errors? If errors only, is there an easy way to change the verbosity to show warnings too?
- We still have messages that are resent every minute because their status is not updated in db, even when properly sent by RapidPro.
The status would get updated if they weren’t throttled.
We are treating throttling, but only for status requests: cht-core/api/src/services/rapidpro.js at 3.17.x · medic/cht-core · GitHub not for sends.
Maybe sends didn’t get throttled back then.