FOP2 Community Forum

wcolling

We ran the test. For the first query we see:

Checking ODBC voicemail connection

END HANDLING AMI EVENT channel USER/4159672901, command vmaildetail, data INBOX!eyJJTkJ...
The full contents of INBOX are returned.

I then bounced mysqld and requested the voicemail.

Checking ODBC voicemail connection

DBD::ODBC::st execute failed: [unixODBC]Error while executing the query;
ERROR: failed to execute the MySQL query:
MySQL server has gone away (SQL-HV00L) at /tmp/par-root/cache-18b38fcffafe18b85ee9f07de91069f7509b888c/inc/lib/FOP2/voicemail.pm line 31.
Describe failed during DBI::st=HASH(0x10342248)->FETCH(NAME,0) at /tmp/par-root/cache-18b38fcffafe18b85ee9f07de91069f7509b888c/inc/lib/FOP2/voicemail.pm line 33.
Checking ODBC voicemail connection

Checking ODBC voicemail connection

END HANDLING AMI EVENT channel USER/4159672901, command vmaildetail, data INBOX!eyJJTkJPWCI6IFt7fV19, slot 0

END HANDLING AMI EVENT channel USER/4159672901, command vmaildetail, data Old!eyJPbGQiOiBbeyJtYWlsYm94dXNlciI6ICI0MTU5NjcyOTAxIiwibXNnbnVtIjogIjAiLCJmbGFnIjogIiIsImR1cmF0aW9uIjogIjkxIiwibWFjcm9jb250ZXh0IjogImV4dC1sb2NhbCIsImRpciI6ICIvdmFyL3Nwb29sL2FzdGVyaXNrL3ZvaWNlbWFpbC9kZWZhdWx0LzQxNTk2NzI5MDEvT2xkIiwiY2FsbGVyaWQiOiAiXCI0OTczODhcIiA8NDk3Mzg4PiIsIm1haWxib3hjb250ZXh0IjogImRlZmF1bHQiLCJvcmlndGltZSI6ICIxNDUyODkwNjUyICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICIsImNvbnRleHQiOiAibWFjcm8tdm0iLCJpZCI6ICI2MzQ5In0seyJtYWlsYm94dXNlciI6ICI0MTU5NjcyOTAxIiwibXNnbnVtIjogIjEiLCJmbGFnIjogIiIsImR1cmF0aW9uIjogIjk2IiwibWFjcm9jb250ZXh0IjogImV4dC1sb2NhbCIsImRpciI6ICIvdmFyL3Nwb29sL2FzdGVyaXNrL3ZvaWNlbWFpbC9kZWZhdWx0LzQxNTk2NzI5MDEvT2xkIiwiY2FsbGVyaWQiOiAiXCJUZXN0XCIgPDQ0NDQ0ND4iLCJtYWlsYm94Y29udGV4dCI6ICJkZWZhdWx0Iiwib3JpZ3RpbWUiOiAiMTQ2NjQ1MDE5OCAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAiLCJjb250ZXh0IjogIm1hY3JvLXZtIiwiaWQiOiAiNjM3MiJ9XX0=, slot 0

Here an empty array was returned for INBOX.

If I understand this correctly, the query for inbox is issued and there is a problem with the connection, the FOP2 server recovers the connection, fails to reattempt the read for INBOX and continues on with the Old folder.

wcolling

Thanks for the information. I can now reproduce the problem by the following:

Log into the FOP2 interface.
Bounce mysql (service mysqld restart)
Request voicemail by clicking on the envelope icon on the extension button.

I turned on the general log for mysql to see if I could see the problem. Here is what I saw:

In the normal case where all voicemails are returned, the fop2 server issues a query for each voicemail folder and for each msgnum returned another query is issued for the voicemail details.

Example:

Query for INBOX msgnum:
SELECT msgnum FROM voicemail.voicemessages WHERE ((dir LIKE BINARY '%INBOX')) AND ((mailboxuser = '4159672901')) AND ((mailboxcontext = 'default'))

Query for each msgnum in INBOX:
SELECT id, msgnum, dir, context, macrocontext, callerid, origtime, duration, mailboxuser, mailboxcontext, flag FROM voicemail.voicemessages WHERE ((dir LIKE BINARY '%INBOX')) AND ((mailboxuser = '4159672901')) AND ((mailboxcontext = 'default')) AND ((msgnum = 12))

The query for msgnum is done for the INBOX, Old, Work, Family, and Friends folders.

After I restart mysqld, for the first voicemail request only, the fop2 server only queries for the Old, Work, Family, and Friends folders. For some reason, it does not query for INBOX. This then explains why the INBOX voicemails are missing in the response.

I am not clear how the fop2 server knows which voicemail folders should be returned. Can you give us a little information on what happens here?

wcolling

We are having a problem where occasionally voicemail is not being returned for a user. I was able to see it this morning and capture the server log.

For the first request, the client requested the voicemail and the server responded with an empty array for the inbox, two voicemails for the old folder, and empty arrays for the other folders. Every thing was correct except the inbox which should return 26 voicemails.

I then requested the voicemail again and this time the server responded with the correct number of voicemails in each folder.

Can you explain how the fop2 server retrieves the voicemails so we can investigate our system to see if there is something wrong on our end?

