Opened 5 years ago

Last modified 15 months ago

#11573 assigned enhancement

Store pre-generated response parts in a database rather than in plain files

Reported by: karsten Owned by: metrics-team
Priority: Low Milestone:
Component: Metrics/Onionoo Version:
Severity: Normal Keywords:
Cc: wfn, tyseom Actual Points:
Parent ID: Points:
Reviewer: Sponsor:

Description

With #11350, we're almost crossing the line where keeping indexes in memory and contents on disk doesn't scale anymore. In the long term we should consider using a database to handle requests.

Child Tickets

Attachments (1)

requests.csv (342.8 KB) - added by karsten 4 years ago.
Requests taking more than 1 second, 2014-09-04 18:00:00 to 2014-09-05 06:00:00

Download all attachments as: .zip

Change History (13)

comment:1 Changed 5 years ago by karsten

Cc: wfn added

See wfn's comments on tweaking PostgreSQL: https://trac.torproject.org/projects/tor/ticket/11350#comment:2

comment:2 Changed 4 years ago by iwakeh

Just came across this older issue, hope it's not obsolete yet.

Without the hassle of having to tune a database one could first give sqlite a try.
Using the persistence api the switch to some "real" dbms would be easy.
sqlite claims at least better performance than file io solutions.

comment:3 Changed 4 years ago by karsten

Let's see. We do have some performance statistics now which we didn't have when this ticket was created.

Request statistics (2014-08-19 18:04:00, 3600 s):
  Total processed requests: 11371
  Most frequently requested resource: details (8372), weights (1759), bandwidth (1120)
  Most frequently requested parameter combinations: [lookup] (5015), [fingerprint] (3749), [lookup, fields] (2371)
  Matching relays per request: .500<2, .900<2, .990<8, .999<16384
  Matching bridges per request: .500<1, .900<1, .990<2, .999<16384
  Written characters per response: .500<2048, .900<16384, .990<32768, .999<16777216
  Milliseconds to handle request: .500<8, .900<16, .990<64, .999<128
  Milliseconds to build response: .500<4, .900<16, .990<512, .999<16384

The last two lines are most relevant here. "Handle request" means parsing a request with all parameters and looking up relays or bridges that should go into the response. "Build response" means taking a list of relay or bridge fingerprints and writing all JSON files from disk to the response.

.999<128 in the last but one line means that 99.9% of requests are handled in under 128 milliseconds. In fact, 128 is the next bigger power of two, it could also be less than 65 milliseconds. But this seems like a fine value to me.

However, .990<512 and .999<16384 in the last line worry me a bit. It means that the 0.9% of requests between 99% and 99.9% can take up to 16 seconds to build. And it's unclear from these data how much longer the slowest 0.1% take.

But before we replace the file system storage with a database, should we find out if it's really the file system that slows us down here? It could as well be the network that doesn't let us write bytes as fast as they're coming from disk. (And even if it's the file system, let's benchmark databases first before deciding on one.)

Want to write a patch to ResourceServlet's doGet() to obtain more meaningful statistics that tell us if we really want to mess with databases?

comment:4 Changed 4 years ago by iwakeh

You're right to carefully investigate the performance before changing anything.

I'll take a look at the ResourceServlet when trying Vagrant. That will have the additional benefit
for me of brushing up my knowledge about the onionoo protocol/ tor stats.

comment:5 Changed 4 years ago by iwakeh

It seems like the few longer response builds are the ones with really large output.
Probably requests without the limit parameter.

I added more detailed direct logging for longer processing times to PerformanceMetrics.

The patch is included with my logging patch in #12882 .

a log example:

2014-08-24 18:45:27 longer response building: 8616 ms for uptime params: [] and 6234523 chars.
2014-08-24 18:47:37 longer response building: 29151 ms for weights params: [] and 21760692 chars.
2014-08-24 18:48:43 longer response building: 3289 ms for bandwidth params: [] and 33954994 chars. 

comment:6 Changed 4 years ago by karsten

Your patch was merged together with the #12882 patch. I tweaked it a bit to log all requests taking more than 1 second in total and included three durations in the log message:

  • lookup: how long did it take to parse the request and look up relays and bridges to include in the response?
  • compile: how long did it take to read files from disk and compile a response string (this required a code change, because we're now writing into a local StringWriter first and then write the result into the response's PrintWriter)?
  • respond: how long did it take to send the response to the client?

I deployed the patched version on the production server and got statistics from the last 12 hours. Here's the summary:

                datetime        lookup           compile          respond      
 2014-09-04 18:27:12:  12   Min.   :   4.00   Min.   :   0.0   Min.   :     0  
 2014-09-05 03:27:14:  12   1st Qu.:  13.00   1st Qu.:  78.0   1st Qu.:  1129  
 2014-09-04 18:27:23:  11   Median :  15.00   Median :  89.0   Median :  1455  
 2014-09-04 21:27:34:  11   Mean   :  19.42   Mean   : 280.9   Mean   :  3713  
 2014-09-04 19:28:07:  10   3rd Qu.:  17.00   3rd Qu.: 111.0   3rd Qu.:  3772  
 2014-09-04 22:27:10:  10   Max.   :3021.00   Max.   :6071.0   Max.   :503809  
 (Other)            :6438                                                      
    document                              params         chars         
 details:1768   []                           :5060   Min.   :     213  
 summary:4670   [flag, type, running]        : 994   1st Qu.: 1437133  
 uptime :  30   [lookup, fields]             : 112   Median : 1437411  
 weights:  36   [fingerprint]                :  64   Mean   : 2487374  
                [type, running, fields]      :  49   3rd Qu.: 1437830  
                [flag, type, running, fields]:  46   Max.   :14389566  
                (Other)                      : 179                     

