FusionPBX SMS Integration with Bandwidth

Robert Birch

Member
Mar 16, 2017
81
1
8
49
OK. So I managed to get Bandwidth to connect to my server. I had to change the CallBack URL from HTTPS to HTTP. Guessing that is due to the testing and not a proper certificate in place.

But the only line in the NGINX access.log is this:
Code:
52.72.24.132 - - [03/May/2021:11:39:58 -0600] "POST /app/sms/hook/sms_hook_bandwidth.php HTTP/1.1" 301 185 "-" "bandwidth-api"

Nothing in the error log either. Same with freeswitch.log. Nothing about the receiving of a message. MDR shows nothing as well.

Any other ideas?

Thanks,
Robert
 
Jan 9, 2018
87
11
8
51
Try browsing to this URL yourself and see what you get.

The access.log shows a 301, which is a redirect. Something in your nginx config may be redirecting back to https, which then fails.
 

Robert Birch

Member
Mar 16, 2017
81
1
8
49
OK. I set up HTTPS with LetsEncrypt. Confirmed certificate is valid.
Sent another text message to the number. This is what I get in the access.log
Code:
52.72.24.132 - - [03/May/2021:12:54:34 -0600] "POST /app/sms/hook/sms_hook_bandwidth.php HTTP/1.1" 301 185 "-" "bandwidth-api"
52.72.24.132 - - [03/May/2021:12:54:35 -0600] "GET /app/sms/hook/sms_hook_bandwidth.php HTTP/1.1" 200 205 "-" "bandwidth-api"
52.72.24.132 - - [03/May/2021:12:55:09 -0600] "POST /app/sms/hook/sms_hook_bandwidth.php HTTP/1.1" 502 173 "-" "bandwidth-api"
18.233.250.246 - - [03/May/2021:12:55:35 -0600] "POST /app/sms/hook/sms_hook_bandwidth.php HTTP/1.1" 502 173 "-" "bandwidth-api"
52.72.24.132 - - [03/May/2021:12:57:16 -0600] "POST /app/sms/hook/sms_hook_bandwidth.php HTTP/1.1" 502 173 "-" "bandwidth-api"
3.82.123.96 - - [03/May/2021:12:58:28 -0600] "POST /app/sms/hook/sms_hook_bandwidth.php HTTP/1.1" 502 173 "-" "bandwidth-api"

And this in the error.log:
Code:
2021/05/03 12:57:16 [error] 7475#7475: *5646 upstream sent too big header while reading response header from upstream, client:
52.72.24.132, server: fusionpbx, request: "POST /app/sms/hook/sms_hook_bandwidth.php HTTP/1.1", upstream: "fastcgi://unix:/var/
run/php/php7.1-fpm.sock:", host: "testfusion.XXXXX.com"

Thanks
 
Jan 9, 2018
87
11
8
51
That is a new error to me. Here's something I found that may help. I don't know why it would be exceeding the buffer, but you might try the settings in the one of the answers to the linked question.
 

Robert Birch

Member
Mar 16, 2017
81
1
8
49
Interesting side note.
I can see Bandwidth keep trying to resend the failed messages. Seems that in the error.log the logging seems to be cut off.
For example:
Code:
PHP message: [SMS] REQUEST: Array
(
    [0] => stdClass Object
        (
            [time] => 2021-05-03T17:35:16.221Z
            [type] => message-received
            [to] => +1<Inbound Number>
            [description] => Incoming message received
            [message] => stdClass Object
                (
                    [id] => a92b3882-803b-4a16-b49f-67605d51ea51
                    [owner] => +1<Inbound Number>
                    [applicationId] => xxxxxxx
                    [time] => 2021-05-03T17:35:16.056Z
                    [segmentCount] => 1
                    [direction] => in
                    [to] => Array
                        (
                            [0] => +1<Inbound Number>
                        )

                    [from] => +1<Sending Number>
                    [text] => Replying
                )

        )

)

PHP message: TO: 1<Inbound Number>
PHP message: FROM: 1<Sending Number>
PHP message: BODY: Rep

Strange that the logging stops where it does? I see all the entries stopping somewhere in that PHP message: BODY line.

Could I have something wrong with my hook file?

Thanks
 