Here is the first request:
2016-08-05 05:28:09,553 INFO - 23.240.58.26:64073 <= <msg data="6|getvmail|INBOX|cdd24e08a0c52a2bb18e977f5c1b3df0" />
and the response:
2016-08-05 05:28:09,553 INFO - ++ GET SERVER for USER/4159672901 = 127.0.0.1
2016-08-05 05:28:09,553 INFO -
2016-08-05 05:28:09,553 INFO - 127.0.0.1 -> Action: UserEvent
2016-08-05 05:28:09,553 INFO - 127.0.0.1 -> UserEvent: FOP2VMAIL
2016-08-05 05:28:09,553 INFO - 127.0.0.1 -> Channel: USER/4159672901
2016-08-05 05:28:09,553 INFO - 127.0.0.1 -> Mailbox: 4159672901@default
2016-08-05 05:28:09,553 INFO -
2016-08-05 05:28:09,553 INFO - 127.0.0.1 <- Response: Success
2016-08-05 05:28:09,553 INFO - 127.0.0.1 <- Message: Event Sent
2016-08-05 05:28:09,553 INFO -
2016-08-05 05:28:09,553 INFO - 127.0.0.1 <- Event: UserEvent
2016-08-05 05:28:09,553 INFO - 127.0.0.1 <- Privilege: user,all
2016-08-05 05:28:09,553 INFO - 127.0.0.1 <- UserEvent: FOP2VMAIL
2016-08-05 05:28:09,553 INFO - 127.0.0.1 <- Action: UserEvent
2016-08-05 05:28:09,553 INFO - 127.0.0.1 <- Channel: USER/4159672901
2016-08-05 05:28:09,553 INFO - 127.0.0.1 <- Mailbox: 4159672901@default
2016-08-05 05:28:09,553 INFO - Executing AMI Event Handler in plugin hcpeerstatus for event USEREVENT
2016-08-05 05:28:09,553 INFO -
2016-08-05 05:28:09,553 INFO - Checking ODBC voicemail connection
2016-08-05 05:28:09,553 INFO -
2016-08-05 05:28:09,553 INFO - Checking ODBC voicemail connection
2016-08-05 05:28:09,553 INFO -
2016-08-05 05:28:09,553 INFO - Checking ODBC voicemail connection
2016-08-05 05:28:09,553 INFO -
2016-08-05 05:28:09,553 INFO - Checking ODBC voicemail connection
2016-08-05 05:28:09,553 INFO -
2016-08-05 05:28:09,553 INFO - Checking ODBC voicemail connection
2016-08-05 05:28:09,553 INFO -
2016-08-05 05:28:09,553 INFO - ** CALLING QUERY UNPOPULATED MAILBOX on FOP2::AMI2=HASH(0x11289ea8)
2016-08-05 05:28:09,553 INFO -
2016-08-05 05:28:09,553 INFO - END HANDLING AMI EVENT channel USER/4159672901, command vmaildetail, data INBOX!eyJJTkJPWCI6IFt7fV19, slot 0
2016-08-05 05:28:09,553 INFO -
2016-08-05 05:28:09,553 INFO - END HANDLING AMI EVENT channel USER/4159672901, command vmaildetail, data Old!eyJPbGQiOiBbeyJtYWlsYm94dXNlciI6ICI0MTU5NjcyOTAxIiwibXNnbnVtIjogIjAiLCJmbGFnIjogIiIsImR1cmF0aW9uIjogIjkxIiwibWFjcm9jb250ZXh0IjogImV4dC1sb2NhbCIsImRpciI6ICIvdmFyL3Nwb29sL2FzdGVyaXNrL3ZvaWNlbWFpbC9kZWZhdWx0LzQxNTk2NzI5MDEvT2xkIiwiY2FsbGVyaWQiOiAiXCI0OTczODhcIiA8NDk3Mzg4PiIsIm1haWxib3hjb250ZXh0IjogImRlZmF1bHQiLCJvcmlndGltZSI6ICIxNDUyODkwNjUyICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICIsImNvbnRleHQiOiAibWFjcm8tdm0iLCJpZCI6ICI2MzQ5In0seyJtYWlsYm94dXNlciI6ICI0MTU5NjcyOTAxIiwibXNnbnVtIjogIjEiLCJmbGFnIjogIiIsImR1cmF0aW9uIjogIjk2IiwibWFjcm9jb250ZXh0IjogImV4dC1sb2NhbCIsImRpciI6ICIvdmFyL3Nwb29sL2FzdGVyaXNrL3ZvaWNlbWFpbC9kZWZhdWx0LzQxNTk2NzI5MDEvT2xkIiwiY2FsbGVyaWQiOiAiXCJUZXN0XCIgPDQ0NDQ0ND4iLCJtYWlsYm94Y29udGV4dCI6ICJkZWZhdWx0Iiwib3JpZ3RpbWUiOiAiMTQ2NjQ1MDE5OCAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAiLCJjb250ZXh0IjogIm1hY3JvLXZtIiwiaWQiOiAiNjM3MiJ9XX0=, slot 0
2016-08-05 05:28:09,553 INFO -
2016-08-05 05:28:09,602 INFO - END HANDLING AMI EVENT channel USER/4159672901, command vmaildetail, data Work!eyJXb3JrIjogW3t9XX0=, slot 0
2016-08-05 05:28:09,602 INFO -
2016-08-05 05:28:09,602 INFO - END HANDLING AMI EVENT channel USER/4159672901, command vmaildetail, data Family!eyJGYW1pbHkiOiBbe31dfQ==, slot 0
2016-08-05 05:28:09,602 INFO -
2016-08-05 05:28:09,602 INFO - END HANDLING AMI EVENT channel USER/4159672901, command vmaildetail, data Friends!eyJGcmllbmRzIjogW3t9XX0=, slot 0

and here is the second request and response:

2016-08-05 05:38:06,723 INFO - 23.240.58.26:64073 <= <msg data="6|getvmail|INBOX|cdd24e08a0c52a2bb18e977f5c1b3df0" />
2016-08-05 05:38:06,723 INFO -
2016-08-05 05:38:06,723 INFO - -- PROCESS_FLASH_COMMAND origen 6 accion getvmail destino INBOX password cdd24e08a0c52a2bb18e977f5c1b3df0
2016-08-05 05:38:06,723 INFO -
2016-08-05 05:38:06,723 INFO - ++ GET SERVER for USER/4159672901 = 127.0.0.1
2016-08-05 05:38:06,723 INFO -
2016-08-05 05:38:06,723 INFO - 127.0.0.1 -> Action: UserEvent
2016-08-05 05:38:06,723 INFO - 127.0.0.1 -> UserEvent: FOP2VMAIL
2016-08-05 05:38:06,723 INFO - 127.0.0.1 -> Channel: USER/4159672901
2016-08-05 05:38:06,723 INFO - 127.0.0.1 -> Mailbox: 4159672901@default
2016-08-05 05:38:06,723 INFO -
2016-08-05 05:38:06,723 INFO - 127.0.0.1 <- Response: Success
2016-08-05 05:38:06,723 INFO - 127.0.0.1 <- Message: Event Sent
2016-08-05 05:38:06,723 INFO -
2016-08-05 05:38:06,723 INFO - 127.0.0.1 <- Event: UserEvent
2016-08-05 05:38:06,723 INFO - 127.0.0.1 <- Privilege: user,all
2016-08-05 05:38:06,723 INFO - 127.0.0.1 <- UserEvent: FOP2VMAIL
2016-08-05 05:38:07,407 INFO - 127.0.0.1 <- Action: UserEvent
2016-08-05 05:38:07,407 INFO - 127.0.0.1 <- Channel: USER/4159672901
2016-08-05 05:38:07,407 INFO - 127.0.0.1 <- Mailbox: 4159672901@default
2016-08-05 05:38:07,407 INFO -
2016-08-05 05:38:07,407 INFO - Executing AMI Event Handler in plugin hcpeerstatus for event USEREVENT
2016-08-05 05:38:07,407 INFO -
2016-08-05 05:38:07,407 INFO - Checking ODBC voicemail connection
2016-08-05 05:38:07,407 INFO -
2016-08-05 05:38:07,407 INFO - Checking ODBC voicemail connection
2016-08-05 05:38:07,407 INFO -
2016-08-05 05:38:07,407 INFO - Checking ODBC voicemail connection
2016-08-05 05:38:07,407 INFO -
2016-08-05 05:38:07,407 INFO - Checking ODBC voicemail connection
2016-08-05 05:38:07,407 INFO -
2016-08-05 05:38:07,407 INFO - Checking ODBC voicemail connection
2016-08-05 05:38:07,407 INFO -
2016-08-05 05:38:07,407 INFO - ** CALLING QUERY UNPOPULATED MAILBOX on FOP2::AMI2=HASH(0x11289ea8)

