ACDC call insertion to member queue failure

297 views
Skip to first unread message

Mike Montgomery

unread,
Jun 24, 2017, 2:22:46 PM6/24/17
to 2600hz...@googlegroups.com
We have been using ACDC to build a call center into a new customer’s PBX. After spending time understanding how it works and getting the rabbitmq priority queue plugin installed, we created the queues through API calls and manually built in callflow primitives for agent queue login/logout and member call insertion to the queues in the database so we could string them together in the callflow editor in Monster.

Magically, it worked!

We could have agents login to queues, calls come in and get inserted to queues and ring through to the agents. We then started building the callflow for the customer’s Main number. We found that if we wanted to progress callers through a series of queues with different marketing messages media used in the “moh" parameter of the queue we needed to add silence to the front and back and have the audio duration exactly the length of the “connection_timeout” parameter. If we didn’t, the subsequent menu audio or queue would get “stepped on” with a snippet of the previous audio.

As we adjusted and tuned, the full callflow started coming together and working very well. Then….. something happened.

Now, calls to the queue do not complete. Kazoo complains that the queue cannot be found, Rabbitmq complains that the queue can be found and then 30 seconds later it complains the a precondition is not met when it attempts to delete the queue (presumably the precondition is that the queue exists).

We used the rabbitmq management gui and saw that the queue manager (acdc.queue.manager.xxxx_queue_name_xxxx) existed, however, the actual queue (acdc.queue.yyyyyyyy_Account_ID_yyyyyyy.xxxxx_queue_name_xxxx) did not. We saw the existence of this queue in the management GUI on our federated platform where we first started to implement call queues before we learned that acdc does not work reliably in a federated environment. We created a separate unfederated platform to implement acdc.

Some of the things we have tried:
"sup acdc_maintenance queues_restart AccountID” indicates that the queue was created (no evidence in RabbitMQ management GUI)
“sup kapps_controller restart_app acdc” indicates that the queue was created (no evidence in RabbitMQ management GUI)
Shutdown rabbitmq and wiped the Mnesia database. No change
Deleted all queues through the API and create a new queue. No change
Rebooted the machine. No change

We are stuck and request some pointers on how to get acdc queues working again

-------------------------------------------------------------------------------------------------------------
We are on kazoo-applications 4.0-60, kazoo-freeswitch 4.0-7, kazoo-haproxy 4.0-7, kazoo-kamailio 4.0-7, and kazoo-rabbitmq 4.0-7.

When we make a call to the callflow that inserts the member call to the queue, Kazoo.log shows:

Jun 24 16:49:18 Kazoo Example[9100]: |ZGJjZDY0ZDlkNDI2ODUwZGY4ZmZlMjg1MmUwZjI5N2U-S|gen_listener:1038 (<0.29074.0>) creating new binding: 'call'
Jun 24 16:49:18 Kazoo Example[9100]: |ZGJjZDY0ZDlkNDI2ODUwZGY4ZmZlMjg1MmUwZjI5N2U-S|kz_amqp_channel:321 (<0.29074.0>) bound kazoo...@Kazoo.example.com-<0.29074.0>-79743f36 to callevt exchange (routing key call.*.ZGJjZDY0ZDlkNDI2ODUwZGY4ZmZlMjg1MmUwZjI5N2U-S) via channel <0.20184.0>
Jun 24 16:49:18 Kazoo Example[9100]: |ZGJjZDY0ZDlkNDI2ODUwZGY4ZmZlMjg1MmUwZjI5N2U-S|gen_listener:1038 (<0.29074.0>) creating new binding: 'self'
Jun 24 16:49:18 Kazoo Example[9100]: |ZGJjZDY0ZDlkNDI2ODUwZGY4ZmZlMjg1MmUwZjI5N2U-S|kz_amqp_channel:321 (<0.29074.0>) bound kazoo...@Kazoo.example.com-<0.29074.0>-79743f36 to targeted exchange (routing key kazoo...@Kazoo.example.com-<0.29074.0>-79743f36) via channel <0.20184.0>
Jun 24 16:49:18 Kazoo Example[9100]: |ZGJjZDY0ZDlkNDI2ODUwZGY4ZmZlMjg1MmUwZjI5N2U-S|cf_exe:499 (<0.29074.0>) ready to recv events, launching the callflow
Jun 24 16:49:18 Kazoo Example[9100]: |ZGJjZDY0ZDlkNDI2ODUwZGY4ZmZlMjg1MmUwZjI5N2U-S|cf_exe:689 (<0.29074.0>) moving to action 'cf_callflow'
Jun 24 16:49:18 Kazoo Example[9100]: |0000000000|kz_amqp_channel:159 (<0.1794.0>) published to targeted(amqp://guest:gu...@192.168.200.59:5672) exchange (routing key statistics) via <0.1769.0>
Jun 24 16:49:18 Kazoo Example[9100]: |8cea79c33942f4f7|kz_cache:817 (<0.1095.0>) storing {kzs_cache,<<"account%2Fb4%2Fce%2F674748f8d53ec124f863e4a96c4a">>,<<"f9473cd380d981b56dd743821aa13e7d">>} for 900s
Jun 24 16:49:18 Kazoo Example[9100]: |8cea79c33942f4f7|kz_cache:819 (<0.1095.0>) inserted {kzs_cache,<<"account%2Fb4%2Fce%2F674748f8d53ec124f863e4a96c4a">>,<<"f9473cd380d981b56dd743821aa13e7d">>}
Jun 24 16:49:18 Kazoo Example[9100]: |8cea79c33942f4f7|kz_cache:821 (<0.1095.0>) inserted origin pointers for {kzs_cache,<<"account%2Fb4%2Fce%2F674748f8d53ec124f863e4a96c4a">>,<<"f9473cd380d981b56dd743821aa13e7d">>}
Jun 24 16:49:18 Kazoo Example[9100]: |8cea79c33942f4f7|kz_cache:823 (<0.1095.0>) exec store callbacks
Jun 24 16:49:18 Kazoo Example[9100]: |ZGJjZDY0ZDlkNDI2ODUwZGY4ZmZlMjg1MmUwZjI5N2U-S|cf_callflow:32 (<0.29083.0>) branching to new callflow f9473cd380d981b56dd743821aa13e7d
Jun 24 16:49:18 Kazoo Example[9100]: |ZGJjZDY0ZDlkNDI2ODUwZGY4ZmZlMjg1MmUwZjI5N2U-S|cf_exe:451 (<0.29074.0>) callflow has been branched

Jun 24 16:49:18 Kazoo Example[9100]: |ZGJjZDY0ZDlkNDI2ODUwZGY4ZmZlMjg1MmUwZjI5N2U-S|cf_exe:689 (<0.29074.0>) moving to action 'cf_acdc_member'
Jun 24 16:49:18 Kazoo Example[9100]: |ZGJjZDY0ZDlkNDI2ODUwZGY4ZmZlMjg1MmUwZjI5N2U-S|cf_exe:550 (<0.29074.0>) cf module cf_callflow down normally
Jun 24 16:49:18 Kazoo Example[9100]: |ZGJjZDY0ZDlkNDI2ODUwZGY4ZmZlMjg1MmUwZjI5N2U-S|cf_acdc_member:42 (<0.29084.0>) sending call to queue dbbdc5482210108aa6eb25a6b3688ed6
Jun 24 16:49:18 Kazoo Example[9100]: |ZGJjZDY0ZDlkNDI2ODUwZGY4ZmZlMjg1MmUwZjI5N2U-S|cf_acdc_member:54 (<0.29084.0>) loading ACDc queue: dbbdc5482210108aa6eb25a6b3688ed6
Jun 24 16:49:18 Kazoo Example[9100]: |8cea79c33942f4f7|kz_cache:817 (<0.1095.0>) storing {kzs_cache,<<"account%2Fb4%2Fce%2F674748f8d53ec124f863e4a96c4a">>,<<"dbbdc5482210108aa6eb25a6b3688ed6">>} for 900s
Jun 24 16:49:18 Kazoo Example[9100]: |8cea79c33942f4f7|kz_cache:819 (<0.1095.0>) inserted {kzs_cache,<<"account%2Fb4%2Fce%2F674748f8d53ec124f863e4a96c4a">>,<<"dbbdc5482210108aa6eb25a6b3688ed6">>}
Jun 24 16:49:18 Kazoo Example[9100]: |8cea79c33942f4f7|kz_cache:821 (<0.1095.0>) inserted origin pointers for {kzs_cache,<<"account%2Fb4%2Fce%2F674748f8d53ec124f863e4a96c4a">>,<<"dbbdc5482210108aa6eb25a6b3688ed6">>}
Jun 24 16:49:18 Kazoo Example[9100]: |8cea79c33942f4f7|kz_cache:823 (<0.1095.0>) exec store callbacks

Jun 24 16:49:18 Kazoo Example[9100]: |ZGJjZDY0ZDlkNDI2ODUwZGY4ZmZlMjg1MmUwZjI5N2U-S|kz_amqp_channel:262 (<0.29084.0>) amqp command exception exit : {{shutdown,{server_initiated_close,404,<<"NOT_FOUND - no queue 'acdc.queue.b4ce674748f8d53ec124f863e4a96c4a.dbbdc5482210108aa6eb25a6b3688ed6' in vhost '/'">>}},{gen_server,call,[<0.20184.0>,{call,{'queue.declare',0,<<"acdc.queue.b4ce674748f8d53ec124f863e4a96c4a.dbbdc5482210108aa6eb25a6b3688ed6">>,true,false,false,true,false,[{<<"x-message-ttl">>,signedint,60000},{<<"x-max-length">>,short,100}]},none,<0.29084.0>},infinity]}}
Jun 24 16:49:18 Kazoo Example[9100]: |kz_amqp_assignments|kz_amqp_assignments:751 (<0.118.0>) floating channel <0.20184.0> on amqp://guest:gu...@192.168.200.59:5672 went down while still assigned to consumer <0.29074.0>: {shutdown,{server_initiated_close,404,<<"NOT_FOUND - no queue 'acdc.queue.b4ce674748f8d53ec124f863e4a96c4a.dbbdc5482210108aa6eb25a6b3688ed6' in vhost '/'">>}}

Jun 24 16:49:18 Kazoo Example[9100]: |kz_amqp_assignments|kz_amqp_assignments:767 (<0.118.0>) defer channel reassign for 30000 ms
Jun 24 16:49:18 Kazoo Example[9100]: |ZGJjZDY0ZDlkNDI2ODUwZGY4ZmZlMjg1MmUwZjI5N2U-S|cf_exe:728 (<0.29084.0>) action cf_acdc_member died unexpectedly (error): {try_clause,{error,{{shutdown,{server_initiated_close,404,<<"NOT_FOUND - no queue 'acdc.queue.b4ce674748f8d53ec124f863e4a96c4a.dbbdc5482210108aa6eb25a6b3688ed6' in vhost '/'">>}},{gen_server,call,[<0.20184.0>,{call,{'queue.declare',0,<<"acdc.queue.b4ce674748f8d53ec124f863e4a96c4a.dbbdc5482210108aa6eb25a6b3688ed6">>,true,false,false,true,false,[{<<"x-message-ttl">>,signedint,60000},{<<"x-max-length">>,short,100}]},none,<0.29084.0>},infinity]}}}}
Jun 24 16:49:18 Kazoo Example[9100]: |ZGJjZDY0ZDlkNDI2ODUwZGY4ZmZlMjg1MmUwZjI5N2U-S|kz_util:171 (<0.29084.0>) stacktrace:
Jun 24 16:49:18 Kazoo Example[9100]: |ZGJjZDY0ZDlkNDI2ODUwZGY4ZmZlMjg1MmUwZjI5N2U-S|kz_util:185 (<0.29084.0>) st: kapi_acdc_queue:queue_size/2 at (612)
Jun 24 16:49:18 Kazoo Example[9100]: |ZGJjZDY0ZDlkNDI2ODUwZGY4ZmZlMjg1MmUwZjI5N2U-S|kz_util:185 (<0.29084.0>) st: cf_acdc_member:handle/2 at (62)
Jun 24 16:49:19 Kazoo Example[9100]: |ZGJjZDY0ZDlkNDI2ODUwZGY4ZmZlMjg1MmUwZjI5N2U-S|kz_util:185 (<0.29084.0>) st: cf_exe:cf_module_task/4 at (724)
Jun 24 16:49:19 Kazoo Example[9100]: |ZGJjZDY0ZDlkNDI2ODUwZGY4ZmZlMjg1MmUwZjI5N2U-S|cf_exe:543 (<0.29074.0>) action cf_acdc_member died unexpectedly: {{nocatch,{try_clause,{error,{{shutdown,{server_initiated_close,404,<<"NOT_FOUND - no queue 'acdc.queue.b4ce674748f8d53ec124f863e4a96c4a.dbbdc5482210108aa6eb25a6b3688ed6' in vhost '/'">>}},{gen_server,call,[<0.20184.0>,{call,{'queue.declare',0,<<"acdc.queue.b4ce674748f8d53ec124f863e4a96c4a.dbbdc5482210108aa6eb25a6b3688ed6">>,true,false,false,true,false,[{<<"x-message-ttl">>,signedint,60000},{<<"x-max-length">>,short,100}]},none,<0.29084.0>},infinity]}}}}},[{cf_exe,cf_module_task,4,[{file,"src/cf_exe.erl"},{line,730}]}]}
Jun 24 16:49:19 Kazoo Example[9100]: |ZGJjZDY0ZDlkNDI2ODUwZGY4ZmZlMjg1MmUwZjI5N2U-S|cf_exe:411 (<0.29074.0>) continuing to child '_'
Jun 24 16:49:19 Kazoo Example[9100]: |ZGJjZDY0ZDlkNDI2ODUwZGY4ZmZlMjg1MmUwZjI5N2U-S|cf_exe:415 (<0.29074.0>) wildcard child does not exist, we are lost...hanging up

At the same time, rabbitmq.log shows:

=ERROR REPORT==== 24-Jun-2017::16:49:18 ===
connection <0.5604.0>, channel 265 - soft error:
{amqp_error,not_found,
"no queue 'acdc.queue.b4ce674748f8d53ec124f863e4a96c4a.dbbdc5482210108aa6eb25a6b3688ed6' in vhost '/'",
'queue.declare'}

=ERROR REPORT==== 24-Jun-2017::16:49:48 ===
connection <0.5604.0>, channel 266 - soft error:
{amqp_error,precondition_failed,
"queue 'kazoo...@KZD.trust-tek.com-<0.29074.0>-79743f36' in vhost '/' in use",
'queue.delete'}


If you made it all the way to this point, your assistance is appreciated!

Best Regards,

Mike Montgomery
919 539 6133




James Aimonetti

unread,
Jun 26, 2017, 11:46:59 AM6/26/17
to 2600hz...@googlegroups.com
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

Perhaps you can capture the logs when you try restarting the ACDc queue
via SUP?

And barring something there, the logs for restarting ACDc itself?
- --
James Aimonetti

Lead Systems Architect
"If Dialyzer don't care, I don't care"
2600HzPDX | http://2600hz.com
sip:ja...@2600hz.com
tel:415.886.7905
irc:mc_ @ freenode
-----BEGIN PGP SIGNATURE-----

iQEzBAEBCAAdFiEEvSh+xZ5hP1H8lVIU1Mpr4k9cJWAFAllRLGwACgkQ1Mpr4k9c
JWDiQgf+MJa/5c3IlbNSUyTuCZnmwnp25RM/s8c4stCGU4ZgLMBTbuRTRkHlWZW+
CV/anWUA70kwhpMEjt9GHPJZB7sb2JL7QcfiXYGro/Ib/ULyKXMd99q2Emj9Yw0p
9eywTsEsh+1/2af9iJW+W54wojHRNwXWzWKUMe9vA8QgUeo0QdgJQyvSl920N4Jg
donIv8YWbt+wxREJoaOpy9Itw4HYQDH5F/mmV6apOfAIQskFsGe5bAK/QzJfHUI5
2qEIfEldtNMCFFdXeY5ArP6ro77c9En3rlzsHDOdUaUeo8cIOQYWn9QHDL+WCJVy
CKUXFascyYj9i33+m98+Mss0trqdqw==
=oJiy
-----END PGP SIGNATURE-----

Mike Montgomery

unread,
Jun 26, 2017, 6:45:01 PM6/26/17
to 2600hz...@googlegroups.com
Thank you, James.

It seems that the queue manager get created but not the queue itself

Any direction you can provide is appreciated

Here is the gist of the queue restart >>> Queue_restart

Here is the gist of ACDC restart >>>> ACDC_Restart

Best Regards,

Mike Montgomery




--
You received this message because you are subscribed to the Google Groups "2600hz-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to 2600hz-users...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

Reply all
Reply to author
Forward
0 new messages