carbon-cache.py grinds to a halt

The default carbon cache size is "infinite". You can set a limit to bound
memory utilization but it would imply dropping metrics. Probably not what
you want for this type of historical import. Carbon cache is largely IO
bound. I suspect a check of iostat/sar or similar will likely display
elevated IO_WAIT times.

The high level suggestion i would make at this point is to rate limit your
input. I am happy to help with some more concrete suggestions if you can
provide additional context:

Are you able to rate limit the sending process or generally what level of
control do you have over this process?
If your ability to modify this sending process is limited, do you have
access to extract and format the data outside of the sending process?
What are your acceptable levels of utilization of memory/CPU/IO?
Aprox how many total data points per metric do you wish to import?
Aprox how many total metrics are you attempting to import?

 regards,

On Thu, Sep 8, 2011 at 3:35 AM, Dyna
<email address hidden>wrote:

> New question #170527 on Graphite:
> https://answers.launchpad.net/graphite/+question/170527
>
> I'm submitting old data into graphite. There is five data points collected
> each five minutes. We have a text based archive of the data which I'm
> parsing and sending to the carbon-cache daemon. It starts a-ok but when I've
> submitted a two years worth of data the daemon grind to a halt, eating up
> 75% of the memory of the box (messured in top) with only 2% of the CPU
> activity. It's a bog standard settings of carbon-cache nothing changed.. and
> it's the lates release i.e. graphite-web-0.9.8
>
> Cheers
>
> --
> You received this question notification because you are a member of
> graphite-dev, which is an answer contact for Graphite.
>
> _______________________________________________
> Mailing list: https://launchpad.net/~graphite-dev
> Post to : <email address hidden>
> Unsubscribe : https://launchpad.net/~graphite-dev
> More help : https://help.launchpad.net/ListHelp
>

--

regards,

Chris Brinley
Cleartrial

e: <email address hidden>
p: 312-460-3038
m: 219-789-2811

Hi

Thanks for you answer:

Metrics:

8 different metics:
cpu, user cpu, system cpu, context switch, disk usage, write rate kb, read rate kb, mem usage

The metrics are in a csv file, one line each five (5) minutes (this is std extract data from HP-UX).

I'm reading each line then sending it like this:

           lines.append("server.hpux.%s.global.cpu %s %s" % (server, CPU, EPOC))
           lines.append("server.hpux.%s.global.system_cpu %s %s" % (server, SCPU, EPOC))
           lines.append("server.hpux.%s.global.user_cpu %s %s" % (server, UCPU, EPOC))
           lines.append("server.hpux.%s.global.context_switch %s %s" % (server, CSWI, EPOC))
           lines.append("server.hpux.%s.global.disk %s %s" % (server, DISK, EPOC))
           lines.append("server.hpux.%s.global.read_rate_kb %s %s" % (server, READ, EPOC))
           lines.append("server.hpux.%s.global.write_rate_kb %s %s" % (server, WRITE, EPOC))
           lines.append("server.hpux.%s.global.mem %s %s" % (server, MEM, EPOC))
           message = '\n'.join(lines) + '\n
           ......
           sock.sendall(message)

I do this in a loop sending it as fast as I can, it's not very fast even when I start it from scratch (I can see this since I write a little dot for each line sent).

I've installed carbon/graphite on two server so I can compare, both are running the latest update of RHEL 5

Server1:

VMware virtual server: 500MB mem and 1CPU allocated, the hosting VMware server is a DL380G5 4GB RAM 1 CPU with about 10 virtual server running at the same time (I expect this server to be slow)

Server2:
Is a real box DL360G5 (Dual CPU) with 8GB of RAM (I expect this box to be fast since it has loads of mem and loads of CPU resourses compared to the other one).

Here is my findings so far.

Visually I don't see any difference in commit rate, they are both slow, and looking at the listner log it's about 1.5 commits per second when they start with fresh database files. In my test yesterday Server2 grided to a halt after just 50 min of importing the data, it had then eaten up 75% of the mem and didn't listen to kill signals (i.e. carbon-cache.py stop). However if you do kill the commit process exporting the data carbon-cache.py will wake up after a little while (2-10 min) complaing it lost connection with the other end.

What was even funnier is that the Server1 continued to work until late last evening.. then you see random hangs like this:

09/09/2011 06:09:02 :: [listener] MetricLineReceiver connection with 10.102.246.140:60858 established
09/09/2011 06:09:02 :: [listener] MetricLineReceiver connection with 10.102.246.140:60857 closed cleanly
09/09/2011 06:09:03 :: [listener] MetricLineReceiver connection with 10.102.246.140:60859 established
09/09/2011 06:21:03 :: [listener] MetricLineReceiver connection with 10.102.246.140:60858 closed cleanly
09/09/2011 06:21:04 :: [listener] MetricLineReceiver connection with 10.102.246.140:61511 established
09/09/2011 06:21:04 :: [listener] MetricLineReceiver connection with 10.102.246.140:60859 closed cleanly
09/09/2011 06:21:04 :: [listener] MetricLineReceiver connection with 10.102.246.140:61512 established
09/09/2011 06:21:04 :: [listener] MetricLineReceiver connection with 10.102.246.140:61511 closed cleanly
09/09/2011 06:21:05 :: [listener] MetricLineReceiver connection with 10.102.246.140:61513 established

It looks like the hang of the carbon-cache.py is pretty random. It doesn't look like it's a server size issue, reason being that the server with very low resourses continued to work until late last evening while it only too 50 min or so for the beefy one to hang.

I say this is some sort of bug either in the program or in my config or possibly in the program that commits. Commiting five data points every second is not much load any system should be able to handle that. It's also an issue of that when I commit the CPU spikes at nearly 100%, and that for ~300-450 metics in a minute???

I'm aware of the MAX_CACHE_SIZE = inf, (althugh I've not digged deep enough to see how it's parsed so I don't know if I can limit it like this MAX_CACHE_SIZE = 1GB). However the MAX_UPDATES_PER_SECOND = 1000 indicates to be that my 1 update per second should be childs play ;)..

I'm attaching my program that submits the data and I'm now about to pickle it to see if that solves the problem. Sorry for the poor python programming..

Cheers Dyna

----

#!/usr/bin/python

import getopt
import sys
import time
import os
import platform
import csv
from socket import socket

CARBON_SERVER = 'ldn4lin15.ebrd.com'
CARBON_PORT = 2003

def usage():
    print "Usage\n"