2016-08-05 05:38:07,407 INFO -
2016-08-05 05:38:07,407 INFO - END HANDLING AMI EVENT channel USER/4159672901, command vmaildetail, data INBOX!eyJJTkJPWCI6IFt7Im1haWxib3h1c2VyIjogIjQxNTk2NzI5MDEiLCJtc2dudW0iOiAiMTIiLCJmbGFnIjogIiIsImR1cmF0aW9uIjogIjExIiwibWFjcm9jb250ZXh0IjogImV4dC1sb2NhbCIsImRpciI6ICIvdmFyL3Nwb29sL2FzdGVyaXNrL3ZvaWNlbWFpbC9kZWZhdWx0LzQxNTk2NzI5MDEvSU5CT1giLCJjYWxsZXJpZCI6ICJcIkNPTExJTkcgV0lMTElBTVwiIDwrMTk1MTk0MTQ4NzY+IiwibWFpbGJveGNvbnRleHQiOiAiZGVmYXVsdCIsIm9yaWd0aW1lIjogIjE0Njk5MDMwMzYgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgIiwiY29udGV4dCI6ICJtYWNyby12bSIsImlkIjogIjYzODgifSx7Im1haWxib3h1c2VyIjogIjQxNTk2NzI5MDEiLCJtc2dudW0iOiAiMTMiLCJmbGFnIjogIiIsImR1cmF0aW9uIjogIjExIiwibWFjcm9jb250ZXh0IjogImV4dC1sb2NhbCIsImRpciI6ICIvdmFyL3Nwb29sL2FzdGVyaXNrL3ZvaWNlbWFpbC9kZWZhdWx0LzQxNTk2NzI5MDEvSU5CT1giLCJjYWxsZXJpZCI6ICJcIkNPTExJTkcgV0lMTElBTVwiIDwrMTk1MTk0MTQ4NzY+IiwibWFpbGJveGNvbnRleHQiOiAiZGVmYXVsdCIsIm9yaWd0aW1lIjogIjE0Njk5MDMwNzEgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgIiwiY29udGV4dCI6ICJtYWNyby12bSIsImlkIjogIjYzODkifSx7Im1haWxib3h1c2VyIjogIjQxNTk2NzI5MDEiLCJtc2dudW0iOiAiMTQiLCJmbGFnIjogIiIsImR1cmF0aW9uIjogIjExIiwibWFjcm9jb250ZXh0IjogImV4dC1sb2NhbCIsImRpciI6ICIvdmFyL3Nwb29sL2FzdGVyaXNrL3ZvaWNlbWFpbC9kZWZhdWx0LzQxNTk2NzI5MDEvSU5CT1giLCJjYWxsZXJpZCI6ICJcIkNPTExJTkcgV0lMTElBTVwiIDwrMTk1MTk0MTQ4NzY+IiwibWFpbGJveGNvbnRleHQiOiAiZGVmYXVsdCIsIm9yaWd0aW1lIjogIjE0Njk5MDMxMDcgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgIiwiY29udGV4dCI6ICJtYWNyby12bSIsImlkIjogIjYzOTAifSx7Im1haWxib3h1c2VyIjogIjQxNTk2NzI5MDEiLCJtc2dudW0iOiAiMCIsImZsYWciOiAiIiwiZHVyYXRpb24iOiAiMTEiLCJtYWNyb2NvbnRleHQiOiAiZXh0LWxvY2FsIiwiZGlyIjogIi92YXIvc3Bvb2wvYXN0ZXJpc2svdm9pY2VtYWlsL2RlZmF1bHQvNDE1OTY3MjkwMS9JTkJPWCIsImNhbGxlcmlkIjogIlwiQ09MTElORyxXSUxMSUFNXCIgPDk1MTc4MDc3MzY+IiwibWFpbGJveGNvbnRleHQiOiAiZGVmYXVsdCIsIm9yaWd0aW1lIjogIjE0Njk4MDIxMzggICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgIiwiY29udGV4dCI6ICJtYWNyby12bSIsImlkIjogIjYzNzYifSx7Im1haWxib3h1c2VyIjogIjQxNTk2NzI5MDEiLCJtc2dudW0iOiAiMSIsImZsYWciOiAiIiwiZHVyYXRpb24iOiAiOCIsIm1hY3JvY29udGV4dCI6ICJleHQtbG9jYWwiLCJkaXIiOiAiL3Zhci9zcG9vbC9hc3Rlcmlzay92b2ljZW1haWwvZGVmYXVsdC80MTU5NjcyOTAxL0lOQk9YIiwiY2FsbGVyaWQiOiAiXCJDT0xMSU5HLFdJTExJQU1cIiA8OTUxNzgwNzczNj4iLCJtYWlsYm94Y29udGV4dCI6ICJkZWZhdWx0Iiwib3JpZ3RpbWUiOiAiMTQ2OTgwMjE5MCAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAiLCJjb250ZXh0IjogIm1hY3JvLXZtIiwiaWQiOiAiNjM3NyJ9LHsibWFpbGJveHVzZXIiOiAiNDE1OTY3MjkwMSIsIm1zZ251bSI6ICIyIiwiZmxhZyI6ICIiLCJkdXJhdGlvbiI6ICI5IiwibWFjcm9jb250ZXh0IjogImV4dC1sb2NhbCIsImRpciI6ICIvdmFyL3Nwb29sL2FzdGVyaXNrL3ZvaWNlbWFpbC9kZWZhdWx0LzQxNTk2NzI5MDEvSU5CT1giLCJjYWxsZXJpZCI6ICJcIkNPTExJTkcsV0lMTElBTVwiIDw5NTE3ODA3NzM2PiIsIm1haWxib3hjb250ZXh0IjogImRlZmF1bHQiLCJvcmlndGltZSI6ICIxNDY5ODAzMjg2ICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICIsImNvbnRleHQiOiAibWFjcm8tdm0iLCJpZCI6ICI2Mzc4In0seyJtYWlsYm94dXNlciI6ICI0MTU5NjcyOTAxIiwibXNnbnVtIjogIjMiLCJmbGFnIjogIiIsImR1cmF0aW9uIjogIjEwIiwibWFjcm9jb250ZXh0IjogImV4dC1sb2NhbCIsImRpciI6ICIvdmFyL3Nwb29sL2FzdGVyaXNrL3ZvaWNlbWFpbC9kZWZhdWx0LzQxNTk2NzI5MDEvSU5CT1giLCJjYWxsZXJpZCI6ICJcIkNPTExJTkcsV0lMTElBTVwiIDw5NTE3ODA3NzM2PiIsIm1haWxib3hjb250ZXh0IjogImRlZmF1bHQiLCJvcmlndGltZSI6ICIxNDY5ODAzMzE3ICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICIsImNvbnRleHQiOiAibWFjcm8tdm0iLCJpZCI6ICI2Mzc5In0seyJtYWlsYm94dXNlciI6ICI0MTU5NjcyOTAxIiwibXNnbnVtIjogIjQiLCJmbGFnIjogIiIsImR1cmF0aW9uIjogIjgiLCJtYWNyb2NvbnRleHQiOiAiZXh0LWxvY2FsIiwiZGlyIjogIi92YXIvc3Bvb2wvYXN0ZXJpc2svdm9pY2VtYWlsL2RlZmF1bHQvNDE1OTY3MjkwMS9JTkJPWCIsImNhbGxlcmlkIjogIlwiQ09MTElORyxXSUxMSUFNXCIgPDk1MTc4MDc3MzY+IiwibWFpbGJveGNvbnRleHQiOiAiZGVmYXVsdCIsIm9yaWd0aW1lIjogIjE0Njk4MDMzNDggICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgIiwiY29udGV4dCI6ICJtYWNyby12bSIsImlkIjogIjYzODAifSx7Im1haWxib3h1c2VyIjogIjQxNTk2NzI5MDEiLCJtc2dudW0iOiAiNSIsImZsYWciOiAiIiwiZHVyYXRpb24iOiAiOSIsIm1hY3JvY29udGV4dCI6ICJleHQtbG9jYWwiLCJkaXIiOiAiL3Zhci9zcG9vbC9hc3Rlcmlzay92b2ljZW1haWwvZGVmYXVsdC80MTU5NjcyOTAxL0lOQk9YIiwiY2FsbGVyaWQiOiAiXCJDT0xMSU5HLFdJTExJQU1cIiA8OTUxNzgwNzczNj4iLCJtYWlsYm94Y29udGV4dCI6ICJkZWZhdWx0Iiwib3JpZ3RpbWUiOiAiMTQ2OTgwMzM3OSAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAiLCJjb250ZXh0IjogIm1hY3JvLXZtIiwiaWQiOiAiNjM4MSJ9LHsibWFpbGJveHVzZXIiOiAiNDE1OTY3MjkwMSIsIm1zZ251bSI6ICI2IiwiZmxhZyI6ICIiLCJkdXJhdGlvbiI6ICIxMyIsIm1hY3JvY29udGV4dCI6ICJleHQtbG9jYWwiLCJkaXIiOiAiL3Zhci9zcG9vbC9hc3Rlcmlzay92b2ljZW1haWwvZGVmYXVsdC80MTU5NjcyOTAxL0lOQk9YIiwiY2FsbGVyaWQiOiAiXCJDT0xMSU5HLFdJTExJQU1cIiA8OTUxNzgwNzczNj4iLCJtYWlsYm94Y29udGV4dCI6ICJkZWZhdWx0Iiwib3JpZ3RpbWUiOiAiMTQ2OTgwMzQwOCAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAiLCJjb250ZXh0IjogIm1hY3JvLXZtIiwiaWQiOiAiNjM4MiJ9LHsibWFpbGJveHVzZXIiOiAiNDE1OTY3MjkwMSIsIm1zZ251bSI6ICI3IiwiZmxhZyI6ICIiLCJkdXJhdGlvbiI6ICI4IiwibWFjcm9jb250ZXh0IjogImV4dC1sb2NhbCIsImRpciI6ICIvdmFyL3Nwb29sL2FzdGVyaXNrL3ZvaWNlbWFpbC9kZWZhdWx0LzQxNTk2NzI5MDEvSU5CT1giLCJjYWxsZXJpZCI6ICJcIkNPTExJTkcsV0lMTElBTVwiIDw5NTE3ODA3NzM2PiIsIm1haWxib3hjb250ZXh0IjogImRlZmF1bHQiLCJvcmlndGltZSI6ICIxNDY5ODAzNDQxICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICIsImNvbnRleHQiOiAibWFjcm8tdm0iLCJpZCI6ICI2MzgzIn0seyJtYWlsYm94dXNlciI6ICI0MTU5NjcyOTAxIiwibXNnbnVtIjogIjgiLCJmbGFnIjogIiIsImR1cmF0aW9uIjogIjkiLCJtYWNyb2NvbnRleHQiOiAiZXh0LWxvY2FsIiwiZGlyIjogIi92YXIvc3Bvb2wvYXN0ZXJpc2svdm9pY2VtYWlsL2RlZmF1bHQvNDE1OTY3MjkwMS9JTkJPWCIsImNhbGxlcmlkIjogIlwiQ09MTElORyxXSUxMSUFNXCIgPDk1MTc4MDc3MzY+IiwibWFpbGJveGNvbnRleHQiOiAiZGVmYXVsdCIsIm9yaWd0aW1lIjogIjE0Njk4MDM0NzAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgIiwiY29udGV4dCI6ICJtYWNyby12bSIsImlkIjogIjYzODQifSx7Im1haWxib3h1c2VyIjogIjQxNTk2NzI5MDEiLCJtc2dudW0iOiAiOSIsImZsYWciOiAiIiwiZHVyYXRpb24iOiAiMTEiLCJtYWNyb2NvbnRleHQiOiAiZXh0LWxvY2FsIiwiZGlyIjogIi92YXIvc3Bvb2wvYXN0ZXJpc2svdm9pY2VtYWlsL2RlZmF1bHQvNDE1OTY3MjkwMS9JTkJPWCIsImNhbGxlcmlkIjogIlwiQ09MTElORyxXSUxMSUFNXCIgPDk1MTc4MDc3MzY+IiwibWFpbGJveGNvbnRleHQiOiAiZGVmYXVsdCIsIm9yaWd0aW1lIjogIjE0Njk4MDM0OTggICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgIiwiY29udGV4dCI6ICJtYWNyby12bSIsImlkIjogIjYzODUifSx7Im1haWxib3h1c2VyIjogIjQxNTk2NzI5MDEiLCJtc2dudW0iOiAiMTAiLCJmbGFnIjogIiIsImR1cmF0aW9uIjogIjE3IiwibWFjcm9jb250ZXh0IjogImV4dC1sb2NhbCIsImRpciI6ICIvdmFyL3Nwb29sL2FzdGVyaXNrL3ZvaWNlbWFpbC9kZWZhdWx0LzQxNTk2NzI5MDEvSU5CT1giLCJjYWxsZXJpZCI6ICJcIkNPTExJTkcsV0lMTElBTVwiIDw5NTE3ODA3NzM2PiIsIm1haWxib3hjb250ZXh0IjogImRlZmF1bHQiLCJvcmlndGltZSI6ICIxNDY5ODAzNTM1ICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICIsImNvbnRleHQiOiAibWFjcm8tdm0iLCJpZCI6ICI2Mzg2In0seyJtYWlsYm94dXNlciI6ICI0MTU5NjcyOTAxIiwibXNnbnVtIjogIjExIiwiZmxhZyI6ICIiLCJkdXJhdGlvbiI6ICIxNCIsIm1hY3JvY29udGV4dCI6ICJleHQtbG9jYWwiLCJkaXIiOiAiL3Zhci9zcG9vbC9hc3Rlcmlzay92b2ljZW1haWwvZGVmYXVsdC80MTU5NjcyOTAxL0lOQk9YIiwiY2FsbGVyaWQiOiAiXCJDT0xMSU5HIFdJTExJQU1cIiA8KzE5NTE5NDE0ODc2PiIsIm1haWxib3hjb250ZXh0IjogImRlZmF1bHQiLCJvcmlndGltZSI6ICIxNDY5OTAyOTg4ICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICIsImNvbnRleHQiOiAibWFjcm8tdm0iLCJpZCI6ICI2Mzg3In0seyJtYWlsYm94dXNlciI6ICI0MTU5NjcyOTAxIiwibXNnbnVtIjogIjE1IiwiZmxhZyI6ICIiLCJkdXJhdGlvbiI6ICIxMyIsIm1hY3JvY29udGV4dCI6ICJleHQtbG9jYWwiLCJkaXIiOiAiL3Zhci9zcG9vbC9hc3Rlcmlzay92b2ljZW1haWwvZGVmYXVsdC80MTU5NjcyOTAxL0lOQk9YIiwiY2FsbGVyaWQiOiAiXCJDT0xMSU5HIFdJTExJQU1cIiA8KzE5NTE5NDE0ODc2PiIsIm1haWxib3hjb250ZXh0IjogImRlZmF1bHQiLCJvcmlndGltZSI6ICIxNDY5OTAzMTQ1ICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICIsImNvbnRleHQiOiAibWFjcm8tdm0iLCJpZCI6ICI2MzkxIn0seyJtYWlsYm94dXNlciI6ICI0MTU5NjcyOTAxIiwibXNnbnVtIjogIjE2IiwiZmxhZyI6ICIiLCJkdXJhdGlvbiI6ICIxNCIsIm1hY3JvY29udGV4dCI6ICJleHQtbG9jYWwiLCJkaXIiOiAiL3Zhci9zcG9vbC9hc3Rlcmlzay92b2ljZW1haWwvZGVmYXVsdC80MTU5NjcyOTAxL0lOQk9YIiwiY2FsbGVyaWQiOiAiXCJDT0xMSU5HIFdJTExJQU1cIiA8KzE5NTE5NDE0ODc2PiIsIm1haWxib3hjb250ZXh0IjogImRlZmF1bHQiLCJvcmlndGltZSI6ICIxNDY5OTAzMTgzICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICIsImNvbnRleHQiOiAibWFjcm8tdm0iLCJpZCI6ICI2MzkyIn0seyJtYWlsYm94dXNlciI6ICI0MTU5NjcyOTAxIiwibXNnbnVtIjogIjE3IiwiZmxhZyI6ICIiLCJkdXJhdGlvbiI6ICIxMiIsIm1hY3JvY29udGV4dCI6ICJleHQtbG9jYWwiLCJkaXIiOiAiL3Zhci9zcG9vbC9hc3Rlcmlzay92b2ljZW1haWwvZGVmYXVsdC80MTU5NjcyOTAxL0lOQk9YIiwiY2FsbGVyaWQiOiAiXCJDT0xMSU5HIFdJTExJQU1cIiA8KzE5NTE5NDE0ODc2PiIsIm1haWxib3hjb250ZXh0IjogImRlZmF1bHQiLCJvcmlndGltZSI6ICIxNDY5OTAzMjU5ICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICIsImNvbnRleHQiOiAibWFjcm8tdm0iLCJpZCI6ICI2MzkzIn0seyJtYWlsYm94dXNlciI6ICI0MTU5NjcyOTAxIiwibXNnbnVtIjogIjE4IiwiZmxhZyI6ICIiLCJkdXJhdGlvbiI6ICIxMSIsIm1hY3JvY29udGV4dCI6ICJleHQtbG9jYWwiLCJkaXIiOiAiL3Zhci9zcG9vbC9hc3Rlcmlzay92b2ljZW1haWwvZGVmYXVsdC80MTU5NjcyOTAxL0lOQk9YIiwiY2FsbGVyaWQiOiAiXCJDT0xMSU5HLFdJTExJQU1cIiA8OTUxNzgwNzczNj4iLCJtYWlsYm94Y29udGV4dCI6ICJkZWZhdWx0Iiwib3JpZ3RpbWUiOiAiMTQ3MDA1NzM3MSAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAiLCJjb250ZXh0IjogIm1hY3JvLXZtIiwiaWQiOiAiNjM5NCJ9LHsibWFpbGJveHVzZXIiOiAiNDE1OTY3MjkwMSIsIm1zZ251bSI6ICIxOSIsImZsYWciOiAiIiwiZHVyYXRpb24iOiAiNyIsIm1hY3JvY29udGV4dCI6ICJleHQtbG9jYWwiLCJkaXIiOiAiL3Zhci9zcG9vbC9hc3Rlcmlzay92b2ljZW1haWwvZGVmYXVsdC80MTU5NjcyOTAxL0lOQk9YIiwiY2FsbGVyaWQiOiAiXCJDT0xMSU5HLFdJTExJQU1cIiA8OTUxNzgwNzczNj4iLCJtYWlsYm94Y29udGV4dCI6ICJkZWZhdWx0Iiwib3JpZ3RpbWUiOiAiMTQ3MDA1NzQwMyAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAiLCJjb250ZXh0IjogIm1hY3JvLXZtIiwiaWQiOiAiNjM5NSJ9LHsibWFpbGJveHVzZXIiOiAiNDE1OTY3MjkwMSIsIm1zZ251bSI6ICIyMCIsImZsYWciOiAiIiwiZHVyYXRpb24iOiAiNiIsIm1hY3JvY29udGV4dCI6ICJleHQtbG9jYWwiLCJkaXIiOiAiL3Zhci9zcG9vbC9hc3Rlcmlzay92b2ljZW1haWwvZGVmYXVsdC80MTU5NjcyOTAxL0lOQk9YIiwiY2FsbGVyaWQiOiAiXCJDT0xMSU5HLFdJTExJQU1cIiA8OTUxNzgwNzczNj4iLCJtYWlsYm94Y29udGV4dCI6ICJkZWZhdWx0Iiwib3JpZ3RpbWUiOiAiMTQ3MDA1NzQzMCAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAiLCJjb250ZXh0IjogIm1hY3JvLXZtIiwiaWQiOiAiNjM5NiJ9LHsibWFpbGJveHVzZXIiOiAiNDE1OTY3MjkwMSIsIm1zZ251bSI6ICIyMSIsImZsYWciOiAiIiwiZHVyYXRpb24iOiAiNiIsIm1hY3JvY29udGV4dCI6ICJleHQtbG9jYWwiLCJkaXIiOiAiL3Zhci9zcG9vbC9hc3Rlcmlzay92b2ljZW1haWwvZGVmYXVsdC80MTU5NjcyOTAxL0lOQk9YIiwiY2FsbGVyaWQiOiAiXCJDT0xMSU5HLFdJTExJQU1cIiA8OTUxNzgwNzczNj4iLCJtYWlsYm94Y29udGV4dCI6ICJkZWZhdWx0Iiwib3JpZ3RpbWUiOiAiMTQ3MDA1NzQ1OCAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAiLCJjb250ZXh0IjogIm1hY3JvLXZtIiwiaWQiOiAiNjM5NyJ9LHsibWFpbGJveHVzZXIiOiAiNDE1OTY3MjkwMSIsIm1zZ251bSI6ICIyMiIsImZsYWciOiAiIiwiZHVyYXRpb24iOiAiOSIsIm1hY3JvY29udGV4dCI6ICJleHQtbG9jYWwiLCJkaXIiOiAiL3Zhci9zcG9vbC9hc3Rlcmlzay92b2ljZW1haWwvZGVmYXVsdC80MTU5NjcyOTAxL0lOQk9YIiwiY2FsbGVyaWQiOiAiXCJDT0xMSU5HLFdJTExJQU1cIiA8OTUxNzgwNzczNj4iLCJtYWlsYm94Y29udGV4dCI6ICJkZWZhdWx0Iiwib3JpZ3RpbWUiOiAiMTQ3MDA1NzQ4NCAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAiLCJjb250ZXh0IjogIm1hY3JvLXZtIiwiaWQiOiAiNjM5OCJ9LHsibWFpbGJveHVzZXIiOiAiNDE1OTY3MjkwMSIsIm1zZ251bSI6ICIyMyIsImZsYWciOiAiIiwiZHVyYXRpb24iOiAiMTAiLCJtYWNyb2NvbnRleHQiOiAiZXh0LWxvY2FsIiwiZGlyIjogIi92YXIvc3Bvb2wvYXN0ZXJpc2svdm9pY2VtYWlsL2RlZmF1bHQvNDE1OTY3MjkwMS9JTkJPWCIsImNhbGxlcmlkIjogIlwiQ09MTElORyxXSUxMSUFNXCIgPDk1MTc4MDc3MzY+IiwibWFpbGJveGNvbnRleHQiOiAiZGVmYXVsdCIsIm9yaWd0aW1lIjogIjE0NzAwNTc1MTMgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgIiwiY29udGV4dCI6ICJtYWNyby12bSIsImlkIjogIjYzOTkifSx7Im1haWxib3h1c2VyIjogIjQxNTk2NzI5MDEiLCJtc2dudW0iOiAiMjQiLCJmbGFnIjogIiIsImR1cmF0aW9uIjogIjUiLCJtYWNyb2NvbnRleHQiOiAiZXh0LWxvY2FsIiwiZGlyIjogIi92YXIvc3Bvb2wvYXN0ZXJpc2svdm9pY2VtYWlsL2RlZmF1bHQvNDE1OTY3MjkwMS9JTkJPWCIsImNhbGxlcmlkIjogIlwiQ09MTElORyxXSUxMSUFNXCIgPDk1MTc4MDc3MzY+IiwibWFpbGJveGNvbnRleHQiOiAiZGVmYXVsdCIsIm9yaWd0aW1lIjogIjE0NzAwNTc1NDYgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgIiwiY29udGV4dCI6ICJtYWNyby12bSIsImlkIjogIjY0MDAifSx7Im1haWxib3h1c2VyIjogIjQxNTk2NzI5MDEiLCJtc2dudW0iOiAiMjUiLCJmbGFnIjogIiIsImR1cmF0aW9uIjogIjkiLCJtYWNyb2NvbnRleHQiOiAiZXh0LWxvY2FsIiwiZGlyIjogIi92YXIvc3Bvb2wvYXN0ZXJpc2svdm9pY2VtYWlsL2RlZmF1bHQvNDE1OTY3MjkwMS9JTkJPWCIsImNhbGxlcmlkIjogIlwiQ09MTElORyxXSUxMSUFNXCIgPDk1MTc4MDc3MzY+IiwibWFpbGJveGNvbnRleHQiOiAiZGVmYXVsdCIsIm9yaWd0aW1lIjogIjE0NzAwNTc1NzEgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgIiwiY29udGV4dCI6ICJtYWNyby12bSIsImlkIjogIjY0MDEifV19, slot 0
2016-08-05 05:38:07,408 INFO -
2016-08-05 05:38:07,408 INFO - END HANDLING AMI EVENT channel USER/4159672901, command vmaildetail, data Old!eyJPbGQiOiBbeyJtYWlsYm94dXNlciI6ICI0MTU5NjcyOTAxIiwibXNnbnVtIjogIjAiLCJmbGFnIjogIiIsImR1cmF0aW9uIjogIjkxIiwibWFjcm9jb250ZXh0IjogImV4dC1sb2NhbCIsImRpciI6ICIvdmFyL3Nwb29sL2FzdGVyaXNrL3ZvaWNlbWFpbC9kZWZhdWx0LzQxNTk2NzI5MDEvT2xkIiwiY2FsbGVyaWQiOiAiXCI0OTczODhcIiA8NDk3Mzg4PiIsIm1haWxib3hjb250ZXh0IjogImRlZmF1bHQiLCJvcmlndGltZSI6ICIxNDUyODkwNjUyICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICIsImNvbnRleHQiOiAibWFjcm8tdm0iLCJpZCI6ICI2MzQ5In0seyJtYWlsYm94dXNlciI6ICI0MTU5NjcyOTAxIiwibXNnbnVtIjogIjEiLCJmbGFnIjogIiIsImR1cmF0aW9uIjogIjk2IiwibWFjcm9jb250ZXh0IjogImV4dC1sb2NhbCIsImRpciI6ICIvdmFyL3Nwb29sL2FzdGVyaXNrL3ZvaWNlbWFpbC9kZWZhdWx0LzQxNTk2NzI5MDEvT2xkIiwiY2FsbGVyaWQiOiAiXCJUZXN0XCIgPDQ0NDQ0ND4iLCJtYWlsYm94Y29udGV4dCI6ICJkZWZhdWx0Iiwib3JpZ3RpbWUiOiAiMTQ2NjQ1MDE5OCAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAiLCJjb250ZXh0IjogIm1hY3JvLXZtIiwiaWQiOiAiNjM3MiJ9XX0=, slot 0
2016-08-05 05:38:07,408 INFO -
2016-08-05 05:38:07,408 INFO - END HANDLING AMI EVENT channel USER/4159672901, command vmaildetail, data Work!eyJXb3JrIjogW3t9XX0=, slot 0
2016-08-05 05:38:07,782 INFO -
2016-08-05 05:38:07,782 INFO - 23.240.58.26:64073 => { "btn": "6@GENERAL", "cmd": "vmaildetail", "data": "Family!eyJGYW1pbHkiOiBbe31dfQ==", "slot": "0" }
2016-08-05 05:38:07,782 INFO -
2016-08-05 05:38:07,782 INFO - 23.240.58.26:64073 => { "btn": "6@GENERAL", "cmd": "vmaildetail", "data": "Friends!eyJGcmllbmRzIjogW3t9XX0=", "slot": "0" }

