Ad Widget

Collapse

Проблема с высокой нагрузкой

Collapse
X
 
  • Time
  • Show
Clear All
new posts
  • Yagel
    Junior Member
    • Mar 2011
    • 10

    #1

    Проблема с высокой нагрузкой

    Добрый день!
    Где-то с неделю возникла проблема с обновлением данных, а именно периодически перестают поступать данные на сервер. К примеру сервер работает в течении суток, а потом просто перестает получать данные. Рестарт сервера - проходит минут 10, очередь почти вся рассасывается, через 5 часов к примеру начинаются задержки в получении данных ( не всех ), к примеру

    Беру один хост сейчас:

    Исходящий траффик на интерфейсе ( vlan205 ) 11 Мар 2011 09:16:51
    А вот тут все нормально ( на том же хосте )
    Входящий траффик на интерфейсе ( vlan200 ) 11 Мар 2011 10:24:33

    В логах агента вроде все нормально:
    8174:20110311:101425.221 Processing request.
    8174:20110311:101425.222 Requested [net.if.out[vlan205,bytes]]
    8174:20110311:101425.222 Sending back [1071893801]
    8176:20110311:101425.464 In send_buffer('10.1.1.248','10055')
    8176:20110311:101425.464 Values in the buffer 0 Max 100
    8176:20110311:101425.465 Sleeping for 1 seconds
    8173:20110311:101426.426 Processing request.
    8173:20110311:101426.427 Requested [vfs.fs.size[/var,pfree]]
    8173:20110311:101426.427 Sending back [99.240778]
    8176:20110311:101426.465 In send_buffer('10.1.1.248','10055')
    Видно что данные вроде идут на сервер.

    Мы никак не можем понять в чем проблема.

    Хостов больше 1000 мониторится
    2 ноды
    200 прокси ( активные )
    На центральное ноде основные сервера: порядка 50-ти, остальное все на проксях.
    На 2-ой ноде: только прокси ( порядка 60 штук ). Со второй нодой проблем нету.
    50000 тыс элементов на основной ноде ( где и проблема )( среднее время проверки 30 секунд ). Минимально также 30 секунд.

    Конфиг
    NodeID=1
    ListenPort=10055
    LogFile=/var/log/zabbix/zabbix_server.log
    LogFileSize=20
    DebugLevel=3
    StartPollers=30
    StartTrappers=100
    StartPingers=20
    StartHTTPPollers=5
    HousekeepingFrequency=1
    CacheSize=256M
    StartDBSyncers=4
    HistoryCacheSize=256M
    TrendCacheSize=256M
    Timeout=30
    AlertScriptsPath=/etc/zabbix/alert
    ExternalScripts=/etc/zabbix/externalscripts
    StartProxyPollers=0
    StartPollersUnreachable=5

    С Housekeeper-ом вроде проблем нету:
    4844:20110311:092910.013 Executing housekeeper
    4844:20110311:093103.611 Deleted 452140 records from history and trendsz

    В логах сервера ( включен debug=3 ), по данному хосту ошибок вообще нету.

    С дисковой подсистемой, тоже все отлично.
    sda3 0,00 55,00 0,00 31,00 0,00 0,34 22,19 0,01 0,32 0,06 0,20

    В один из моментов перезапуска сервера:
    [root@gend]# nmap 10.1.1.248 -p 10055
    PORT STATE SERVICE
    10055/tcp filtered unknown
    MAC Address: 00:21:5E:4E:72:4A (Unknown)

    Nmap finished: 1 IP address (1 host up) scanned in 0.294 seconds
    [root@gend]# nmap 10.1.1.248 -p 10055

    Starting Nmap 4.11 ( http://www.insecure.org/nmap/ ) at 2011-03-10 19:10 MSK
    PORT STATE SERVICE
    10055/tcp open unknown
    MAC Address: 00:21:5E:4E:72:4A (Unknown)

    Nmap finished: 1 IP address (1 host up) scanned in 0.093 seconds
    [root@gend]# nmap 10.1.1.248 -p 10055

    Starting Nmap 4.11 ( http://www.insecure.org/nmap/ ) at 2011-03-10 19:10 MSK
    PORT STATE SERVICE
    10055/tcp filtered unknown
    MAC Address: 00:21:5E:4E:72:4A (Unknown)

    Nmap finished: 1 IP address (1 host up) scanned in 0.299 seconds
    Mysql:
    long_query_time = 3

    # Time: 110311 10:23:08
    # User@Host: root[root] @ localhost []
    # Query_time: 37 Lock_time: 0 Rows_sent: 0 Rows_examined: 0
    update triggers set value=0,lastchange=1299828151,error='' where triggerid=100100000045875;
    # Time: 110311 10:28:14
    # User@Host: root[root] @ localhost []
    # Query_time: 8 Lock_time: 0 Rows_sent: 0 Rows_examined: 0
    delete from node_cksum where nodeid=2 and cksumtype=1;
    # Time: 110311 10:28:24
    # User@Host: root[root] @ localhost []
    # Query_time: 4 Lock_time: 0 Rows_sent: 0 Rows_examined: 33092
    insert into node_cksum (nodeid,tablename,recordid,cksumtype,cksum) select 2,'items',itemid,1,concat_ws(',',type,md5(snmp_com munity),md5(snmp_oid),snmp_port,hostid,md5(descrip tion
    ),md5(key_),delay,history,trends,status,value_type ,md5(trapper_hosts),md5(units),multiplier,delta,md 5(snmpv3_securityname),snmpv3_securitylevel,md5(sn mpv3_authpassphrase),md5(snm
    pv3_privpassphrase),md5(formula),md5(error),md5(lo gtimefmt),templateid,valuemapid,md5(delay_flex),md 5(params),md5(ipmi_sensor),data_type,authtype,md5( username),md5(password),md5(
    publickey),md5(privatekey)) from items where 1=1 and itemid between 200000000000000 and 299999999999999;
    # Time: 110311 10:28:39
    # User@Host: root[root] @ localhost []
    # Query_time: 11 Lock_time: 0 Rows_sent: 220540 Rows_examined: 2168950
    select curr.tablename,curr.recordid,prev.cksum,curr.cksum ,prev.sync from node_cksum curr, node_cksum prev where curr.nodeid=2 and prev.nodeid=curr.nodeid and curr.tablename=prev.
    tablename and curr.recordid=prev.recordid and curr.cksumtype=1 and prev.cksumtype=0 union all select curr.tablename,curr.recordid,prev.cksum,curr.cksum ,curr.sync from node_cksum
    curr left join node_cksum prev on prev.nodeid=curr.nodeid and prev.tablename=curr.tablename and prev.recordid=curr.recordid and prev.cksumtype=0 where curr.nodeid=2 and curr.cksu
    mtype=1 and prev.tablename is null union all select prev.tablename,prev.recordid,prev.cksum,curr.cksum ,prev.sync from node_cksum prev left join node_cksum curr on curr.nodeid=pre
    v.nodeid and curr.tablename=prev.tablename and curr.recordid=prev.recordid and curr.cksumtype=1 where prev.nodeid=2 and prev.cksumtype=0 and curr.tablename is null;
    # Time: 110311 10:28:40
    # User@Host: root[root] @ localhost []
    # Query_time: 33 Lock_time: 0 Rows_sent: 0 Rows_examined: 0
    update items set status=3,lastclock=1299828483,error='OID [1.3.6.1.4.1.2254.2.4.5.4.0] value has unknown type [0x05]' where itemid=100100000066041;
    # User@Host: root[root] @ localhost []
    # Query_time: 7 Lock_time: 0 Rows_sent: 0 Rows_examined: 0
    update items set status=3,lastclock=1299828497,error='OID [1.3.6.1.4.1.2254.2.4.4.7.0] value has unknown type [0x05]' where itemid=100100000066025;
    # User@Host: root[root] @ localhost []
    # Query_time: 21 Lock_time: 0 Rows_sent: 0 Rows_examined: 0
    update items set status=3,lastclock=1299828493,error='OID [1.3.6.1.4.1.2254.2.4.7.8.0] value has unknown type [0x05]' where itemid=100100000066019;
    # Time: 110311 10:29:23
    # User@Host: root[root] @ localhost []
    # Query_time: 32 Lock_time: 0 Rows_sent: 0 Rows_examined: 0
    update items set status=3,lastclock=1299828494,error='OID [1.3.6.1.4.1.2254.2.4.4.4.0] value has unknown type [0x05]' where itemid=100100000066024;
    # Time: 110311 10:32:38
    # User@Host: root[root] @ localhost []
    # Query_time: 14 Lock_time: 0 Rows_sent: 220540 Rows_examined: 2168950
    select curr.tablename,curr.recordid,prev.cksum,curr.cksum ,prev.sync from node_cksum curr, node_cksum prev where curr.nodeid=2 and prev.nodeid=curr.nodeid and curr.tablename=prev.
    tablename and curr.recordid=prev.recordid and curr.cksumtype=1 and prev.cksumtype=0 union all select curr.tablename,curr.recordid,prev.cksum,curr.cksum ,NULL from node_cksum curr
    left join node_cksum prev on prev.nodeid=curr.nodeid and prev.tablename=curr.tablename and prev.recordid=curr.recordid and prev.cksumtype=0 where curr.nodeid=2 and curr.cksumtype
    =1 and prev.tablename is null union all select prev.tablename,prev.recordid,prev.cksum,curr.cksum ,prev.sync from node_cksum prev left join node_cksum curr on curr.nodeid=prev.nod
    eid and curr.tablename=prev.tablename and curr.recordid=prev.recordid and curr.cksumtype=1 where prev.nodeid=2 and prev.cksumtype=0 and curr.tablename is null;
    Загруза CPU в аттаче

    Сервер:
    2 x Xeon(R) CPU E5420
    32 Gb RAM
    Диски SAS ( 10 рейд ), ну тут проблем не замечено ( await не больше 1 мл/c ), пробовали переносить базу на сторадж по Fibre Channel по 2-ум путям ( multipathd ).

    Пока меня только смущает long query в БД

    Еще смущает TCP стек:
    tcpdump -i eth0 host 10.5.20.1 -vv

    10:50:33.412045 IP (tos 0x0, ttl 64, id 46369, offset 0, flags [DF], proto: TCP (6), length: 77) 10.1.1.248.39739 > 10.5.20.1.zabbix-agent: P, cksum 0x2a3e (incorrect (-> 0xa4b9), 1:26(25) ack 1 win 46 <nop,nop,timestamp 44324371 3416468702>
    10:50:33.412430 IP (tos 0x0, ttl 63, id 39759, offset 0, flags [DF], proto: TCP (6), length: 52) 10.5.20.1.zabbix-agent > 10.1.1.248.39739: ., cksum 0xa217 (correct), 1:1(0) ack 26 win 91 <nop,nop,timestamp 3416468702 44324371>
    А именно cksum 0x2a3e (incorrect (-> 0xa4b9). Может сетевка болеет?
    Attached Files
  • costas
    Senior Member
    • Aug 2009
    • 201

    #2
    А листинг процессов во время загрузки смотрели? кто именно ложит cpu?
    CentOS-5.5 i386, Zabbix 1.8.4 (stable), MySQL 5.0.92, PHP 5.2.17 (cli)

    ...эта проверка бесполезная, вредная, и она зло.

    Comment

    • Yagel
      Junior Member
      • Mar 2011
      • 10

      #3
      Originally posted by costas
      А листинг процессов во время загрузки смотрели? кто именно ложит cpu?
      Mysql:
      top - 11:44:27 up 13:17, 2 users, load average: 2.74, 3.45, 3.32
      Tasks: 355 total, 2 running, 353 sleeping, 0 stopped, 0 zombie
      Cpu(s): 23.5%us, 0.3%sy, 10.0%ni, 66.1%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
      Mem: 32959540k total, 29908156k used, 3051384k free, 343744k buffers
      Swap: 16386292k total, 0k used, 16386292k free, 14999536k cached

      PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
      10477 mysql 15 0 18.3g 12g 5212 S 189.1 40.9 3020:55 mysqld

      В принципе ничего страшного пока в этом не вижу. Load average - нормальный, wait-ы тоже.
      Добиться меньшего CPU у меня получалось, поигравших с настройками количеством пуллов/трапперов zabbix-а, но картина таже.
      Last edited by Yagel; 11-03-2011, 10:50.

      Comment

      • ugh
        Senior Member
        • Jun 2009
        • 296

        #4
        а qps в момент кризиса и кол-во тредов отслеживали?

        # Query_time: 37 Lock_time: 0 Rows_sent: 0 Rows_examined: 0
        update triggers set value=0,lastchange=1299828151,error='' where triggerid=100100000045875;

        это нездорово

        Comment

        • Yagel
          Junior Member
          • Mar 2011
          • 10

          #5
          Originally posted by ugh
          а qps в момент кризиса и кол-во тредов отслеживали?

          # Query_time: 37 Lock_time: 0 Rows_sent: 0 Rows_examined: 0
          update triggers set value=0,lastchange=1299828151,error='' where triggerid=100100000045875;

          это нездорово
          Да посматриваю значения, только с помощью MySQL Administrator-ом.
          Max: 1795 Queries
          Avg: 689
          Current: 565

          [root@zabbix ~]# mysqladmin extended-status - root -p | grep Threads
          Enter password:
          mysqladmin: Unknown command: '-'
          | Threads_cached | 9 |
          | Threads_connected | 188 |
          | Threads_created | 197 |
          | Threads_running | 8 |

          Comment

          • Yagel
            Junior Member
            • Mar 2011
            • 10

            #6
            Вот к примеру во время housekeeper
            4844:20110311:123742.820 Executing housekeeper
            4844:20110311:123931.386 Deleted 446902 records from history and trends

            В long query:

            # Time: 110311 12:39:26
            # User@Host: root[root] @ localhost []
            # Query_time: 120 Lock_time: 0 Rows_sent: 284 Rows_examined: 295086393
            SELECT max(ht.hostid) as hostid, ht.templateid FROM( SELECT count(htt.templateid) as ccc, htt.hostid FROM hosts_templates htt WHERE htt.hostid NOT IN ( SELECT httt.templateid FROM hosts_templates httt ) GROUP BY htt.hostid ) ggg, hosts_templates ht WHERE ggg.ccc>1 AND ht.hostid=ggg.hostid GROUP BY ht.templateid;
            # User@Host: root[root] @ localhost []
            # Query_time: 107 Lock_time: 0 Rows_sent: 0 Rows_examined: 0
            UPDATE profiles SET value_str='20120301113735', type=3 WHERE userid=100100000000003 AND idx='web.item.graph.stime' AND ((profileid BETWEEN 100000000000000 AND 199999999999999)) AND idx2=100100000058145 AND ((idx2 BETWEEN 100000000000000 AND 199999999999999));
            # User@Host: root[root] @ localhost []
            # Query_time: 106 Lock_time: 0 Rows_sent: 0 Rows_examined: 0
            UPDATE profiles SET value_str='20120301113735', type=3 WHERE userid=100100000000003 AND idx='web.item.graph.stime' AND ((profileid BETWEEN 100000000000000 AND 199999999999999)) AND idx2=100100000058145 AND ((idx2 BETWEEN 100000000000000 AND 199999999999999));
            # User@Host: root[root] @ localhost []
            # Query_time: 106 Lock_time: 0 Rows_sent: 0 Rows_examined: 0
            UPDATE profiles SET value_str='20120301113735', type=3 WHERE userid=100100000000003 AND idx='web.item.graph.stime' AND ((profileid BETWEEN 100000000000000 AND 199999999999999)) AND idx2=100100000058145 AND ((idx2 BETWEEN 100000000000000 AND 199999999999999));
            # User@Host: root[root] @ localhost []
            # Query_time: 105 Lock_time: 0 Rows_sent: 0 Rows_examined: 0
            UPDATE profiles SET value_str='screens.php', type=3 WHERE userid=100100000000003 AND idx='web.menu.view.last' AND ((profileid BETWEEN 100000000000000 AND 199999999999999));
            # User@Host: root[root] @ localhost []
            # Query_time: 110 Lock_time: 0 Rows_sent: 0 Rows_examined: 0
            UPDATE profiles SET value_int=604800, type=2 WHERE userid=100100000000003 AND idx='web.item.graph.period' AND ((profileid BETWEEN 100000000000000 AND 199999999999999)) AND idx2=100100000058145 AND ((idx2 BETWEEN 100000000000000 AND 199999999999999));
            # User@Host: root[root] @ localhost []
            # Query_time: 108 Lock_time: 0 Rows_sent: 0 Rows_examined: 0
            UPDATE profiles SET value_int=77661, type=2 WHERE userid=100100000000003 AND idx='web.item.graph.period' AND ((profileid BETWEEN 100000000000000 AND 199999999999999)) AND idx2=100100000058145 AND ((idx2 BETWEEN 100000000000000 AND 199999999999999));
            Attached Files

            Comment

            • Yagel
              Junior Member
              • Mar 2011
              • 10

              #7
              В общем удалось снизить нагрузку cpu до 20%, удалось избавиться от медленных запросов. Очень плохо, что нет нормальных рекомендаций по нагрузке и параметрам настройки заббикса ( все описано условно ).

              Но в итоге проблема не решилась, через несколько часов сервер по прежнему перестает частично принимать данные ( на некоторых элементах задержка по часу ).

              Comment

              • Yagel
                Junior Member
                • Mar 2011
                • 10

                #8
                Если интересно - проблему вроде бы решили, уже 8 часов и полет нормальный. А проблема была в мониторинге одного лог файла.

                Comment

                • zalex_ua
                  Senior Member
                  Zabbix Certified Trainer
                  Zabbix Certified SpecialistZabbix Certified Professional
                  • Oct 2009
                  • 1286

                  #9
                  Originally posted by yagel
                  А проблема была в мониторинге одного лог файла.
                  А с этого момента расскажите поподробней пожалуйста.

                  Comment

                  • ugh
                    Senior Member
                    • Jun 2009
                    • 296

                    #10
                    интересно, поделитесь пожалуйста

                    Comment

                    • Yagel
                      Junior Member
                      • Mar 2011
                      • 10

                      #11
                      Originally posted by zalex_ua
                      А с этого момента расскажите поподробней пожалуйста.
                      Начали по аудиту отказываться и смотреть что менялось, за последнее время.

                      Добавлялся на мониторинг файл log["/opt/firebird/firebird.log"]. Собственно ничего такого там нету, через zabbix-proxy данный файл также собирается с других хостов ( за день максимум 100 строк ). Ну решили подкрутить
                      log["/opt/firebird/firebird.log",,,100]. И все заработало. Если сегодня дадут добро, попробую задебажить.
                      Last edited by Yagel; 14-03-2011, 07:08.

                      Comment

                      • Yagel
                        Junior Member
                        • Mar 2011
                        • 10

                        #12
                        Не помогло, опять таже ситуации. Хотя 2 дня проработало все на ура
                        Attached Files

                        Comment

                        • Yagel
                          Junior Member
                          • Mar 2011
                          • 10

                          #13
                          Элемент данных:

                          100100000076996

                          14.Мар.2011 13:41:06 84
                          14.Мар.2011 13:40:41 86
                          14.Мар.2011 13:35:43 83
                          14.Мар.2011 13:34:45 88
                          14.Мар.2011 13:34:33 86
                          21485:20110314:133909.032 In process_hist_data()
                          21443:20110314:133909.032 End of zbx_hashset_search()
                          21443:20110314:133909.032 In zbx_hashset_search()
                          21443:20110314:133909.032 End of zbx_hashset_search()
                          21485:20110314:133909.032 In process_mass_data()
                          21443:20110314:133909.032 In zbx_binary_heap_remove_min()
                          21485:20110314:133909.032 In DCinit_nextchecks()
                          21443:20110314:133909.032 In zbx_hashmap_remove() key:100100000057615
                          21443:20110314:133909.032 End of zbx_hashmap_remove()
                          21443:20110314:133909.032 In zbx_hashmap_set() key:100100000093465 value:0
                          21443:20110314:133909.032 End of zbx_hashmap_set()
                          21443:20110314:133909.032 In zbx_hashmap_set() key:100100000068611 value:2
                          21443:20110314:133909.032 End of zbx_hashmap_set()
                          21443:20110314:133909.032 In zbx_hashmap_set() key:100100000087945 value:2
                          21443:20110314:133909.032 End of zbx_hashmap_set()
                          21443:20110314:133909.032 In zbx_hashmap_set() key:100100000068611 value:6
                          21443:20110314:133909.032 End of zbx_hashmap_set()
                          21443:20110314:133909.032 In zbx_hashmap_set() key:100100000089085 value:6
                          21443:20110314:133909.032 End of zbx_hashmap_set()
                          21443:20110314:133909.032 In zbx_hashmap_set() key:100100000068611 value:13
                          21443:20110314:133909.032 End of zbx_hashmap_set()
                          21443:20110314:133909.032 In zbx_hashmap_set() key:100100000076996 value:13
                          21443:20110314:133909.032 End of zbx_hashmap_set()
                          21443:20110314:133909.032 In zbx_hashmap_set() key:100100000068611 value:27
                          21443:20110314:133909.032 End of zbx_hashmap_set()
                          21443:20110314:133909.032 In zbx_hashmap_set() key:100100000093346 value:27
                          21443:20110314:133909.032 End of zbx_hashmap_set()
                          21443:20110314:133909.032 In zbx_hashmap_set() key:100100000068611 value:56
                          21443:20110314:133909.032 End of zbx_hashmap_set()
                          21443:20110314:133909.032 In zbx_hashmap_set() key:100100000087947 value:56
                          21443:20110314:133909.032 End of zbx_hashmap_set()
                          21443:20110314:133909.032 In zbx_hashmap_set() key:100100000068611 value:113
                          21443:20110314:133909.032 End of zbx_hashmap_set()
                          21443:20110314:133909.032 In zbx_hashmap_set() key:100100000065990 value:113
                          21443:20110314:133909.032 End of zbx_hashmap_set()
                          21443:20110314:133909.032 In zbx_hashmap_set() key:100100000068611 value:228
                          21443:20110314:133909.033 End of zbx_hashmap_set()
                          21443:20110314:133909.033 In zbx_hashmap_set() key:100100000047153 value:228
                          21443:20110314:133909.033 End of zbx_hashmap_set()
                          21443:20110314:133909.033 In zbx_hashmap_set() key:100100000068611 value:457
                          21443:20110314:133909.033 End of zbx_hashmap_set()
                          21443:20110314:133909.033 In zbx_hashmap_set() key:100100000089881 value:457
                          21443:20110314:133909.033 End of zbx_hashmap_set()
                          21443:20110314:133909.033 In zbx_hashmap_set() key:100100000068611 value:915
                          21443:20110314:133909.033 End of zbx_hashmap_set()
                          21443:20110314:133909.033 In zbx_hashmap_set() key:100100000068888 value:915
                          21443:20110314:133909.033 End of zbx_hashmap_set()
                          21443:20110314:133909.033 In zbx_hashmap_set() key:100100000068611 value:1832
                          21443:20110314:133909.033 End of zbx_hashmap_set()
                          21443:20110314:133909.033 End of zbx_binary_heap_remove_min()
                          21443:20110314:133909.033 In zbx_hashset_search()
                          21443:20110314:133909.033 End of zbx_hashset_search()
                          21443:20110314:133909.033 In zbx_hashset_search()
                          21443:20110314:133909.033 End of zbx_hashset_search()
                          21443:20110314:133909.033 In zbx_hashset_search()
                          21443:20110314:133909.033 End of zbx_hashset_search()
                          21443:20110314:133909.033 In zbx_binary_heap_remove_min()
                          Не могу найти запрос в БД ( insert ).

                          Судя по сорцам: hashmap.c
                          Может уперся в #define CRIT_LOAD_FACTOR 5/1?
                          Что это за значение?

                          Comment

                          Working...