def main():
    try:
        opts, args = getopt.getopt(sys.argv[1:], "hfs:v", ["help", "file=", "server="])
    except getopt.GetoptError, err:
        # print help information and exit:
        #print str(err) # will print something like "option -a not recognized"
        usage()
        sys.exit(2)
    message = None
    file = None
    server = None
    epoc = 0
    verbose = False
    for o, a in opts:
        if o == "-v":
            verbose = True
        elif o in ("-h", "--help"):
            usage()
            sys.exit()
        elif o in ("-f", "--file"):
            file = a
        elif o in ("-s", "--server"):
            server = a
        else:
            assert False, "unhandled option"
    if file == None or server == None:
        usage()
        sys.exit(2)
    print ("Sending global stats file %s from server %s \n" % (file, server))

    infile = open(file, "rb")
    try:
        infile = open(file, "rb")
    except IOError:
        sys.exit(2)

    reader = csv.reader(infile)
    rownum = 0
    version = 0
    dot = 0
    lines = []
    for row in reader:
        if rownum == 1:
           #print ("%s,%s,%s,%s,%s" % (row[0],row[1],row[2],row[3],row[4]))
           if row[1] == "Cache ":
                #print "Version 1\n"
                version = 1
           elif (row[1] == "Cache Mem") and (row[6] != " Phys "):
                #print "Version 2\n"
                version = 2
           elif row[6] == " Phys ":
                #print "Version 3\n"
                version = 3
           else:
                version=4
        if rownum >= 3 and version == 1:
           EPOC=int(time.mktime(time.strptime(row[0], '%m/%d/%Y %H:%M'))) - time.timezone
           CMHIT=row[1]
           SCPU=row[2]
           UCPU=row[3]
           CSWI=row[4]
           DISK=row[5]
           SWAP=row[6]
           MEM=row[7]

           lines.append("server.hpux.%s.global.cache_mem_hit %s %s" % (server, CMHIT, EPOC))
           lines.append("server.hpux.%s.global.system_cpu %s %s" % (server, SCPU, EPOC))
           lines.append("server.hpux.%s.global.user_cpu %s %s" % (server, UCPU, EPOC))
           lines.append("server.hpux.%s.global.context_swith %s %s" % (server, CSWI, EPOC))
           lines.append("server.hpux.%s.global.disk %s %s" % (server, DISK, EPOC))

        if rownum >= 3 and version == 2:
           EPOC=int(time.mktime(time.strptime(row[0], '%m/%d/%Y %H:%M:%S'))) - time.timezone
           CMHIT=row[1]
           CPU=row[2]
           SCPU=row[3]
           UCPU=row[4]
           CSWI=row[5]
           DISK=row[6]
           SWAP=row[7]

           lines.append("server.hpux.%s.global.cache_mem_hit %s %s" % (server, CMHIT, EPOC))
           lines.append("server.hpux.%s.global.cpu %s %s" % (server, CPU, EPOC))
           lines.append("server.hpux.%s.global.system_cpu %s %s" % (server, SCPU, EPOC))
           lines.append("server.hpux.%s.global.user_cpu %s %s" % (server, UCPU, EPOC))
           lines.append("server.hpux.%s.global.context_swith %s %s" % (server, CSWI, EPOC))
           lines.append("server.hpux.%s.global.disk %s %s" % (server, DISK, EPOC))
           lines.append("server.hpux.%s.global.swap %s %s" % (server, SWAP, EPOC))

        if rownum >= 3 and version == 3:
           EPOC=int(time.mktime(time.strptime(row[0], '%m/%d/%Y %H:%M:%S'))) - time.timezone
           CMHIT=row[1]
           CPU=row[2]
           SCPU=row[3]
           UCPU=row[4]
           CSWI=row[5]
           PIOR=row[6]
           DISK=row[7]

           lines.append("server.hpux.%s.global.cache_mem_hit %s %s" % (server, CMHIT, EPOC))
           lines.append("server.hpux.%s.global.cpu %s %s" % (server, CPU, EPOC))
           lines.append("server.hpux.%s.global.system_cpu %s %s" % (server, SCPU, EPOC))
           lines.append("server.hpux.%s.global.user_cpu %s %s" % (server, UCPU, EPOC))
           lines.append("server.hpux.%s.global.context_swith %s %s" % (server, CSWI, EPOC))
           lines.append("server.hpux.%s.global.phys_io_rate %s %s" % (server, PIOR, EPOC))
           lines.append("server.hpux.%s.global.disk %s %s" % (server, DISK, EPOC))

        if rownum >= 2 and version == 4:
           #EPOC=row[0]
           EPOC=int(time.mktime(time.strptime(row[0], '%m/%d/%Y %H:%M:%S'))) - time.timezone
           CPU=row[1]
           SCPU=row[2]
           UCPU=row[3]
           CSWI=row[4]
           DISK=row[5]
           READ=row[6]
           WRITE=row[7]
           MEM=row[8]

           lines.append("server.hpux.%s.global.cpu %s %s" % (server, CPU, EPOC))
           lines.append("server.hpux.%s.global.system_cpu %s %s" % (server, SCPU, EPOC))
           lines.append("server.hpux.%s.global.user_cpu %s %s" % (server, UCPU, EPOC))
           lines.append("server.hpux.%s.global.context_swith %s %s" % (server, CSWI, EPOC))
           lines.append("server.hpux.%s.global.disk %s %s" % (server, DISK, EPOC))
           lines.append("server.hpux.%s.global.read_rate_kb %s %s" % (server, READ, EPOC))
           lines.append("server.hpux.%s.global.write_rate_kb %s %s" % (server, WRITE, EPOC))
           lines.append("server.hpux.%s.global.mem %s %s" % (server, MEM, EPOC))

        if lines:
           message = '\n'.join(lines) + '\n'
           #print message
           if dot == 70:
              dot = 0
              print ".\n",
           else:
              dot = dot + 1
              print ".",
           sock = socket()
           try:
              sock.connect( (CARBON_SERVER,CARBON_PORT) )
           except:
              print "Couldn't connect to %(server)s on port %(port)d, is carbon-agent.py running?" % { 'server':CARBON_SERVER, 'port':CARBON_PORT }
              sys.exit(1)

           sock.sendall(message)
           sock.close()
        rownum = rownum + 1

if __name__ == "__main__":
    main()

Ah forgot a few things:

>Are you able to rate limit the sending process or generally what level of
>control do you have over this process?

I've total control of that one, later on when we swith to feed live data I assume it will be less of control. But this is just a test, it's easy to import data.

