Overpass API developpement

[Roland Olbricht <>]

Hello,

> In the transaction.log file
> on the read_finished() start line there are lines such as:
>
> yyyy-mm-dd hh:mm:ss [124716] read_finished() start 3915 14484 14484
> yyyy-mm-dd hh:mm:ss [124716]  read_finished() start 78 278 226 52

In general, these lines help on the public instance to monitor resource
usage. Like most of the content of the transaction.log, it does not make
sense unless one is debugging or understanding a specific issue. The
values have historically been added to get insight as I have needed for
each situation.

> 2. Why sometimes 4 numbers and some times 3

I'm not sure about that one. In the log here, I see either four or five
entries. The nuber has risen with newer versions, thus this might be an
older version.

> 1. What do the numbers 3915, 144484, 14484 mean?

Normally, the first number is the client_token of the process. This is
the same as you can see on the public instance via /api/status. It is
used for the quota system, based on the IP adddress of the client and
can be safely ignored on private instances.

The second number is the number of read blocks. This gives an idea about
the disk activity of the process. These cannot be converted to bytes
because the blocks differ in size across different files. However, they
were an almost-perfect predictor of disk load in the time of harddisks
with inevitably high latency and do still somewhat help with SSDs.

The third number is the amount of userland processor time the process
has used. Fourth and fifth number are the processor user time for only
the statements query and print, as they have been the suspects of being
the biggest time consumers. That in turn is important to optimize speed.

> 3. Is it possible to estimate how long the query took from these numbers? Is
> the query runtime related to these numbers?

There are two other ways how to get a much more precise value:
- compute the difference between the "request_read_and_idx" and
"read_finished" of the process
- look it up in the logfile of the web server

Other than that, counters for disk and CPU are probably helpful to
estimate the wall cock time, but relatively imprecise.

> 4. Following the above type lines is:
> yyyy-mm-dd hh:mm:ss [2092] waited idle for 12 cycles.
> I assume 2092 is the main process. Is this 12 cycles a clue as to how long the
> query took?

No. This is another indicative check for me. There have been times where
the select call of some OSes had been unreliable. Select is a
self-declaration by a process to go asleep because nothing important is
happening. The process is then awakened for the kind of events it has
asked for. Time has been reliable in all cases, socket communication not
so. For that reason the dispatcher falls asleep for 10 to 100
milliseconds if no new messages have arrived and then looks again for
messages. That turned out to be cheap enough. The number for cycles is
the number of times the dispatcher has polled the kernel since the last
payload event.

> 5. During the main process idle:  are incoming requests pending? [I don't know
> if each query is handled serially]

No. Incoming processes are pending because the dispatcher performs load
shedding for the server.

Serial is for sure the wrong model for what is happening. The dispatcher
processes messages round robin unless there are no more messages to
process. I.e. in each cycle of the dispatcher, all processes that have
something to say are talked to.

However, the dispatcher may delay or refuse to give to a process a share
of runtime because there are already too many other requests of the same
client, or under higher load simply too many active concurrent processes
in total.

Best regards,

Roland