-
Type:
Bug
-
Status: Closed
-
Priority:
Minor
-
Resolution: Commercial
-
Affects Version/s: 15.0.17
-
Fix Version/s: None
-
Component/s: REST Phone Apps (Commercial)
-
Labels:None
-
Bug Tracker:Customer Issue
-
ToDo:
-
Asterisk Version:18.5.0
-
Distro Version:15.0.17.47
-
Distro:FreePBX Distro
In the last couple of weeks the Call Log button on our D65 phones has stopped working with FreePBX. It simply sits on the "Loading call history from server..." screen for a minute or so before returning to the idle screen.
The phones are configured to run via EPM using DPMA and "Use DPMA Apps" is enabled in the Options tab of the template applied. All other DPMA apps on the phone (such as Voicemail, Contacts and Status) appear to function correctly, implying this is not simply a configuration issue on the server end. They are running fimrware version 2_9_14.
To diagnose further, I have enabled Debug level syslog on a D65 and reproduced the issue. The output (anonymised) is below:
Aug 16 18:27:44 d65.example.net xyz: KEY 40-[ ( ] 1
Aug 16 18:27:44 d65.example.net phone: *** State phone.idle, process event: fn.call_log
Aug 16 18:27:44 d65.example.net phone: VIEW EVENT: fn.call_log
Aug 16 18:27:44 d65.example.net phone: HomeScreen::process_event: fn.call_log
Aug 16 18:27:44 d65.example.net phone: REMAP EVENT fn.call_log
Aug 16 18:27:44 d65.example.net phone: dbus_hide_idle_apps()
Aug 16 18:27:45 d65.example.net phone: request guiClog slot:0 creds:$s body:Pbx
Aug 16 18:27:45 d65.example.net phone: request guiClog cURL https://voice.example.net:5443/dphoneApi.php/xml
Aug 16 18:27:45 d65.example.net core[782]: core dbus_callback()
Aug 16 18:27:45 d65.example.net core[782]: middleman: Middleman thread 3 handling curl_request com.digium.middleman.req
Aug 16 18:27:45 d65.example.net core[782]: middleman: Sending cURL request to https://voice.example.net:5443/dphoneApi.php/xml with body request=<request method="switchvox.users.callLogs.getList"><parameters><account_id>35</account_id><max_entries>50</max_entries></
Aug 16 18:27:45 d65.example.net phone: LogScreen::redraw()
Aug 16 18:27:45 d65.example.net phone: LogScreen::redraw()
Aug 16 18:27:45 d65.example.net phone: @@@ new state: phone.idle
Aug 16 18:27:45 d65.example.net xyz: freetype_createfont: using font timesz.ttf
Aug 16 18:27:45 d65.example.net phone: *** State phone.idle, process event: idle_hidden
Aug 16 18:27:45 d65.example.net phone: VIEW EVENT: idle_hidden
Aug 16 18:27:45 d65.example.net phone: LogScreen::process_event: idle_hidden
Aug 16 18:27:45 d65.example.net phone: HomeScreen::process_event: idle_hidden
Aug 16 18:27:45 d65.example.net phone: REMAP EVENT idle_hidden
Aug 16 18:27:45 d65.example.net phone: ==== State phone.idle, process event idle_hidden: no matching transition
Aug 16 18:27:45 d65.example.net phone: @@@ new state: phone.idle
Aug 16 18:27:45 d65.example.net phone: HOLD TIME 0.133607s
Aug 16 18:27:45 d65.example.net xyz: KEY 40-[ ( ] 0
Aug 16 18:27:45 d65.example.net watchcat[340]: dbus_message_handler(): for app ae, updated watchcat timer to 240
Aug 16 18:27:45 d65.example.net core[782]: core dbus_callback()
Aug 16 18:27:45 d65.example.net core[782]: middleman: Middleman thread 0 handling ae com.digium.watchcat.report
Aug 16 18:27:45 d65.example.net watchcat[340]: dbus_message_handler(): for app ehs, updated watchcat timer to 230
Aug 16 18:27:45 d65.example.net core[782]: middleman: Middleman thread 1 handling ehs com.digium.watchcat.report
Aug 16 18:27:45 d65.example.net core[782]: core dbus_callback()
Aug 16 18:27:45 d65.example.net core[782]: middleman: cURL status code https://voice.example.net:5443/dphoneApi.php/xml 401
Aug 16 18:27:45 d65.example.net core[782]: middleman: dbus_send_response() id:guiClog76B61AAB_0, type:cURL, out:(null), error:401
Aug 16 18:27:45 d65.example.net core[782]: Thread [0xb528b480] sending com.digium.middleman.resp.response onto the [1] queue
Aug 16 18:27:45 d65.example.net core[782]: parsing guiClog76B61AAB_0
Aug 16 18:27:45 d65.example.net phone: *** State phone.idle, process event: response.id.guiClog76B61AAB_0.ResponseType.cURL.InternalErrors.401
Aug 16 18:27:45 d65.example.net phone: VIEW EVENT: response.id.guiClog76B61AAB_0.ResponseType.cURL.InternalErrors.401
Aug 16 18:27:45 d65.example.net phone: LogScreen::process_event: response.id.guiClog76B61AAB_0.ResponseType.cURL.InternalErrors.401
Aug 16 18:27:45 d65.example.net phone: ERROR, load_call_logs could not load xml logFile:401
Aug 16 18:27:45 d65.example.net phone: load_call_logs 401 acct:1 In:0, Out:0, Miss:0, ???:0, Total:0
Aug 16 18:27:45 d65.example.net phone: @@@ new state: phone.idle
The configuration EPM automatically generates for call_log is below:
</appconfig>
<!--FREEI-2459 although we are not really using the api for the call log app yet. The other apps rely on this <appconfig> chunk -->
<appconfig id="call_log" use_pbx_credentials="1">
<account account_id="35" username="user" appserver="https://voice.example.net:5443/dphoneApi.php"/>
</appconfig>
The voicemail configuration generated, which operates correctly, is:
<appconfig id="voicemail" use_pbx_credentials="1">
<account account_id="35" username="user" appserver="https://voice.example.net:5443/dphoneApi.php"/>
<auto_start/>
</appconfig>
You can see that https://voice.example.net:5443/dphoneApi.php/xml generates a 401 (Unauthorised) error in response to the call log XML query sent to it. Given that the same call using the same credentials works for voicemail, I am unsure where the issue lies. Could it be that the firmware is not formatting the request in a way that the PHP script understands? Is there somewhere I have to authorise the phone to access the server-side call log? UCP has access for the same user account and can view call history.