>If your ability to modify this sending process is limited, do you have
>access to extract and format the data outside of the sending process?

Yes I can limit it, just put a wait stage and I can say send 10 data points evey minute, but that would really cut the mustard.

>What are your acceptable levels of utilization of memory/CPU/IO?
Well I don't expec the process to eat all my mem. If so I don't fancy creating swap mem since the only thing that will happen is that the box will start to swap and come to a crawl. A cach is a-ok but you really need to be able to set it level say 50% of the RAM. It's should be an abolute priority to flush write data to disk as fast as possible, when you start getting close to your limit. Submitting eight datapoints a second from one server should not use 99% of the CPU, rather just a few%. When you start feeding data from 100 servers, then you I could see util of mem and cpu being very high.

Aprox how many total data points per metric do you wish to import?
It's as said eight datapoints every five minutes for five years..

Cheers Dyna

PS: Sorry for my typos it's not easy to type with a big bandage..

Hey Dyna,
Didn't want to leave you hanging out there without some feedback.
I definitely want to help look into this but I am going to be pretty tied up
today with my day job :). I'll try to review this info later in the evening
and see where we can go from here.

Thanks for the in depth response!
regards,

On Fri, Sep 9, 2011 at 3:50 AM, Dyna
<email address hidden>wrote:

> Question #170527 on Graphite changed:
> https://answers.launchpad.net/graphite/+question/170527
>
> Dyna gave more information on the question:
> Ah forgot a few things:
>
> >Are you able to rate limit the sending process or generally what level of
> >control do you have over this process?
>
> I've total control of that one, later on when we swith to feed live data
> I assume it will be less of control. But this is just a test, it's easy
> to import data.
>
> >If your ability to modify this sending process is limited, do you have
> >access to extract and format the data outside of the sending process?
>
> Yes I can limit it, just put a wait stage and I can say send 10 data
> points evey minute, but that would really cut the mustard.
>
> >What are your acceptable levels of utilization of memory/CPU/IO?
> Well I don't expec the process to eat all my mem. If so I don't fancy
> creating swap mem since the only thing that will happen is that the box will
> start to swap and come to a crawl. A cach is a-ok but you really need to be
> able to set it level say 50% of the RAM. It's should be an abolute priority
> to flush write data to disk as fast as possible, when you start getting
> close to your limit. Submitting eight datapoints a second from one server
> should not use 99% of the CPU, rather just a few%. When you start feeding
> data from 100 servers, then you I could see util of mem and cpu being very
> high.
>
> Aprox how many total data points per metric do you wish to import?
> It's as said eight datapoints every five minutes for five years..
>
> Cheers Dyna
>
> PS: Sorry for my typos it's not easy to type with a big bandage..
>
> --
> You received this question notification because you are a member of
> graphite-dev, which is an answer contact for Graphite.
>
> _______________________________________________
> Mailing list: https://launchpad.net/~graphite-dev
> Post to : <email address hidden>
> Unsubscribe : https://launchpad.net/~graphite-dev
> More help : https://help.launchpad.net/ListHelp
>

--

regards,

Chris Brinley
Cleartrial

e: <email address hidden>
p: 312-460-3038
m: 219-789-2811

Dyna, the listener log is showing you how frequently clients are connecting to carbon. So its processing 1.5 connections per second , which is just how fast your clients must be connecting to it. Look at the updates.log to see how fast it is writing datapoints to disk.

The best thing to do is to figure out where the bottleneck is specifically. You mention the CPU usage spikes to 100% when you send a batch of data, that is somewhat expected but it should be very short-lived, if CPU usage is consistently high there may be some other problem going on. If CPU usage is not consistently high I would expect the bottleneck to be I/O utilization, what does iostat show? If the disk is more than 50% utilized I would advise setting MAX_UPDATES_PER_SECOND to something lower like 500, the default of 1000 is too high for most systems and is going to be lower in the next release. It turns out that trying to write too quickly can cause worse performance than relying more on buffering.

Thank all of you trying to help!!

The problem was a bug on my side (yes I'm in the corner and ashamed). I didn't delete the line array and basically I sent the old data over and over, building it up as I parsed the data. What looked like a few updates per second was in fact 30000 updates per second at the very end when it grinded to a halt....

Now back to trying to pickle the data don't really get that one to work....

Cheers Dyna