ZABBIX BUGS AND ISSUES
  1. ZABBIX BUGS AND ISSUES
  2. ZBX-5920

Syncronization config process is very slow for Oracle database

    Details

      Description

      See comment for more detailed information.

        Activity

        Hide
        Alexey Pustovalov added a comment -
        41292:20121130:111031.430 DCsync_configuration() sync config: 0.002474 sec.
        41292:20121130:111031.430 DCsync_configuration() item sql   : 0.004955 sec.
        41292:20121130:111031.430 DCsync_configuration() trig sql   : 0.461767 sec.
        41292:20121130:111031.430 DCsync_configuration() tdep sql   : 0.007816 sec.
        41292:20121130:111031.430 DCsync_configuration() func sql   : 0.666670 sec.
        41292:20121130:111031.430 DCsync_configuration() host sql   : 0.001819 sec.
        41292:20121130:111031.430 DCsync_configuration() htmpl sql  : 0.002521 sec.
        41292:20121130:111031.430 DCsync_configuration() gmacro sql : 0.001341 sec.
        41292:20121130:111031.430 DCsync_configuration() hmacro sql : 0.001384 sec.
        41292:20121130:111031.430 DCsync_configuration() interf sql : 0.001349 sec.
        41292:20121130:111031.430 DCsync_configuration() sync lock  : 216.455358 sec.
        41292:20121130:111031.430 DCsync_configuration() total time : 217.607453 sec.
        41292:20121130:111031.430 DCsync_configuration() items      : 184987 (298153 slots)
        41292:20121130:111031.430 DCsync_configuration() items_hk   : 184987 (298153 slots)
        41292:20121130:111031.431 DCsync_configuration() snmpitems  : 0 (1009 slots)
        41292:20121130:111031.431 DCsync_configuration() ipmiitems  : 0 (1009 slots)
        41292:20121130:111031.431 DCsync_configuration() flexitems  : 2848 (5153 slots)
        41292:20121130:111031.431 DCsync_configuration() trapitems  : 8 (1009 slots)
        41292:20121130:111031.431 DCsync_configuration() logitems   : 0 (1009 slots)
        41292:20121130:111031.431 DCsync_configuration() dbitems    : 0 (1009 slots)
        41292:20121130:111031.431 DCsync_configuration() sshitems   : 0 (1009 slots)
        41292:20121130:111031.431 DCsync_configuration() telnetitems: 0 (1009 slots)
        41292:20121130:111031.431 DCsync_configuration() jmxitems   : 0 (1009 slots)
        41292:20121130:111031.431 DCsync_configuration() calcitems  : 5590 (7741 slots)
        41292:20121130:111031.431 DCsync_configuration() functions  : 113535 (198769 slots)
        41292:20121130:111031.431 DCsync_configuration() triggers   : 89625 (132511 slots)
        41292:20121130:111031.431 DCsync_configuration() trigdeps   : 29582 (39229 slots)
        41292:20121130:111031.431 DCsync_configuration() time_trigs : 17935 (20979 allocated)
        41292:20121130:111031.431 DCsync_configuration() hosts      : 3781 (5153 slots)
        41292:20121130:111031.431 DCsync_configuration() hosts_ph   : 3781 (5153 slots)
        41292:20121130:111031.431 DCsync_configuration() proxies    : 2 (1009 slots)
        41292:20121130:111031.431 DCsync_configuration() ipmihosts  : 7 (1009 slots)
        41292:20121130:111031.431 DCsync_configuration() htmpls     : 2798 (5153 slots)
        41292:20121130:111031.431 DCsync_configuration() gmacros    : 1 (1009 slots)
        41292:20121130:111031.431 DCsync_configuration() gmacros_m  : 1 (1009 slots)
        41292:20121130:111031.431 DCsync_configuration() hmacros    : 38 (1009 slots)
        41292:20121130:111031.431 DCsync_configuration() hmacros_hm : 38 (1009 slots)
        41292:20121130:111031.431 DCsync_configuration() interfaces : 9965 (17431 slots)
        41292:20121130:111031.431 DCsync_configuration() interfac_ht: 4834 (7741 slots)
        41292:20121130:111031.432 DCsync_configuration() if_snmpitms: 0 (1009 slots)
        41292:20121130:111031.432 DCsync_configuration() if_snmpaddr: 0 (1009 slots)
        41292:20121130:111031.432 DCsync_configuration() queue[0]   : 4913 (6216 allocated)
        41292:20121130:111031.432 DCsync_configuration() queue[1]   : 20 (32 allocated)
        41292:20121130:111031.432 DCsync_configuration() queue[2]   : 0 (0 allocated)
        41292:20121130:111031.432 DCsync_configuration() queue[3]   : 9 (32 allocated)
        41292:20121130:111031.432 DCsync_configuration() queue[4]   : 0 (0 allocated)
        41292:20121130:111031.432 DCsync_configuration() pqueue     : 2 (32 allocated)
        41292:20121130:111031.432 DCsync_configuration() configfree : 71.682842%
        41292:20121130:111031.432 DCsync_configuration() strings    : 113632 (198769 slots)
        41292:20121130:111031.432 DCsync_configuration() strpoolfree: 73.029420%
        41292:20121130:111031.432 === memory statistics for configuration cache ===
        41292:20121130:111031.432 free chunks of size     72 bytes:        3
        41292:20121130:111031.432 free chunks of size >= 256 bytes:        7
        41292:20121130:111031.432 min chunk size:         72 bytes
        41292:20121130:111031.432 max chunk size:  163515216 bytes
        41292:20121130:111031.432 memory of total size 228169776 bytes fragmented into 1370901 chunks
        41292:20121130:111031.432 of those,  163558840 bytes are in       10 free chunks
        41292:20121130:111031.432 of those,   53643736 bytes are in  1370891 used chunks
        41292:20121130:111031.432 ================================
        41292:20121130:111031.432 === memory statistics for string pool ===
        41292:20121130:111031.432 free chunks of size >= 256 bytes:        2
        41292:20121130:111031.432 min chunk size:     345944 bytes
        41292:20121130:111031.432 max chunk size:   29059584 bytes
        41292:20121130:111031.433 memory of total size 40264968 bytes fragmented into 227268 chunks
        41292:20121130:111031.433 of those,   29405528 bytes are in        2 free chunks
        41292:20121130:111031.433 of those,    9041304 bytes are in   227266 used chunks
        41292:20121130:111031.433 ================================
        41292:20121130:111031.433 End of DCsync_configuration()
        41292:20121130:111031.433 configuration syncer spent 217.610428 second while processing configuration data
        41292:20121130:111031.433 sleeping for 300 seconds
        
        Show
        Alexey Pustovalov added a comment - 41292:20121130:111031.430 DCsync_configuration() sync config: 0.002474 sec. 41292:20121130:111031.430 DCsync_configuration() item sql : 0.004955 sec. 41292:20121130:111031.430 DCsync_configuration() trig sql : 0.461767 sec. 41292:20121130:111031.430 DCsync_configuration() tdep sql : 0.007816 sec. 41292:20121130:111031.430 DCsync_configuration() func sql : 0.666670 sec. 41292:20121130:111031.430 DCsync_configuration() host sql : 0.001819 sec. 41292:20121130:111031.430 DCsync_configuration() htmpl sql : 0.002521 sec. 41292:20121130:111031.430 DCsync_configuration() gmacro sql : 0.001341 sec. 41292:20121130:111031.430 DCsync_configuration() hmacro sql : 0.001384 sec. 41292:20121130:111031.430 DCsync_configuration() interf sql : 0.001349 sec. 41292:20121130:111031.430 DCsync_configuration() sync lock : 216.455358 sec. 41292:20121130:111031.430 DCsync_configuration() total time : 217.607453 sec. 41292:20121130:111031.430 DCsync_configuration() items : 184987 (298153 slots) 41292:20121130:111031.430 DCsync_configuration() items_hk : 184987 (298153 slots) 41292:20121130:111031.431 DCsync_configuration() snmpitems : 0 (1009 slots) 41292:20121130:111031.431 DCsync_configuration() ipmiitems : 0 (1009 slots) 41292:20121130:111031.431 DCsync_configuration() flexitems : 2848 (5153 slots) 41292:20121130:111031.431 DCsync_configuration() trapitems : 8 (1009 slots) 41292:20121130:111031.431 DCsync_configuration() logitems : 0 (1009 slots) 41292:20121130:111031.431 DCsync_configuration() dbitems : 0 (1009 slots) 41292:20121130:111031.431 DCsync_configuration() sshitems : 0 (1009 slots) 41292:20121130:111031.431 DCsync_configuration() telnetitems: 0 (1009 slots) 41292:20121130:111031.431 DCsync_configuration() jmxitems : 0 (1009 slots) 41292:20121130:111031.431 DCsync_configuration() calcitems : 5590 (7741 slots) 41292:20121130:111031.431 DCsync_configuration() functions : 113535 (198769 slots) 41292:20121130:111031.431 DCsync_configuration() triggers : 89625 (132511 slots) 41292:20121130:111031.431 DCsync_configuration() trigdeps : 29582 (39229 slots) 41292:20121130:111031.431 DCsync_configuration() time_trigs : 17935 (20979 allocated) 41292:20121130:111031.431 DCsync_configuration() hosts : 3781 (5153 slots) 41292:20121130:111031.431 DCsync_configuration() hosts_ph : 3781 (5153 slots) 41292:20121130:111031.431 DCsync_configuration() proxies : 2 (1009 slots) 41292:20121130:111031.431 DCsync_configuration() ipmihosts : 7 (1009 slots) 41292:20121130:111031.431 DCsync_configuration() htmpls : 2798 (5153 slots) 41292:20121130:111031.431 DCsync_configuration() gmacros : 1 (1009 slots) 41292:20121130:111031.431 DCsync_configuration() gmacros_m : 1 (1009 slots) 41292:20121130:111031.431 DCsync_configuration() hmacros : 38 (1009 slots) 41292:20121130:111031.431 DCsync_configuration() hmacros_hm : 38 (1009 slots) 41292:20121130:111031.431 DCsync_configuration() interfaces : 9965 (17431 slots) 41292:20121130:111031.431 DCsync_configuration() interfac_ht: 4834 (7741 slots) 41292:20121130:111031.432 DCsync_configuration() if_snmpitms: 0 (1009 slots) 41292:20121130:111031.432 DCsync_configuration() if_snmpaddr: 0 (1009 slots) 41292:20121130:111031.432 DCsync_configuration() queue[0] : 4913 (6216 allocated) 41292:20121130:111031.432 DCsync_configuration() queue[1] : 20 (32 allocated) 41292:20121130:111031.432 DCsync_configuration() queue[2] : 0 (0 allocated) 41292:20121130:111031.432 DCsync_configuration() queue[3] : 9 (32 allocated) 41292:20121130:111031.432 DCsync_configuration() queue[4] : 0 (0 allocated) 41292:20121130:111031.432 DCsync_configuration() pqueue : 2 (32 allocated) 41292:20121130:111031.432 DCsync_configuration() configfree : 71.682842% 41292:20121130:111031.432 DCsync_configuration() strings : 113632 (198769 slots) 41292:20121130:111031.432 DCsync_configuration() strpoolfree: 73.029420% 41292:20121130:111031.432 === memory statistics for configuration cache === 41292:20121130:111031.432 free chunks of size 72 bytes: 3 41292:20121130:111031.432 free chunks of size >= 256 bytes: 7 41292:20121130:111031.432 min chunk size: 72 bytes 41292:20121130:111031.432 max chunk size: 163515216 bytes 41292:20121130:111031.432 memory of total size 228169776 bytes fragmented into 1370901 chunks 41292:20121130:111031.432 of those, 163558840 bytes are in 10 free chunks 41292:20121130:111031.432 of those, 53643736 bytes are in 1370891 used chunks 41292:20121130:111031.432 ================================ 41292:20121130:111031.432 === memory statistics for string pool === 41292:20121130:111031.432 free chunks of size >= 256 bytes: 2 41292:20121130:111031.432 min chunk size: 345944 bytes 41292:20121130:111031.432 max chunk size: 29059584 bytes 41292:20121130:111031.433 memory of total size 40264968 bytes fragmented into 227268 chunks 41292:20121130:111031.433 of those, 29405528 bytes are in 2 free chunks 41292:20121130:111031.433 of those, 9041304 bytes are in 227266 used chunks 41292:20121130:111031.433 ================================ 41292:20121130:111031.433 End of DCsync_configuration() 41292:20121130:111031.433 configuration syncer spent 217.610428 second while processing configuration data 41292:20121130:111031.433 sleeping for 300 seconds
        Hide
        Alexey Pustovalov added a comment -

        Oracle does not put all received data set to result variable, it received by a one row.

        Show
        Alexey Pustovalov added a comment - Oracle does not put all received data set to result variable, it received by a one row.
        Hide
        dimir added a comment -

        I tested the results using a memory buffer for prefetched rows (OCI_ATTR_PREFETCH_MEMORY). Let's see some results. I have:

        • 959 hosts
        • 37556 items
        • 14208 triggers

        Without any changes it takes about 35 seconds to synchronize configuration:

        configuration syncer spent 36.242239 second while processing configuration data
        configuration syncer spent 36.183110 second while processing configuration data
        configuration syncer spent 36.657940 second while processing configuration data
        

        Let's see how it works if we enable prefetching buffer:

        100 KB:

        configuration syncer spent 8.749929 second while processing configuration data
        configuration syncer spent 8.835130 second while processing configuration data
        configuration syncer spent 9.176195 second while processing configuration data
        configuration syncer spent 8.110003 second while processing configuration data
        

        500 KB:

        configuration syncer spent 3.354367 second while processing configuration data
        configuration syncer spent 4.052118 second while processing configuration data
        configuration syncer spent 3.645470 second while processing configuration data
        configuration syncer spent 3.983950 second while processing configuration data
        

        1 MB:

        configuration syncer spent 2.767637 second while processing configuration data
        configuration syncer spent 3.016469 second while processing configuration data
        configuration syncer spent 2.716325 second while processing configuration data
        

        2 MB (wins):

        configuration syncer spent 2.045982 second while processing configuration data
        configuration syncer spent 2.493603 second while processing configuration data
        configuration syncer spent 2.245250 second while processing configuration data
        

        4 MB:

        configuration syncer spent 2.143801 second while processing configuration data
        configuration syncer spent 2.769383 second while processing configuration data
        configuration syncer spent 3.175865 second while processing configuration data
        configuration syncer spent 2.105325 second while processing configuration data
        

        20 MB:

        configuration syncer spent 3.328395 second while processing configuration data
        configuration syncer spent 2.828088 second while processing configuration data
        configuration syncer spent 2.011795 second while processing configuration data
        configuration syncer spent 2.344685 second while processing configuration data
        

        Based on results I conclude that prefetch buffer should be 2 MB.

        Show
        dimir added a comment - I tested the results using a memory buffer for prefetched rows (OCI_ATTR_PREFETCH_MEMORY). Let's see some results. I have: 959 hosts 37556 items 14208 triggers Without any changes it takes about 35 seconds to synchronize configuration: configuration syncer spent 36.242239 second while processing configuration data configuration syncer spent 36.183110 second while processing configuration data configuration syncer spent 36.657940 second while processing configuration data Let's see how it works if we enable prefetching buffer: 100 KB : configuration syncer spent 8.749929 second while processing configuration data configuration syncer spent 8.835130 second while processing configuration data configuration syncer spent 9.176195 second while processing configuration data configuration syncer spent 8.110003 second while processing configuration data 500 KB : configuration syncer spent 3.354367 second while processing configuration data configuration syncer spent 4.052118 second while processing configuration data configuration syncer spent 3.645470 second while processing configuration data configuration syncer spent 3.983950 second while processing configuration data 1 MB : configuration syncer spent 2.767637 second while processing configuration data configuration syncer spent 3.016469 second while processing configuration data configuration syncer spent 2.716325 second while processing configuration data 2 MB (wins): configuration syncer spent 2.045982 second while processing configuration data configuration syncer spent 2.493603 second while processing configuration data configuration syncer spent 2.245250 second while processing configuration data 4 MB : configuration syncer spent 2.143801 second while processing configuration data configuration syncer spent 2.769383 second while processing configuration data configuration syncer spent 3.175865 second while processing configuration data configuration syncer spent 2.105325 second while processing configuration data 20 MB : configuration syncer spent 3.328395 second while processing configuration data configuration syncer spent 2.828088 second while processing configuration data configuration syncer spent 2.011795 second while processing configuration data configuration syncer spent 2.344685 second while processing configuration data Based on results I conclude that prefetch buffer should be 2 MB.
        Hide
        dimir added a comment -

        Fixed in development branch svn://svn.zabbix.com/branches/dev/ZBX-5920 .

        Show
        dimir added a comment - Fixed in development branch svn://svn.zabbix.com/branches/dev/ZBX-5920 .
        Hide
        dimir added a comment - - edited

        OK, with

        1782 hosts
        26538 trigger
        71154 items
        

        and this fix the configuration synchronization time drops down from 70 seconds to 3 seconds. Increasing the prefetch memory buffer from 2MB does not give visible improvements. Moreover, the tests show that when it's too big (~500 MB) it takes too much time to allocate/deallocate the memory which results in worse results than without the fix.

        There is still a place for improvement especially in case of larger installations but further improvements require bigger changes which we decided not to do at this moment.

        A possible improvement was proposed by sasha: 2 copies of configuration, one that is being updated (writable, locking) another that's being used (read-only, no lock), which are swapped on update.

        Another way of improving it - moving the constantly changing columns like "lastvalue", "lastclock" away from configuration (items table), making it reasonable to enable e. g. client-side statement caching.

        Show
        dimir added a comment - - edited OK, with 1782 hosts 26538 trigger 71154 items and this fix the configuration synchronization time drops down from 70 seconds to 3 seconds. Increasing the prefetch memory buffer from 2MB does not give visible improvements. Moreover, the tests show that when it's too big (~500 MB) it takes too much time to allocate/deallocate the memory which results in worse results than without the fix. There is still a place for improvement especially in case of larger installations but further improvements require bigger changes which we decided not to do at this moment. A possible improvement was proposed by sasha: 2 copies of configuration, one that is being updated (writable, locking) another that's being used (read-only, no lock), which are swapped on update. Another way of improving it - moving the constantly changing columns like "lastvalue", "lastclock" away from configuration (items table), making it reasonable to enable e. g. client-side statement caching.
        Hide
        Andris Mednis added a comment -

        Successfully tested.

        Show
        Andris Mednis added a comment - Successfully tested.
        Hide
        dimir added a comment -

        Fixed in pre-2.0.5 r32299, pre-2.1.0 r32300.

        Show
        dimir added a comment - Fixed in pre-2.0.5 r32299, pre-2.1.0 r32300.
        Hide
        richlv added a comment - - edited

        (2) i believe changelog entry for 2.1.0 shouldn't be there because this was also added in 2.0.5 ?

        dimir Ye, RESOLVED in r33301.

        <richlv> thanks, CLOSED

        Show
        richlv added a comment - - edited (2) i believe changelog entry for 2.1.0 shouldn't be there because this was also added in 2.0.5 ? dimir Ye, RESOLVED in r33301. <richlv> thanks, CLOSED
        Hide
        Oleksiy Zagorskyi added a comment -

        Looks like this change caused a problem with housekeeper, reported in ZBX-6493

        Show
        Oleksiy Zagorskyi added a comment - Looks like this change caused a problem with housekeeper, reported in ZBX-6493

          People

          • Assignee:
            richlv
            Reporter:
            Alexey Pustovalov
          • Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved: