CTI working, but with some POST 500 errors. Not opening user or ticket when accepting calls?

Infos:

  • Used Zammad version: 3.6.0-1610545422.444c3a5d.buster amd64
  • Used Zammad installation source: apt-package from: https://dl.packager.io/srv/deb/zammad/zammad/stable/debian 10 main
  • Operating system: Debian 10.7
  • Browser + version: Google Chrome Version 87.0.4280.141 (64-Bit)
  • CTI connection established with our NetPhone (Telekom branded “Swyx”) telephone system and call routing

Expected behavior:

  • Not really sure since it seems something isn’t working as it should. I guess when a CTI call is incoming, a new ticket or the customer page should open.

Actual behavior:

  • Here’s the actual behavior, whats happening when a call is incoming, gets picked up by the agent (who is also in the notify-map) and hung up a few seconds afterwards. When the call is incoming, there’s a “+”-Button to open a new ticket. When accepting the call however, it’s gone and the call just remains in the overall list and you can’t really do anything from there.

Also, we receive the following POST error in the http-logs of the CTI integration menu:

The error-log ID shown in the screenshot refers to the following log from the server:

I, [2021-01-15T09:11:55.841404 #20729-70046885162700]  INFO -- : Started POST "/api/v1/cti/gi5idl6[***censored***]zYBeB3Jt8" for [***censored***] at 2021-01-15 09:11:55 +0100
I, [2021-01-15T09:11:55.844767 #20729-70046885162700]  INFO -- : Processing by Integration::CtiController#event as */*
I, [2021-01-15T09:11:55.844832 #20729-70046885162700]  INFO -- :   Parameters: {"event"=>"answer", "from"=>" 141", "to"=>"145", "direction"=>"in", "callId"=>"566537", "user"=>[""], "answeringNumber"=>"49
", "token"=>"gi5idl6[***censored***]BeB3Jt8"}
I, [2021-01-15T09:11:55.872328 #20729-70046885162700]  INFO -- : Enqueued SearchIndexJob (Job ID: 2338e8f4-b462-48ce-ad0a-bbf19c9339ba) to DelayedJob(default) with arguments: "Cti::Log", 43
I, [2021-01-15T09:11:55.876199 #20729-70046885162700]  INFO -- : Enqueued SearchIndexAssociationsJob (Job ID: e63fd9ca-4a7e-42b2-a7da-07d8ffed94b4) to DelayedJob(default) with arguments: "Cti::Log", 43
E, [2021-01-15T09:11:55.887312 #20729-70046885162700] ERROR -- : undefined method `downcase' for [""]:Array (NoMethodError)
/opt/zammad/app/models/cti/driver/base.rb:183:in `push_open_ticket_screen_recipient'
/opt/zammad/app/models/cti/driver/base.rb:131:in `push_open_ticket_screen'
/opt/zammad/app/models/cti/driver/base.rb:47:in `process'
/opt/zammad/app/controllers/integration/cti_controller.rb:13:in `event'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/abstract_controller/base.rb:194:in `process_action'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_controller/metal/rendering.rb:30:in `process_action'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/abstract_controller/callbacks.rb:42:in `block in process_action'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/callbacks.rb:109:in `block in run_callbacks'
/opt/zammad/app/controllers/application_controller/has_secure_content_security_policy_for_downloads.rb:18:in `block (4 levels) in <module:HasSecureContentSecurityPolicyForDownloads>'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/notifications.rb:180:in `subscribed'
/opt/zammad/app/controllers/application_controller/has_secure_content_security_policy_for_downloads.rb:17:in `block (3 levels) in <module:HasSecureContentSecurityPolicyForDownloads>'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/notifications.rb:180:in `subscribed'
/opt/zammad/app/controllers/application_controller/has_secure_content_security_policy_for_downloads.rb:16:in `block (2 levels) in <module:HasSecureContentSecurityPolicyForDownloads>'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/callbacks.rb:118:in `instance_exec'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/callbacks.rb:118:in `block in run_callbacks'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/callbacks.rb:136:in `run_callbacks'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/abstract_controller/callbacks.rb:41:in `process_action'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_controller/metal/rescue.rb:22:in `process_action'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_controller/metal/instrumentation.rb:34:in `block in process_action'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/notifications.rb:168:in `block in instrument'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/notifications/instrumenter.rb:23:in `instrument'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/notifications.rb:168:in `instrument'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_controller/metal/instrumentation.rb:32:in `process_action'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_controller/metal/params_wrapper.rb:256:in `process_action'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.4.4/lib/active_record/railties/controller_runtime.rb:24:in `process_action'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/abstract_controller/base.rb:134:in `process'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionview-5.2.4.4/lib/action_view/rendering.rb:32:in `process'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_controller/metal.rb:191:in `dispatch'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_controller/metal.rb:252:in `dispatch'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/routing/route_set.rb:52:in `dispatch'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/routing/route_set.rb:34:in `serve'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/journey/router.rb:52:in `block in serve'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/journey/router.rb:35:in `each'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/journey/router.rb:35:in `serve'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/routing/route_set.rb:840:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:420:in `call_app!'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-saml-1.10.1/lib/omniauth/strategies/saml.rb:89:in `other_phase'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:190:in `call!'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:169:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:192:in `call!'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:169:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:192:in `call!'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:169:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:192:in `call!'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:169:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:192:in `call!'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:169:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:192:in `call!'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:169:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:192:in `call!'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:169:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:192:in `call!'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:169:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:192:in `call!'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:169:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:192:in `call!'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:169:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/builder.rb:45:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/rack-2.2.3/lib/rack/tempfile_reaper.rb:15:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/rack-2.2.3/lib/rack/etag.rb:27:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/rack-2.2.3/lib/rack/conditional_get.rb:40:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/rack-2.2.3/lib/rack/head.rb:12:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/http/content_security_policy.rb:18:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/rack-2.2.3/lib/rack/session/abstract/id.rb:266:in `context'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/rack-2.2.3/lib/rack/session/abstract/id.rb:260:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/middleware/cookies.rb:670:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/middleware/callbacks.rb:28:in `block in call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/callbacks.rb:98:in `run_callbacks'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/middleware/callbacks.rb:26:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/middleware/debug_exceptions.rb:61:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/middleware/show_exceptions.rb:33:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/railties-5.2.4.4/lib/rails/rack/logger.rb:38:in `call_app'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/railties-5.2.4.4/lib/rails/rack/logger.rb:26:in `block in call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/tagged_logging.rb:71:in `block in tagged'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/tagged_logging.rb:28:in `tagged'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/tagged_logging.rb:71:in `tagged'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/railties-5.2.4.4/lib/rails/rack/logger.rb:26:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/middleware/remote_ip.rb:81:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/middleware/request_id.rb:27:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/rack-2.2.3/lib/rack/method_override.rb:24:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/rack-2.2.3/lib/rack/runtime.rb:22:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/middleware/executor.rb:14:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/middleware/static.rb:127:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/rack-2.2.3/lib/rack/sendfile.rb:110:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/railties-5.2.4.4/lib/rails/engine.rb:524:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/puma-3.12.6/lib/puma/configuration.rb:227:in `call'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/puma-3.12.6/lib/puma/server.rb:706:in `handle_request'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/puma-3.12.6/lib/puma/server.rb:476:in `process_client'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/puma-3.12.6/lib/puma/server.rb:334:in `block in run'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/puma-3.12.6/lib/puma/thread_pool.rb:135:in `block in spawn_thread'
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/logging-2.2.2/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'
E, [2021-01-15T09:11:55.889644 #20729-70046885162700] ERROR -- : Error ID 2HBLHXIs: undefined method `downcase' for [""]:Array
I, [2021-01-15T09:11:55.895122 #20729-70046885162700]  INFO -- : Completed 500 Internal Server Error in 50ms (Views: 0.1ms | ActiveRecord: 11.7ms)

Steps to reproduce the behavior:

  • Call, pick up, talk a bit, hang up and check the https-log

Roundup

Our error seems to be with undefined method `downcase’ for [""]:Array (NoMethodError), do you know what’s up with that and how we can fix this?

Thanks and best regards,
Frederik

We also use a netphone and I had similar problems. I assume you are using the one call routing script someone posted a while back for the cti integration? We had to modify this script a bit to work as expected. You can see in your screenshot that one problem is the last bit of the event “answeringNumber=49” which is probably the extension of the agent. Your agents probably have their full phone number +49…+ Extension in their userprofile so Zammad doesn’t know who “49” is. We simply solved this by adding the full number to the answeringNumber parameter. This way you don’t need a notify-map at all.
Additionally we added that when the number of the caller is only 3 digits we also add the full number to it so internal callers can be identified correctly as well, you would have to change this to 2 if you use 2 digit extensions.
With these simple changes the script works perfectly for us with the generic CTI integration offered in Zammad.
Here is our script:

Function URLescape ( sURL )
	URLescape = sURL
	URLescape = Replace(URLescape ,"-","%2D")
	URLescape = Replace(URLescape ,"'","%27")
	URLescape = Replace(URLescape ,"""","%22")
End Function

Function SendData ( DataToSend )
	On Error Resume Next
 	Dim xml
	Set xml = PBXScript.CreateObject("Microsoft.XMLHTTP")
	PBXScript.OutputTrace "Call for Zammad: "	
	xml.Open "POST", "YOUR ZAMMAD CTI API URL HERE", False
	xml.setRequestHeader "Content-Type", "application/x-www-form-urlencoded"
	xml.send DataToSend
	xml.Send
	Set xml = Nothing 
End Function
	
Sub NewCall
  	Dim DataToSend 
	If Len(PBXCall.CallingPartyNumber) = 3 Then
		PBXCall.CallingPartyNumber = "+49YOURNUMBERHERE" + PBXCall.CallingPartyNumber
	End If
	DataToSend = "event=newCall&from=" & PBXCall.CallingPartyNumber & "&to=" & PBXCall.DialedNumber & "&direction=in&callId=" & PBXCall.CallId & "&user[]="
	SendData DataToSend
End Sub

Sub CallAnswer
  	Dim DataToSend
	If Len(PBXCall.CallingPartyNumber) = 3 Then
		PBXCall.CallingPartyNumber = "+49YOURNUMBERHERE" + PBXCall.CallingPartyNumber
	End If
	DataToSend = "event=answer&from=" & PBXCall.CallingPartyNumber & "&to=" & PBXCall.DialedNumber & "&direction=in&callId=" & PBXCall.CallId & "&user[]=" & PBXCall.ConnectedName & "&answeringNumber=+49YOURNUMBERHERE" & PBXCall.ConnectedNumber
	SendData DataToSend
End Sub

Sub CloseCall
  	Dim DataToSend
	If Len(PBXCall.CallingPartyNumber) = 3 Then
		PBXCall.CallingPartyNumber = "+49YOURNUMBERHERE" + PBXCall.CallingPartyNumber
	End If
	DataToSend = "event=hangup&cause=normalClearing&from=" & PBXCall.CallingPartyNumber & "&to=" & PBXCall.DialedNumber & "&direction=in&callId=" & PBXCall.CallId & "&user[]=" & PBXCall.ConnectedName & "&answeringNumber=+49YOURNUMBERHERE" & PBXCall.ConnectedNumber
	SendData DataToSend
End Sub

Hi Awedor,

thanks so much for your script!

We now got further and already had a new ticket open when a call is incoming, but one thing still isn’t working:
Does the agent who answered the call get matched with the Zammad user?
The “FROM” get’s matched all the time, but the “TO” in the Zammad call log doesn’t get matched - it just shows the number and name given from the NetPhone. Even if I ‘hardcode’ a number Zammad just shows the blank number without a name or matching to the Zammad user who has this exact number.

Thanks and best regards,
Frederik

My only guess is that the numbers don’t really match with the phone number of an agent or you still have a notify map active that breaks things. I use the generic CTI with the script I posted above and made sure the user profiles of my agents contain the phone number in the same format (+49…). If you are sure everything matches maybe you just need a zammad restart.

Oh I just noticed in your screenshot that nobody answered the call. You only see the name of the agent that answered the call in the log, and only this agent gets the new ticket screen for the customer that called.

I was also testing when answering the call, but it only shows the display name of the netphone somehow - not the one from zammad.

Also, in the CallAswer function the netphone sends the PBXCall.ConnectedName to zammad which then gets displayed.

DataToSend = "event=answer&from=" & PBXCall.CallingPartyNumber & "&to=" & PBXCall.DialedNumber & "&direction=in&callId=" & PBXCall.CallId & "&user[]=" & PBXCall.ConnectedName & "&answeringNumber=+49YOURNUMBERHERE" & PBXCall.ConnectedNumber

Does the agents who pick up the call really get matched with their zammad users? Do you also use a dummy-user in netphone which redirecty the call to the call-group in which the agents are?

You did replace this with your number right? Did you check in the logged cti events that the transmitted number of the person that picked up is correct?

This is because it couldn’t find a matching number. If a match is found this is not displayed but instead the Zammad user. You could leave this out completely once it works for you.

Yes, if the numbers are matching it just works automatically.

Yes we have a dummy user for the hotline number and on this user the call routing script contains the zammad script parts and the routing to the groups.

Hey awedor,

yes, I did replace our number everywhere where it says ‘+49YOURNUMBERHERE’ in your script (5 entries).

I checked the logs, it seems to be correct:

It shows that +49xxxxxx141 answered the call. This number is set for the agent Maximilian as +49 xxxx xxxx-141 but it doesn’t get matched.

For me it seems that it should work, which confuses me… am I missing something?

Thanks for your help

You need configure the Notify Map
integration>cti

No you don’t. This is only necessary if you want to control who even sees the incoming call, if you don’t configure this then everybody sees the incoming call that has the CTI switch enabled. This is how I have it configured and it works perfectly for us.

@Frederik I don’t know why it’s not working for you, I told you everything that I have setup and it works for us. Did you try the zammad restart I recommended? Did the users maybe disable the CTI switch in the sidebar? If nothing helps you might need support from Zammad, I am just a user.

@YosefAdPro is correct. In order for Zammad to open a user dialogue or the new ticket dialogue (depending on the situation) you need the correct notify map mapping set.
The phone number provided on the agents user has nothing to do with that - this also qualifies for the name of the person picking up. That’s information we retreive from your telephony system.

@awedor is also correct, the agent will need to enable the phone switch for notifications.
Currently I’m unsure on the “open dialogue” functionality - that should work no matter how the button state is.

As for Error 500’s it’s hard to tell.
The production log might be able to help better.