Realtime Extensions - Log show triple Queries

I’m sorry if this has been asked before but could not find with the search option.

I started using realtime for my extensions and when I watch the log, I see each query displayed 3 times for each priority. Why is that?

Jul 12 22:02:14 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM tbl_extensions WHERE exten = 'XXX6158599' AND context = 'inbound' AND priority = '1'
Jul 12 22:02:14 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Everything is fine.
Jul 12 22:02:14 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM tbl_extensions WHERE exten = 'XXX6158599' AND context = 'inbound' AND priority = '1'
Jul 12 22:02:14 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Everything is fine.
Jul 12 22:02:14 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM tbl_extensions WHERE exten = 'XXX6158599' AND context = 'inbound' AND priority = '1'
Jul 12 22:02:14 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Everything is fine.
Jul 12 22:02:14 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM tbl_extensions WHERE exten = 'XXX6158599' AND context = 'inbound' AND priority = '1'
Jul 12 22:02:14 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Everything is fine.
Jul 12 22:02:14 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM tbl_extensions WHERE exten = 'XXX6158599' AND context = 'inbound' AND priority = '2'
Jul 12 22:02:15 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Everything is fine.
Jul 12 22:02:15 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM tbl_extensions WHERE exten = 'XXX6158599' AND context = 'inbound' AND priority = '2'
Jul 12 22:02:15 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Everything is fine.
Jul 12 22:02:15 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM tbl_extensions WHERE exten = 'XXX6158599' AND context = 'inbound' AND priority = '2'
Jul 12 22:02:15 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Everything is fine.
Jul 12 22:02:15 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM tbl_extensions WHERE exten = 'XXX6158599' AND context = 'inbound' AND priority = '3'
Jul 12 22:02:15 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Everything is fine.
Jul 12 22:02:15 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM tbl_extensions WHERE exten = 'XXX6158599' AND context = 'inbound' AND priority = '3'
Jul 12 22:02:15 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Everything is fine.
Jul 12 22:02:15 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM tbl_extensions WHERE exten = 'XXX6158599' AND context = 'inbound' AND priority = '3'
Jul 12 22:02:15 DEBUG[24355] chan_sip.c: Auto destroying call 'ZDg0OWM4MWYzMjQwNTAyMGEyNjQ4OGEzNmQ0ZjMxY2Y.'
Jul 12 22:02:15 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Everything is fine.
Jul 12 22:02:15 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM tbl_extensions WHERE exten = 'XXX6158599' AND context = 'inbound' AND priority = '4'
Jul 12 22:02:15 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Everything is fine.
Jul 12 22:02:15 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM tbl_extensions WHERE exten = 'XXX6158599' AND context = 'inbound' AND priority = '4'
Jul 12 22:02:16 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Everything is fine.
Jul 12 22:02:16 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM tbl_extensions WHERE exten = 'XXX6158599' AND context = 'inbound' AND priority = '4'
Jul 12 22:02:16 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Everything is fine.
Jul 12 22:02:16 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM tbl_extensions WHERE exten = 'XXX6158599' AND context = 'inbound' AND priority = '5'
Jul 12 22:02:16 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Everything is fine.
Jul 12 22:02:16 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM tbl_extensions WHERE exten = 'XXX6158599' AND context = 'inbound' AND priority = '5'
Jul 12 22:02:16 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Everything is fine.
Jul 12 22:02:16 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM tbl_extensions WHERE exten = 'XXX6158599' AND context = 'inbound' AND priority = '5'
Jul 12 22:02:16 DEBUG[27265] pbx.c: Expression result is '0'
Jul 12 22:02:16 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Everything is fine.
Jul 12 22:02:16 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM tbl_extensions WHERE exten = 'XXX6158599' AND context = 'inbound' AND priority = '6'
Jul 12 22:02:16 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Everything is fine.
Jul 12 22:02:16 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM tbl_extensions WHERE exten = 'XXX6158599' AND context = 'inbound' AND priority = '6'
Jul 12 22:02:17 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Everything is fine.
Jul 12 22:02:17 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM tbl_extensions WHERE exten = 'XXX6158599' AND context = 'inbound' AND priority = '6'
Jul 12 22:02:17 VERBOSE[27265] logger.c:   cnam.agi: CNAM|Cached result found, setting to Brookfield CT
Jul 12 22:02:17 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Everything is fine.
Jul 12 22:02:17 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM tbl_extensions WHERE exten = 'XXX6158599' AND context = 'inbound' AND priority = '7'
Jul 12 22:02:17 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Everything is fine.
Jul 12 22:02:17 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM tbl_extensions WHERE exten = 'XXX6158599' AND context = 'inbound' AND priority = '7'
Jul 12 22:02:17 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Everything is fine.
Jul 12 22:02:17 DEBUG[27265] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM tbl_extensions WHERE exten = 'XXX6158599' AND context = 'inbound' AND priority = '7'

Still, everything works fine:

    -- Executing SetCDRUserField("SIP/mike-b70e4ca0", "DIDXXX6158599")
    -- Executing SetAMAFlags("SIP/mike-b70e4ca0", "billing")
    -- Executing SetAccount("SIP/mike-b70e4ca0", "DIDXXXXX")
    -- Executing Set("SIP/mike-b70e4ca0", "CNAM=1")
    -- Executing GotoIf("SIP/mike-b70e4ca0", "0?7:6")
    -- Goto (inbound,XXX6158599,6)
    -- Executing DeadAGI("SIP/mike-b70e4ca0", "cnam.agi")
    -- Launched AGI Script /var/lib/asterisk/agi-bin/cnam.agi
  cnam.agi: CNAM|Cached result found, setting  calleridname to MCKAY S
    -- AGI Script cnam.agi completed, returning 0
     -- Executing Dial("SIP/mike-b70e4ca0", "SIP/XXXXXXX/XXX6158599")

Xs are normal, i just replaced them for the public post.

I’m scratching my head as to why each query are displayed 3 times in the debug log.

Update, i turned on MySQL logging and my SQL server really receives 3 identical queries for each Extension Priority

1,1,1
2,2,2
3,3,3

Here’s how my extensions look like:

| 103 | inbound | XXX6158599 |        1 | SetCDRUserField | DIDXXX6158599                |
| 104 | inbound | XXX6158599 |        2 | SetAMAFlags     | billing                      |
| 105 | inbound | XXX6158599 |        3 | SetAccount      | DID31XXX                    |
| 106 | inbound | XXX6158599 |        4 | Set             | CNAM=1                       |
| 107 | inbound | XXX6158599 |        5 | GotoIf          | $["${CNAM}" != "1"]?7:6      |
| 108 | inbound | XXX6158599 |        6 | DeadAGI         | cnam.agi                     |
| 109 | inbound | XXX6158599 |        7 | Dial            | SIP/XXXXX_001/XXX6158599    |
| 110 | inbound | XXX6158599 |        8 | Hangup          |                              |

voip3*CLI> show version files like real
File Revision


app_realtime.c Revision: 7221
pbx_realtime.c Revision: 7221
voip3*CLI> show version
Asterisk 1.2.19 built by root @ voip3.xxxxxxxx on a i686 running Linux on 2007-06-27 21:16:47 UTC