There are plenty of bottlenecks to analyze here, which I don't have the cycles for right now. I'm attaching the .csv file. Maybe you want to take a look?

Changed 4 years ago by karsten

Attachment: requests.csv added

Requests taking more than 1 second, 2014-09-04 18:00:00 to 2014-09-05 06:00:00

comment:7 in reply to:  6 ; Changed 4 years ago by iwakeh

  • It might be also interesting to look at the access log in terms of how many request were there at a given instance in time.
  • Response times could be longer if the connection of the client is slow, or not correctly terminated, or in case of too many concurrent session threads (that's why I asked about access logs). Too many concurrent sessions would slow down lookup and compile in addition.
  • Maybe, also separate the lookup and prepare measurements "physically" from the response times. Seperate lab-measurements for lookup and compile could be easily compared to db solutions. Seperate response time measuremnts in-vitro and in-lab might help identifying server issues.
  • Pondering the database question should not only be done b/c of performance reasons, but also in the light of what Onionoo serves. Many requests especially those using the history subtype are database concerns.Future requests (like #13137) too. Databases are made for that;
    • why reprogram the functionality? The reprogramming won't scale forever, and, what could turn out more difficult, is the code maintenance.
    • A highly optimized "query" on a proprietary in-memory index, might pose a problem when it needs to be extended/changed. An sql-query is way more readable, b/c the database takes care of optimization (of course one needs to define indexes and the like).

So, maybe just think about using a database anyway.

In this light I would not opt for sqllite anymore, but start with a reasonable gpl-db-system.

Last edited 4 years ago by iwakeh (previous) (diff)

comment:8 in reply to:  7 ; Changed 4 years ago by karsten

Replying to iwakeh:

  • It might be also interesting to look at the access log in terms of how many request were there at a given instance in time.

I just did a very quick analysis of access logs. In particular, I looked at number of requests coming in per minute. Here's the summary:

Min. : 539.0
1st Qu.: 728.5
Median : 781.0
Mean : 788.9
3rd Qu.: 849.0
Max. :1151.0

That's relatively stable load, I'd say.

  • Response times could be longer if the connection of the client is slow, or not correctly terminated, or in case of too many concurrent session threads (that's why I asked about access logs). Too many concurrent sessions would slow down lookup and compile in addition.

Agreed that response times depend to a large extent on the client connection. That's why I temporarily modified the code to separate compiling the response from sending it.

Regarding concurrent sessions, I could imagine measuring that in the code: whenever a new RequestHandler or ResponseBuilder instance is created we increment a counter, and whenever an instance is released we decrement that counter. For statistics, we print out what fraction of the time the counter was at 0, 1, 2, etc. The question is just what we'd do with these statistics. Maybe we should first resolve #13089 to see what options we'd have to fine-tune the server, for example, by changing thread pool sizes or something.

  • Maybe, also separate the lookup and prepare measurements "physically" from the response times. Seperate lab-measurements for lookup and compile could be easily compared to db solutions. Seperate response time measuremnts in-vitro and in-lab might help identifying server issues.

These steps are already separated: lookup is what RequestHandler does and compile+respond is what ResponseBuilder does. Should be pretty easy to measure these steps separately in a lab setting.

  • Pondering the database question should not only be done b/c of performance reasons, but also in the light of what Onionoo serves. Many requests especially those using the history subtype are database concerns.Future requests (like #13137) too. Databases are made for that;

Even with requests like #13137, we shouldn't give up the current model of performing queries based on a small substeps of attributes and putting together prepared response parts.

  • why reprogram the functionality? The reprogramming won't scale forever, and, what could turn out more difficult, is the code maintenance.
  • A highly optimized "query" on a proprietary in-memory index, might pose a problem when it needs to be extended/changed. An sql-query is way more readable, b/c the database takes care of optimization (of course one needs to define indexes and the like).

So, maybe just think about using a database anyway.

Agreed. I'm mostly thinking that it's not a priority to do this, but I don't question that using a database with good indexes is the better design.

In this light I would not opt for sqllite anymore, but start with a reasonable gpl-db-system.

Traditionally, there's a preference for PostgreSQL at Tor. Our sysadmins and devs have experience with that.

comment:9 in reply to:  8 Changed 4 years ago by iwakeh

Thanks, for the access/minute summary!

These steps are already separated: lookup is what RequestHandler does and compile+respond is what ResponseBuilder does. Should be pretty easy to measure these steps separately in a lab setting.

That's true.
And, you're right to postpone major testing of the server until after #13089.

Agreed. I'm mostly thinking that it's not a priority to do this, but I don't question that using a database with good indexes is the better design.

I understand. Onionoo is running fine, currently. No need to change it in a hurry.
Postgres ought to be fine.
Considering Onionoo's "document retrieval setup" it would also be interesting to look into
NoSQL databases. But, currently I have not a good idea about their performance.

I would like to keep performance measuring separate from the application itself.
As tomcat6 supports jmx and the considered embedded server ought as well,
an MBean (re-usable with the coming embedded server) would be nice. It could even be used for nagios monitoring.

(btw: The response time could be measured via the access log, cf. option %D and others here.
Of course, currently it is easier to log it in addition to the other values.)

comment:10 Changed 4 years ago by tyseom

Cc: tyseom added

comment:11 Changed 15 months ago by karsten

Severity: Normal
Summary: Ponder using a database for Onionoo rather than keeping indexes in memory and contents on diskStore pre-generated response parts in a database rather than in plain files

Attempt to write a better summary for this ticket.

comment:12 Changed 15 months ago by karsten

Owner: set to metrics-team
Status: newassigned
Note: See TracTickets for help on using tickets.