wcolling

We were using fop2 server: The server is version: 2.29.02

When requesting voicemail for a particular button, the vmaildetail response indicated that it was for the requested button. For example, if I login with extension 1 (button 7) and request voicemail for another extension(button 6), the vmaildetail response indicates that it is for the requested extension(button 6):

08:27:27,487 - ws send <msg data="6|getvmail|INBOX|3dc70d56e7af904043d4434f78a1c658" />
08:27:27,813 - 6,vmaildetail=INBOX!eyJJTkJPWC

We are now testing server 2.31.03 and have noticed that the response is different. If I login again as button 7 and request voicemail for button 6, the vmaildetail response indicates that is for the reqestor, not the requested:

08:20:33,876 - ws send <msg data="6|getvmail|INBOX|0cabfbb12d9ce6464abcb52653198912" />
VM142296:628 7,vmaildetail=INBOX!eyJJTkJPWCI6I

Is this correct? If so, how does the client know to which button the vmaildetail belongs?

wcolling

Occasionally, the FOP2 server will disconnect the client. The server log shows:

2016-07-27 11:50:25,989 INFO - Disconnecting Client 75.84.163.162:51527 on timeout
2016-07-27 11:50:25,989 INFO -
2016-07-27 11:50:25,989 INFO - Client Disconnection - remove client on error from socket AnyEvent::Handle=HASH(0xc504e00) (75.84.163.162:51527)
2016-07-27 11:50:25,989 INFO -
2016-07-27 11:50:25,989 INFO - Tengo 2 sesiones para el usuario 4159672901 por lo que no ejecuto callbacks de deslogueo
and fop2.js gets the onclose handler for the websocket connection.