Jan 9, 2018
87
11
8
51
No, that's one of those "feature-bugs". There is a buffer limit on the logging. I suspect it will only write a certain amount to the log at a time. It's writing a lot to the log for each inbound message, for troubleshooting purposes. It will cut off the log in the middle of a line, somewhere along the way. It probably needs something like a "dump" command somewhere in the common hook file, but I haven't bothered to research it, because it doesn't actually seem to impact any other operations.

Since it looks like you are actually receiving the message now, via the webhook, what comes before or after that snippet?

Also, there is a known issue with Bandwidth where they will keep retrying (for a while) if they don't receive back the response they are looking for. See earlier in this thread for solutions. (after you actually get it working/delivering the message, that is)
 

Robert Birch

Member
Mar 16, 2017
81
1
8
49
This seems to be the whole log for the message. Seems like one entry? Is that correct?
Code:
2021/05/03 13:55:34 [error] 8194#8194: *9 FastCGI sent in stderr: "PHP message: [SMS] REQUEST: Array
(
    [USER] => www-data
    [HOME] => /var/www
    [HTTP_CONTENT_TYPE] => application/json; charset=utf-8
    [HTTP_USER_AGENT] => bandwidth-api
    [HTTP_ACCEPT_ENCODING] => gzip
    [HTTP_CONNECTION] => Keep-Alive
    [HTTP_HOST] => testfusion.xxxxxx.com
    [HTTP_CONTENT_LENGTH] => 403
    [SCRIPT_FILENAME] => /var/www/fusionpbx/app/sms/hook/sms_hook_bandwidth.php
    [REDIRECT_STATUS] => 200
    [SERVER_NAME] => fusionpbx
    [SERVER_PORT] => 443
    [SERVER_ADDR] => xxx.xxx.xxx.xxx
    [REMOTE_PORT] => 14378
    [REMOTE_ADDR] => 18.233.250.246
    [SERVER_SOFTWARE] => nginx/1.10.3
    [GATEWAY_INTERFACE] => CGI/1.1
    [HTTPS] => on
    [REQUEST_SCHEME] => https
    [SERVER_PROTOCOL] => HTTP/1.1
    [DOCUMENT_ROOT] => /var/www/fusionpbx
    [DOCUMENT_URI] => /app/sms/hook/sms_hook_bandwidth.php
    [REQUEST_URI] => /app/sms/hook/sms_hook_bandwidth.php
    [SCRIPT_NAME] => /app/sms/hook/sms_hook_bandwidth.php
    [CONTENT_LENGTH] => 403
    [CONTENT_TYPE] ...
PHP message: [SMS] REQUEST: Array
(
    [0] => stdClass Object
        (
            [time] => 2021-05-03T19:55:33.477Z
            [type] => message-received
            [to] => +1<Inbound Number>
            [description] => Incoming message received
            [message] => stdClass Object
                (
                    [id] => fcf1a02d-b86f-4ef9-8a52-8c895cbfce4b
                    [owner] => +1<Inbound NUmber>
                    [applicationId] => xxxxxx
                    [time] => 2021-05-03T19:55:33.387Z
                    [segmentCount] => 1
                    [direction] => in
                    [to] => Array
                        (
                            [0] => +1<Inbound Number>
                        )

                    [from] => +1<Sending Number>
                    [text] => Once more with feeling
                )

        )

)

PHP message: TO: 1<Inbound Number>
PHP message: FROM: 1<Sending Number>
PHP mess

Thanks
 

Robert Birch

Member
Mar 16, 2017
81
1
8
49
If I check the MDRS section in fusion, I can see all the incoming messages now, so I am guessing the hook is working to some extent. :)
 

Robert Birch

