ZABBIX BUGS AND ISSUES

Syncronization config process is very slow for Oracle database

Details

  • Zabbix ID:
    RTF

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

Vote (0)
Watch (2)

Dates

  • Created:
    Updated:
    Resolved: