Hi there. I am revisiting this post and the info was very helpful to get going thank you to all. I seem to be stuck in doodle vortex though that endlessly loops my messages, even after delivery. I am sending SMS from an external number to a DID which points to a phone. The message is received but as mentioned kazoo and FS loops endlessly causing a flood. I'm wondering if anyone has an idea of what the issue is? FS version is kazoo-freeswitch-4.0-7.el7
Jun 25 22:08:03 kz 2600hz[3012]: |0000000000|gen_listener:381 (<0.28000.9>) starting new gen_listener proc : doodle_exe
Jun 25 22:08:03 kz 2600hz[3012]: |kz_amqp_assignments|kz_amqp_assignments:475 (<0.118.0>) assigned existing channel <0.27865.9> on amqp://guest:guest@kz:5672 to new consumer <0.28000.9>
Jun 25 22:08:03 kz 2600hz[3012]: |kz_amqp_assignments|kz_amqp_assignments:886 (<0.118.0>) registered handlers for channel <0.27865.9> to <0.28000.9>
Jun 25 22:08:03 kz 2600hz[3012]: |3c7bab56cf6087cb10b612e2605c4881|gen_listener:1147 (<0.28000.9>) channel started, let's connect
Jun 25 22:08:03 kz 2600hz[3012]: |0000000000|Undefined:Undefined (<0.28002.9>) Supervisor {<0.28002.9>,amqp_channel_sup} started amqp_gen_consumer:start_link(amqp_selective_consumer, [], {<<"client 158.xxx:40769 -> 158.xxxx:5672">>,5146}) at pid <0.28003.9>
Jun 25 22:08:03 kz 2600hz[3012]: |0000000000|Undefined:Undefined (<0.28002.9>) Supervisor {<0.28002.9>,amqp_channel_sup} started amqp_channel:start_link(network, <0.125.0>, 5146, <0.28003.9>, {<<"client 158.x.x.x:40769 -> 158.x.x.x:5672">>,5146}) at pid <0.28004.9>
Jun 25 22:08:03 kz 2600hz[3012]: |0000000000|Undefined:Undefined (<0.28002.9>) Supervisor {<0.28002.9>,amqp_channel_sup} started rabbit_writer:start_link(#Port<0.3042>, 5146, 131072, rabbit_framing_amqp_0_9_1, <0.28004.9>, {<<"client x.x.x.x:40769 -> 158.x.x.x:5672">>,5146}) at pid <0.28005.9>
Jun 25 22:08:03 kz 2600hz[3012]: |3c7bab56cf6087cb10b612e2605c4881|kz_amqp_channel:302 (<0.28000.9>) declared queue kazoo_apps@kz-<0.28000.9>-1e94bf13 via channel <0.27865.9>
Jun 25 22:08:03 kz 2600hz[3012]: |kz_amqp_assignments|kz_amqp_assignments:600 (<0.118.0>) added new channel <0.28004.9> on amqp://guest:guest@kz:5672 to available pool
Jun 25 22:08:03 kz 2600hz[3012]: |3c7bab56cf6087cb10b612e2605c4881|kz_amqp_channel:328 (<0.28000.9>) created consumer amq.ctag-r2hVldOEN3ifGI6Hkm5dOA via channel <0.27865.9>
Jun 25 22:08:03 kz 2600hz[3012]: |3c7bab56cf6087cb10b612e2605c4881|gen_listener:889 (<0.28000.9>) queue started: kazoo_apps@kz-<0.28000.9>-1e94bf13
Jun 25 22:08:03 kz 2600hz[3012]: |3c7bab56cf6087cb10b612e2605c4881|gen_listener:1038 (<0.28000.9>) creating new binding: 'sms'
Jun 25 22:08:03 kz 2600hz[3012]: |3c7bab56cf6087cb10b612e2605c4881|kz_amqp_channel:321 (<0.28000.9>) bound kazoo_apps@kz-<0.28000.9>-1e94bf13 to sms exchange (routing key message.delivery.3c7bab56cf6087cb10b612e2605c4881) via channel <0.27865.9>
Jun 25 22:08:03 kz 2600hz[3012]: |3c7bab56cf6087cb10b612e2605c4881|gen_listener:1038 (<0.28000.9>) creating new binding: 'self'
Jun 25 22:08:03 kz 2600hz[3012]: |3c7bab56cf6087cb10b612e2605c4881|kz_amqp_channel:321 (<0.28000.9>) bound kazoo_apps@kz-<0.28000.9>-1e94bf13 to targeted exchange (routing key kazoo_apps@kz-<0.28000.9>-1e94bf13) via channel <0.27865.9>
Jun 25 22:08:03 kz 2600hz[3012]: |3c7bab56cf6087cb10b612e2605c4881|kz_amqp_channel:159 (<0.28006.9>) published to callctl(amqp://guest:guest@kz:5672) exchange (routing key chatplan_ignored) via <0.27865.9>
Jun 25 22:08:03 kz 2600hz[3012]: |034c65e5c7d06160|kz_amqp_channel:159 (<0.27275.1>) published to configuration(amqp://guest:guest@kz:5672) exchange (routing key doc_edited.account%2F01%2F80%2Ffabe1652a755xxxxxxxxxxxxxxx-201706.sms.201706-1946d9698c2987923625791d8e300452) via <0.27238.1>
Jun 25 22:08:03 kz 2600hz[3012]: |034c65e5c7d06160|kz_amqp_worker:663 (<0.27275.1>) published message 034c65e5c7d06160 for <0.27967.9>
Jun 25 22:08:03 kz 2600hz[3012]: |034c65e5c7d06160|webhooks_object:103 (<0.27969.9>) no hooks to handle doc_edited for {account id}
Jun 25 22:08:03 kz 2600hz[3012]: |kz_couch_compactor|kz_couch_compactor:1597 (<0.1198.0>) getting db info attempt 1
Jun 25 22:08:03 kz 2600hz[3012]: |3c7bab56cf6087cb10b612e2605c4881|kz_endpoint:827 (<0.28006.9>) failed to create endpoint: call_forward_not_appropriate
Jun 25 22:08:03 kz 2600hz[3012]: |3c7bab56cf6087cb10b612e2605c4881|kapps_config:386 (<0.28006.9>) setting default for kazoo_endpoint [<<"sip_transport">>]: undefined
Jun 25 22:08:03 kz 2600hz[3012]: |3c7bab56cf6087cb10b612e2605c4881|kapps_config:386 (<0.28006.9>) setting default for kazoo_endpoint [<<"custom_sip_interface">>]: undefined
Jun 25 22:08:03 kz 2600hz[3012]: |3c7bab56cf6087cb10b612e2605c4881|kz_endpoint:178 (<0.28006.9>) no formatters defined
Jun 25 22:08:03 kz 2600hz[3012]: |3c7bab56cf6087cb10b612e2605c4881|kz_amqp_worker:441 (<0.28006.9>) attempting to collect 1 responses from ecallmgr
Jun 25 22:08:03 kz 2600hz[3012]: |57e1a9aa04790c0d|kz_amqp_channel:159 (<0.27275.1>) published to registrar(amqp://guest:guest@kz:5672) exchange (routing key registration.query.domain.user_xxx) via <0.27238.1>
Jun 25 22:08:03 kz 2600hz[3012]: |57e1a9aa04790c0d|kz_amqp_worker:614 (<0.27275.1>) published request with msg id 57e1a9aa04790c0d for <0.28006.9>
Jun 25 22:08:03 kz 2600hz[3012]: |57e1a9aa04790c0d|kz_amqp_worker:798 (<0.27275.1>) recv message 57e1a9aa04790c0d
Jun 25 22:08:03 kz 2600hz[3012]: |57e1a9aa04790c0d|kz_amqp_worker:802 (<0.27275.1>) responses have apparently met the criteria for the client, returning
Jun 25 22:08:03 kz 2600hz[3012]: |57e1a9aa04790c0d|kz_amqp_worker:803 (<0.27275.1>) response for msg id 57e1a9aa04790c0d took 2366us to return
Jun 25 22:08:03 kz 2600hz[3012]: |3c7bab56cf6087cb10b612e2605c4881|kapps_sms_command:127 (<0.28006.9>) sending sms and waiting for response 3c7bab56cf6087cb10b612e2605c4881
Jun 25 22:08:03 kz 2600hz[3012]: |3c7bab56cf6087cb10b612e2605c4881|kz_amqp_channel:159 (<0.27275.1>) published to sms(amqp://guest:guest@kz:5672) exchange (routing key message.route.kamailio%40kz2%2Ekz.3c7bab56cf6087cb10b612e2605c4881) via <0.27238.1>
Jun 25 22:08:03 kz 2600hz[3012]: |3c7bab56cf6087cb10b612e2605c4881|kz_amqp_worker:663 (<0.27275.1>) published message 6e0b524b0d154063 for <0.28006.9>
Jun 25 22:08:04 kz 2600hz[3012]: |c9aa7276d02e9fedd77a32100ce5af10|kz_amqp_channel:159 (<0.27275.1>) published to callctl(amqp://guest:guest@kz:5672) exchange (routing key chatplan_ignored) via <0.27238.1>
Jun 25 22:08:04 kz 2600hz[3012]: |c9aa7276d02e9fedd77a32100ce5af10|kz_amqp_worker:663 (<0.27275.1>) published message 42c9d585f08cb094 for <0.25731.9>
Jun 25 22:08:04 kz 2600hz[3012]: |c9aa7276d02e9fedd77a32100ce5af10|kz_amqp_channel:95 (<0.25731.9>) release consumer <0.25731.9> channel assignment
Jun 25 22:08:04 kz 2600hz[3012]: |kz_amqp_assignments|kz_amqp_assignments:893 (<0.118.0>) unregistered handlers for channel <0.22166.9>
Jun 25 22:08:04 kz 2600hz[3012]: |c9aa7276d02e9fedd77a32100ce5af10|gen_listener:724 (<0.25731.9>) doodle_exe terminated cleanly, going down
Jun 25 22:08:04 kz 2600hz[3012]: |kz_amqp_history|kz_amqp_history:301 (<0.119.0>) removing AMQP history for consumer <0.25731.9> in 2.5s: normal
Jun 25 22:08:04 kz 2600hz[3012]: |3c7bab56cf6087cb10b612e2605c4881|doodle_util:270 (<0.20851.9>) trying to replay sms 201706-61f1e7df802635ae47856d490908566c for account {account id}
Jun 25 22:08:04 kz 2600hz[3012]: |kz_amqp_assignments|kz_amqp_channel:105 (<0.118.0>) closed amqp channel <0.22166.9>
Jun 25 22:08:04 kz 2600hz[3012]: |kz_amqp_assignments|kz_amqp_assignments:300 (<0.118.0>) removed assignment for consumer <0.25731.9>
Jun 25 22:08:04 kz 2600hz[3012]: |3c7bab56cf6087cb10b612e2605c4881|doodle_util:280 (<0.20851.9>) replaying sms 201706-61f1e7df802635ae47856d490908566c for account {account id}
Jun 25 22:08:04 kz 2600hz[3012]: |61f1e7df802635ae47856d490908566c|doodle_route_win:62 (<0.20851.9>) error getting kz_endpoint for the sms : invalid_endpoint_id
Jun 25 22:08:04 kz 2600hz[3012]: |61f1e7df802635ae47856d490908566c|kz_amqp_channel:159 (<0.20851.9>) published to callctl(amqp://guest:guest@kz:5672) exchange (routing key chatplan_ignored) via <0.21251.2>
FS Log
-----------
2017-06-26 01:54:05.713654 [INFO] mod_sms.c:368 Processing text message 151xxxx->1844xxxx in context context_2
2017-06-26 01:54:05.713654 [DEBUG] kazoo_fetch_agent.c:216 Sending chatplan XML request (927ccf6e-5a01-11e7-9a0c-7ff39be64202) to ecallmgr@kz2 <1.19971.6>
send 610 bytes to udp/[158.xxxx]:5060 at 01:54:05.721080:
------------------------------------------------------------------------
SIP/2.0 202 Accepted
Via: SIP/2.0/UDP 158.x.x.x;branch=z9hG4bK42ac.979e06fad9da977a912e6730f6c14929.0
Via: SIP/2.0/UDP 158.6x.x.x;received=158.6xxxx;rport=5060;branch=z9hG4bK22UH80QKFv7vS
From: <sip:1514x...@64.xxxx>;tag=sansay1958528959rdb27188
Call-ID: 95c64c22-5a01-11e7-a680-3fdc8336d067
CSeq: 108881628 MESSAGE
Contact: <sip:158.69.xxxx>
User-Agent: CloudCalling.me
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Content-Length: 0
------------------------------------------------------------------------
2017-06-26 01:54:05.873644 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@kz2 <1.24118.6>
2017-06-26 01:54:05.873644 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@kz2 <1.19971.6>
2017-06-26 01:54:05.893647 [DEBUG] kazoo_fetch_agent.c:277 Received chatplan XML (927ccf6e-5a01-11e7-9a0c-7ff39be64202) after 179ms: <document type="freeswitch/xml"><section name="chatplan" description="Chat Response"><context name="context_2"><extension name="chat plan" continue="false"><condition><action application="stop" data="stored"/></condition></extension></context></section></document>
Chatplan: 18446xxxx parsing [context_2->chat plan] continue=false
Chatplan: 1844...@158.x.x.x Absolute Condition [chat plan]
Chatplan: 1844...@158.x.x.x Action stop(stored)
2017-06-26 01:54:05.893647 [DEBUG] sofia_presence.c:225 Can't find registered user 1844...@158.x.x.x
send 636 bytes to udp/[158.x.x.x]:5060 at 01:54:05.895742:
------------------------------------------------------------------------
MESSAGE sip:1844...@158.x.x.x SIP/2.0
Via: SIP/2.0/UDP 158.6x.x.x;rport;branch=z9hG4bKyF7tH3SN7QUyj
Max-Forwards: 70
From: <sip:15145...@64.xx.x.>;tag=sansay1958528959rdb27188
To: <sip:1844xxx@158.>
Call-ID: 929770da-5a01-11e7-9a0d-7ff39be64202
CSeq: 108881639 MESSAGE
User-Agent: CloudCalling
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Content-Type: text/plain
Content-Length: 12
X-FS-Sending-Message: d659adac-5a00-11e7-9736-7ff39be64202
X-AUTH-IP: 158.
X-AUTH-PORT: 5060
new sms test
------------------------
FS version is kazoo-freeswitch-4.0-7.el7
Thanks for any insight on this!
Matt