Member
Mar 16, 2017
81
1
8
49
Didn't notice there was actual Freeswitch logging for this as well.
Here is that if it helps:
Code:
2021-05-03 14:20:19.673367 [NOTICE] switch_cpp.cpp:1465 [sms] DIRECTION: inbound
2021-05-03 14:20:19.673367 [INFO] switch_cpp.cpp:1465 chat console
2021-05-03 14:20:19.673367 [NOTICE] switch_cpp.cpp:1465 [sms] TO: 101@testfusion.xxxx.com
2021-05-03 14:20:19.673367 [NOTICE] switch_cpp.cpp:1465 [sms] Extension: 101
2021-05-03 14:20:19.673367 [NOTICE] switch_cpp.cpp:1465 [sms] FROM: 1<Sending Number>
2021-05-03 14:20:19.673367 [NOTICE] switch_cpp.cpp:1465 [sms] BODY: New Test
2021-05-03 14:20:19.673367 [NOTICE] switch_cpp.cpp:1465 [sms] DOMAIN_NAME: testfusion.xxxxx.com
2021-05-03 14:20:19.673367 [NOTICE] switch_cpp.cpp:1465 [sms] MAILSENT (already): 1
2021-05-03 14:20:19.673367 [INFO] switch_cpp.cpp:1465 Event-Name: CUSTOM
Core-UUID: 75dd2cf6-5b4d-4e15-8274-5b82ff3e4186
FreeSWITCH-Hostname: fusion
FreeSWITCH-Switchname: fusion
FreeSWITCH-IPv4: <Internal IP>
FreeSWITCH-IPv6: fe80%3A%3A250%3A56ff%3Afe8a%3Ab584
Event-Date-Local: 2021-05-03%2014%3A20%3A19
Event-Date-GMT: Mon,%2003%20May%202021%2020%3A20%3A19%20GMT
Event-Date-Timestamp: 1620073219673367
Event-Calling-File: switch_cpp.cpp
Event-Calling-Function: Event
Event-Calling-Line-Number: 314
Event-Sequence: 35363
Event-Subclass: SMS%3A%3ASEND_MESSAGE
proto: sip
dest_proto: sip
from: sip%3A1<Sending Number>
from_user: 1<Sending Number>
from_host: testfusion.xxxxx.com
from_full: sip%3A1<Sending Number>%40testfusion.xxxxx.com
sip_profile: internal
to: 101%40testfusion.xxxxx.com
to_user: 101
to_host: testfusion.xxxxx.com
subject: SIMPLE%20MESSAGE
type: text/plain
hint: the%20hint
replying: true
DP_MATCH: 101%40testfusion.xxxxx.com
Content-Length: 8

New Test
2021-05-03 14:20:19.673367 [NOTICE] switch_cpp.cpp:1465 [sms] SQL DOMAIN_NAME: SELECT domain_uuid FROM v_domains WHERE domain_name = :domain_name; params:{"domain_name":"testfusion.xxxxx.com"}
2021-05-03 14:20:19.673367 [DEBUG] mod_sms.c:92 SMS Delivery assumed successful due to being sent in non-blocking manner
2021-05-03 14:20:19.673367 [NOTICE] switch_cpp.cpp:1465 [sms] SQL EXTENSION: SELECT extension_uuid FROM v_extensions WHERE domain_uuid = :domain_uuid and extension = :extension; params:{"domain_uuid":"<domain_uuid>","extension":"101"}
2021-05-03 14:20:19.673367 [NOTICE] switch_cpp.cpp:1465 [sms] SQL: insert into v_sms_messages(sms_message_uuid,extension_uuid,domain_uuid,start_stamp,from_number,to_number,message,direction,response,carrier) values (:uuid,:extension_uuid,:domain_uuid,now(),:from,:to,:body,:direction,'',:carrier); params:{"to":"101","direction":"inbound","domain_uuid":"<domain_uuid>","carrier":"","uuid":"88c85814-0c81-4186-b4fa-2bdc1fb2391a","from":"1<Sending Number>","body":"New Test","extension_uuid":"9e2e99fd-f8fb-46a1-bf71-2e053682c06f"}

Thanks
 

Robert Birch

Member
Mar 16, 2017
81
1
8
49
Should also say adding:
fastcgi_buffers 16 16k;
fastcgi_buffer_size 32k;

to the nginx.conf file got rid of the upstream sent too big header while reading response header from upstream error.

Thanks
 

Robert Birch

Member
Mar 16, 2017
81
1
8
49
UGH!!!! Don't I feel like an idiot. The message are actually getting through. I wasn't getting a notification for them in the GroundWire app, so didn't realize they were coming into the 1xxxxxxx verison of the number, not xxxxxxx version of the number.

I'm sorry, but I guess it is working now!!!!!

Thanks for all the help. I do appreciate it.
 
Jan 9, 2018
87
11
8
51
No problem. Yes, the whole 1+ thing on responses has bitten me a time or two. Glad it's working for you!

Regarding the log truncation, here's some info on that. I haven't tried changing the log_errors_max_len setting, but it sounds like that might work. Could even try the ini_set command at the start of the hook file.