I do not understand what the timeout is. The client is sending the ping and the server replies with a pong:

2016-07-27 11:50:23,244 INFO - 67.180.156.186:64541 <= <msg data="1|ping
" />
2016-07-27 11:50:23,244 INFO -
2016-07-27 11:50:23,244 INFO - -- PROCESS_FLASH_COMMAND origen 1 accion ping destino password
2016-07-27 11:50:23,244 INFO -
2016-07-27 11:50:25,988 INFO - 67.180.156.186:64541 => { "btn": "0", "cmd": "pong", "data": ...

As you can see from this log excerpt the disconnect comes right after the server replies to the ping request.

What can we do to prevent this timeout and allow the client to stay connected to the server?

The server is version: 2.29.02

wcolling

I did some more checking and I don't think this is related to ODBC. Assuming that FOP2 is written in perl, I wrote the following test program that retrieves the row contents with ODBC.

#!/usr/bin/perl -w
use strict;
use DBI;
my $dbh = DBI-> connect('dbi:ODBC:voicemail');

my $sql = qq/select id, msgnum, dir, context, macrocontext, origtime, duration from voicemail where id='6353'/;
my $sth = $dbh->prepare($sql) or die "Unable to prepare $sql ".$dbh->errstr;

$sth->execute() or die "Unable to execute query $sql " . $sth->errstr;
my ($id, $msgnum, $dir, $context, $macrocontext, $origtime, $duration);
$sth->bind_col(1, $id);
$sth->bind_col(2, $msgnum);
$sth->bind_col(3, $dir);
$sth->bind_col(4, $context);
$sth->bind_col(5, $macrocontext);
$sth->bind_col(6, $origtime);
$sth->bind_col(7, $duration);

while ($sth->fetch()) {
print ("$id\t,$msgnum\t,$dir\t,$context\t,$macrocontext\t,$origtime\t,$duration\n");
}
$sth->finish();
$dbh->disconnect();

When I ran it, the results were:

6353 ,0 ,/var/spool/asterisk/voicemail/default/4156849813/INBOX ,macro-vm ,ext-local ,1453737132 ,16

which returned the correct values for each field, including the origtime field.

wcolling

The origtime field is defined as varchar(40) with a latin1 character set. Do you think this may be a problem and it should be redefined as datetime or timestamp?

wcolling

We are experiencing a problem with the origtime field in the vmaildetail response. When voicemail data is returned, the fields look correct except for the origtime field which is returned as 1. I checked the database and the field contents appears correct there.

Here is an example:

16,vmaildetail=INBOX!eyJJTkJPWCI6IFt7Im1haWxib3h1c2VyIjogIjQxNTY4NDk4MTMiLCJtc2dudW0iOiAiMCIsImZsYWciOiAiIiwiZHVyYXRpb24iOiAiMTYiLCJtYWNyb2NvbnRleHQiOiAiZXh0LWxvY2FsIiwiZGlyIjogIi92YXIvc3Bvb2wvYXN0ZXJpc2svdm9pY2VtYWlsL2RlZmF1bHQvNDE1Njg0OTgxMy9JTkJPWCIsImNhbGxlcmlkIjogIlwiQ29sbGluZyxXaWxsaWFtXCIgPDk1MTc4MDc3MzY+IiwibWFpbGJveGNvbnRleHQiOiAiZGVmYXVsdCIsIm9yaWd0aW1lIjogIjEiLCJjb250ZXh0IjogIm1hY3JvLXZtIiwiaWQiOiAiNjM1MyJ9XX0= en slot 0

vmaildetail returns the following (I commented out the phone numbers so people do not call me):
{"INBOX": [{"mailboxuser": "415nnnnnnn","msgnum": "0","flag": "","duration": "16","macrocontext": "ext-local","dir": "/var/spool/asterisk/voicemail/default/4156849813/INBOX","callerid": ""Colling,William" <951nnnnnnn>","mailboxcontext": "default","origtime": "1","context": "macro-vm","id": "6353"}]}

But the database shows:

SELECT origtime from voicemail.voicemessages where id = 6353;
'1453737132'

Would you please explain how the fop2 server retrieves the origtime so we can check to see if we have an error on our side.

fop2_server version 2.29.02

wcolling

We have an external application that can delete or move voicemail to a separate folder. We are having a problem with the voicemailcount notification. When logging into the user interface, the counts are often wrong and after manipulating the voicemail by deleting it or moving to a different folder, no voicemailcount message is received with the updated counts.

In /etc/asterisk/voicemail.conf, we have:
pollmailboxes = yes
pollfreq = 10

My understanding is that these two entries tell FOP2 to check for voicemail changes every ten seconds, but that does not appear to be happening.

Can you explain how FOP2 gets the correct voicemail counts when voicemail is manipulated from an external source so we can troubleshoot this? Is there a user event we can issue in asterisk to cause FOP2 to update the counts? We currently issue a FOP2VMAIL UserEvent but I am not sure what that does.

127.0.0.1 -> Mailbox: 4159672903@default
127.0.0.1 -> Action: UserEvent
127.0.0.1 -> UserEvent: FOP2VMAIL
127.0.0.1 -> Channel: USER/4159672903
127.0.0.1 -> ActionID: 31

wcolling

I have an extension with four voicemails. One voicemail is in the INBOX folder while the other three, 6311, 6174, and 6168, are in the Friends folder.

When I open the voicemail dialog, the server sends the vmaildetail message which contains the information about each folder. When it sends the information for the Friends folder it sends voicemessage 6311, and 6174, twice. Message 6168 is missing completely.

Here is the message from the FOP2 server log:

75.84.163.162:57769 => { "btn": "7@GENERAL", "cmd": "vmaildetail", "data": "Friends!eyJGcmllbmRzIjogW3sibWFpbGJveHVzZXIiOiAiNDE1OTY3MjkwMSIsIm1zZ251bSI6ICIxIiwiZmxhZyI6ICIiLCJkdXJhdGlvbiI6ICIxNCIsIm1hY3JvY29udGV4dCI6ICJleHQtbG9jYWwiLCJkaXIiOiAiL3Zhci9zcG9vbC9hc3Rlcmlzay92b2ljZW1haWwvZGVmYXVsdC80MTU5NjcyOTAxL0ZyaWVuZHMiLCJjYWxsZXJpZCI6ICJcIkNPTExJTkcgV0lMTElBTVwiIDwrMTk1MTk0MTQ4Nzk+IiwibWFpbGJveGNvbnRleHQiOiAiZGVmYXVsdCIsIm9yaWd0aW1lIjogIjE0MzkzMDAwODAiLCJjb250ZXh0IjogIm1hY3JvLXZtIiwiaWQiOiAiNjMxMSJ9LHsibWFpbGJveHVzZXIiOiAiNDE1OTY3MjkwMSIsIm1zZ251bSI6ICIwIiwiZmxhZyI6ICIiLCJkdXJhdGlvbiI6ICIxNiIsIm1hY3JvY29udGV4dCI6ICJleHQtbG9jYWwiLCJkaXIiOiAiL3Zhci9zcG9vbC9hc3Rlcmlzay92b2ljZW1haWwvZGVmYXVsdC80MTU5NjcyOTAxL0ZyaWVuZHMiLCJjYWxsZXJpZCI6ICJcIkNPTExJTkcsIFdcIiA8KzE5NTE3ODA3NzM2PiIsIm1haWxib3hjb250ZXh0IjogImRlZmF1bHQiLCJvcmlndGltZSI6ICIxNDEzMzU1MjU3IiwiY29udGV4dCI6ICJtYWNyby12bSIsImlkIjogIjYxNzQifSx7Im1haWxib3h1c2VyIjogIjQxNTk2NzI5MDEiLCJtc2dudW0iOiAiMCIsImZsYWciOiAiIiwiZHVyYXRpb24iOiAiMTYiLCJtYWNyb2NvbnRleHQiOiAiZXh0LWxvY2FsIiwiZGlyIjogIi92YXIvc3Bvb2wvYXN0ZXJpc2svdm9pY2VtYWlsL2RlZmF1bHQvNDE1OTY3MjkwMS9GcmllbmRzIiwiY2FsbGVyaWQiOiAiXCJDT0xMSU5HLCBXXCIgPCsxOTUxNzgwNzczNj4iLCJtYWlsYm94Y29udGV4dCI6ICJkZWZhdWx0Iiwib3JpZ3RpbWUiOiAiMTQxMzM1NTI1NyIsImNvbnRleHQiOiAibWFjcm8tdm0iLCJpZCI6ICI2MTc0In1dfQ==", "slot": "0" }

The data translates to:

{"Friends": [{"mailboxuser": "4159672901","msgnum": "1","flag": "","duration": "14","macrocontext": "ext-local","dir": "/var/spool/asterisk/voicemail/default/4159672901/Friends","callerid": ""COLLING WILLIAM" <+19519414879>","mailboxcontext": "default","origtime": "1439300080","context": "macro-vm","id": "6311"},{"mailboxuser": "4159672901","msgnum": "0","flag": "","duration": "16","macrocontext": "ext-local","dir": "/var/spool/asterisk/voicemail/default/4159672901/Friends","callerid": ""COLLING, W" <+19517807736>","mailboxcontext": "default","origtime": "1413355257","context": "macro-vm","id": "6174"},{"mailboxuser": "4159672901","msgnum": "0","flag": "","duration": "16","macrocontext": "ext-local","dir": "/var/spool/asterisk/voicemail/default/4159672901/Friends","callerid": ""COLLING, W" <+19517807736>","mailboxcontext": "default","origtime": "1413355257","context": "macro-vm","id": "6174"}]}

This is with FOP2 server 2.29.00.

Does the server read the voicemail information directly from the database? If not, how does it read it?

wcolling

Using Channel: GLOBAL works great. Thank you.

wcolling

We would like to receive PeerStatus notifications in the UI. I created a plugin with an AMI_Event_Handler for the PeerStatus event. This plugin gets called when the event occurs, but I do not see how I can get the message back to the UI.

In other plugins, we created a UserEvent with a unique family name and that was sent back to the UI. However, in the case of the PeerStatus there is no channel and I am seeing:

There is no channel , but we've got Family. Do nothing

in the FOP2 log.

Is there something I can put in the Channel parameter to tell the FOP2 server to ignore the channel and send the notification? If not, is there another mechanism where I can send a message from the plugin to the UI?

wcolling

I reloaded the original 2.28 fop2.js and was able to reproduce the problem, albeit a bit differently.

This time, open the browser, navigate to the fop2 login page, and enter a correct extension with an invalid password. The client sends the auth request, gets the incorrect return, and redisplays the login dialog.

uncion init
VM97:1 sends auth 1234 y ieRMoKueUKgRfm9Q9nK1RoAGzbSAX
VM97:1 ws send <msg data="1|auth|4159672901|1da254f595f949a51b0aa5232a19a020" />
VM97:1 0,incorrect=0 en slot
VM97:1 show sec box
VM97:1 limpia todo
VM97:1

At this point, do the update in FreePBX. The fop2 server will start sending messages to the client that never logged in.

wcolling

[root@ASTERISK18 ~]# /usr/local/fop2/fop2_server --version
fop2_server version 2.28

wcolling

I forgot to add that we have made some modifications to fop2.js so there will be some messages you do not recognize.

wcolling

I was finally able to replicate this problem consistently. The problem occurs in both Chrome and Firefox (the only two browsers we use).

To replicate the problem:

log into FOP2
log out
In FreePBX, I updated the permissions of my user, clicked on Submit Changes, and then Apply Configuration Changes.
At this point, the FOP2 server starts sending messages to my logged off client again.

I have attached the console log that shows this. I added
=====> Here I am logged out and have the login dialog <=====
to the log so you can see where I am logged off. There are a couple pings after this, and then a whole slew of messages from the FOP2 server.

wcolling

The console log continues to show messages sent from the server.

wcolling

We have noticed that occasionally when the user logs out of the FOP2 server but leaves the browser open, that he continues to get messages from the server. He tells us that he hears the ringing sound when a queue call is received.

I checked the FOP2 server log and verified that the close message was received by the server.

One thing I noticed is when I attempt to replicate the problem, I see what appear to be entries in the log that support the close request.

<= <msg data="19|close||a51774713f90db99bb7ebe652561d2c8" />
-- PROCESS_FLASH_COMMAND origen 19 accion close destino password a51774713f90db99bb7ebe652561d2c8
Client Disconnection - remove client on error from socket AnyEvent::Handle=HASH(0xe5ac120) (75.85.118.107:52967)
Client disconnection, user 4159672901 logged off
Discarding from status notifications as it is not a permitted possition (19).
No context defined for AnyEvent::Handle::destroyed=HASH(0xe5ac120) (unauthenticated or connection failed), skip online status notification.

However, when I check the user's logout, all I see is the close request, but no additional entries after it.

I don't know if this indicates an error in the close request or something else.

Can you think of a reason that the server would continue to send messages to a client after logout? There is a possibility that another user is logged into FOP2 with the same extension.

wcolling

I rechecked the presence file (deleted the entry and retyped it without copying from another line) and the problem persists. If the problem were in the presence.js file, I would expect the command sent to the fop2 server to show the problem, yet the translation appears to occur in the server.

[root@ASTERISK18 fop2]# file js/presence.js
js/presence.js: UTF-8 Unicode C++ program text

Correct here in the command sent to the server
75.85.118.107:52197 <= <msg data="23|setastdb|fop2state~4159672901~Away|0c81ee79a3e68fb6a9f03eb4bdeb5461" />

Yet, incorrect when the action is sent to Asterisk.
127.0.0.1 -> Action: Command
127.0.0.1 -> Command: database put fop2state USER/4159672901 "^C^F²"

I got around the problem by changing the command sent from fop2.js to setastdb2 and handling it in a plugin. This is with the same entry in presence.js:

75.85.118.107:52323 <= <msg data="23|setastdb2|fop2state~4159672901~Away|0c9f5d4fcf8982e0d9b3e6f57a486fe3" />

In Headland pre-command setastdb plugin
127.0.0.1 -> Command: database put fop2state USER/4159672901 "Away"
127.0.0.1 -> Action: Command
127.0.0.1 -> ActionID: 62

wcolling

I would like to replace an action performed by the FOP2 server. To do this, I would write a plugin with a precommand handler that would process the command.

Is there a way, then, that the plugin can send a response that tells the FOP2 server to bypass its standard processing of the command and proceed to invoke the postcommand handler, if present?

FOP2 Community Forum

wcolling

Posts