WORK IN PROGRESS - EXPECT BUGS
This tool is used to trace HTTP request paths from access logs, which can be useful when designing load tests or just figuring out how other people or systems are using a specific web service.
For example, we have the following dummy access log at examples/simple.log
:
2018-12-12T12:00:01.000Z 127.0.0.10:5000 "GET https://my-api/login" "Mozilla/5.0 USERAGENT 1"
2018-12-12T12:00:01.500Z 127.0.0.90:5000 "GET https://my-api/health" "httpkit"
2018-12-12T12:00:02.000Z 127.0.0.20:5000 "GET https://my-api/login" "Mozilla/5.0 USERAGENT 2"
2018-12-12T12:00:03.000Z 127.0.0.10:5000 "GET https://my-api/data" "Mozilla/5.0 USERAGENT 1"
2018-12-12T12:00:04.000Z 127.0.0.20:5000 "GET https://my-api/data" "Mozilla/5.0 USERAGENT 2"
2018-12-12T12:00:05.000Z 127.0.0.10:5000 "POST https://my-api/data" "Mozilla/5.0 USERAGENT 1"
2018-12-12T12:00:05.250Z 127.0.0.10:5000 "GET https://my-api/login" "Mozilla/5.0 USERAGENT 1"
2018-12-12T12:00:05.500Z 127.0.0.90:5000 "GET https://my-api/health" "httpkit"
2018-12-12T12:00:06.000Z 127.0.0.20:5000 "DELETE https://my-api/data" "Mozilla/5.0 USERAGENT 2"
2018-12-12T12:00:07.000Z 127.0.0.30:5000 "GET https://my-api/login" "Mozilla/5.0 USERAGENT 3"
2018-12-12T12:00:08.000Z 127.0.0.30:5000 "GET https://my-api/data" "Mozilla/5.0 USERAGENT 3"
2018-12-12T12:00:09.000Z 127.0.0.90:5000 "GET https://my-api/health" "httpkit"
Running the command below...
$ ./apathy -o examples/simple.dot examples/simple.log
...would produce the following dot
-formatted file in examples/simple.dot
:
digraph apathy_graph {
nodesep=1.0;
rankdir=LR;
ranksep=1.0;
subgraph s0 {
rank = same;
r0 [label="GET https://my-api/login\n(in 33.33% (4), out 75.00% (3))", fontsize=30, style=filled, fillcolor="#e2aaae", penwidth=4.309401];
r1 [label="GET https://my-api/health\n(in 25.00% (3), out 66.67% (2))", fontsize=28, style=filled, fillcolor="#d3c5eb", penwidth=4.000000];
}
subgraph s1 {
rank = same;
r2 [label="GET https://my-api/data\n(in 25.00% (3), out 66.67% (2))", fontsize=28, style=filled, fillcolor="#a6ffb9", penwidth=4.000000];
}
subgraph s2 {
rank = same;
r3 [label="POST https://my-api/data\n(in 8.33% (1), out 100.00% (1))", fontsize=22, style=filled, fillcolor="#c6e5e9", penwidth=3.154701];
r4 [label="DELETE https://my-api/data\n(in 8.33% (1), out 0.00% (0))", fontsize=22, style=filled, fillcolor="#9180b2", penwidth=3.154701];
}
r0 -> r2 [xlabel="37.50% (3)\n1.7s", fontsize=28, style="solid", color="#b4888b", fontcolor="#876668", penwidth=4.000000];
r1 -> r1 [xlabel="25.00% (2)\n3.8s", fontsize=25, style="dotted", color="#a89dbc", fontcolor="#7e768d", penwidth=3.632993];
r2 -> r3 [xlabel="12.50% (1)\n2.0s", fontsize=22, style="solid", color="#84cc94", fontcolor="#63996f", penwidth=3.154701];
r2 -> r4 [xlabel="12.50% (1)\n2.0s", fontsize=22, style="solid", color="#84cc94", fontcolor="#63996f", penwidth=3.154701];
r3 -> r0 [xlabel="12.50% (1)\n0.2s", fontsize=22, style="dashed", color="#9eb7ba", fontcolor="#76898b", penwidth=3.154701];
}
Now we can, for example, use the dot
tool from graphviz
to transform it into a PNG image:
$ dot -Tpng examples/simple.dot -o examples/simple.png
From the image we can observe at least the following facts:
- The most common call path is from
GET https://my-api/login
toGET https://my-api/data
, as that edge was taken 3 times. - Less common edges are from
GET https://my-api/data
toPOST https://my-api/data
andDELETE https://my-api/data
, and fromPOST https://my-api/data
back toGET https://my-api/login
. GET https://my-api/health
has been called 3 times, consisting of 2 repeats, so it's probably from a monitoring service.
Other notes:
- The more calls an endpoint has, the larger the node.
- The more hits an edge has, the thicker the line between two nodes.
- The
in
percentage tells how many of all the requests in the log ended up at that node, while the absolute count is in parentheses. - The
out
percentage tells how many of thein
requests continued to other nodes, while the absolute count is in parentheses. - The edge percentage tells how common that edge is in the whole log, with the absolute edge count in parentheses.
- Below the edge percentage is the average duration for that edge, in seconds.
- Edge lines from a lower depth node to an equal or higher depth node are solid, while those from a higher depth node to a lower depth one are dashed.
- Self-referential edge lines are dotted, as seen with the health endpoint.
- Nodes are grouped by their minimum call depth from left to right, so that nodes on the left tend to be the first to be called, while those on the right tend to occur deeper during each session.
The program constructs a session ID from each HTTP log entry, using the user agent and first IPv4 address by default. It uses this information to construct a call path for each session, after which we can generate a graph like above.
Compilation is tested only on Linux and OSX at the moment.
- Recent GCC or Clang
- Concurrency Kit
$ make clean all
See ./apathy --help
for command-line reference.
One of two variants below must be found:
- A single RFC3339-formatted timestamp field, with or without
millisecond precision
- examples:
2018-12-12T12:00:01.000Z
,2018-12-10T18:00:52
- examples:
- Separate date and time fields, where date is in
YYYY-MM-DD
format, and time is inHH:mm:SS
format.- example:
2018-12-12 12:00:01
- example:
One of the two fields below must be found:
- An IP address field, with or without a port suffix.
- examples:
127.0.0.1
,127.0.0.1:5000
- examples:
- A user agent string, enclosed by double quotes if it contains whitespace.
- example:
"Mozilla/5.0 ..."
- example:
One of the two variants must be found:
- A full request field, surrounded by double quotes, with the method and URL inside.
- example:
"GET https://my-api/v1/data?limit=50 ..."
- example:
- Separate method, protocol (optional), domain and endpoint fields.
- examples:
my-api.foo GET https /v1/data
- examples:
The program tries its best to infer what kind of field lies at each column, but might find multiple valid matches for a certain field.
For example, the line below:
2018-12-10 10:00:10 DUB2 615 127.0.0.1 GET foobar.cloudfront.net /login 200 Mozilla/5.0 id=user1 my-api.foo https HTTP/1.1
...has two valid indices for the domain field, being 7 (foobar.cloudfront.net
)
and 12 (my-api.foo
). In this case, you probably want to use the field
at index 12, so use the -i
/ --index
command line option to override
it:
$ ./apathy --index domain=12 $MY_LOG_FILE
If your log file contains endpoints that take path parameters, such as
UUIDs, then you probably want to combine their occurrences. You may do
this manually with a tool like sed
,
but you may also use the -T
/ --truncate-patterns
command line option
to point to a file, that contains the patterns you want to truncate.
For example, using the file at examples/truncate.txt
:
# Truncate UUIDs (this line is a comment)
$UUID = [0-9a-fA-F]{8}\-[0-9a-fA-F]{4}\-[0-9a-fA-F]{4}\-[0-9a-fA-F]{4}\-[0-9a-fA-F]{12}
...would merge the two following requests below:
GET https://my-api/token/37bd1951-91e0-43ea-a313-ba3074e46ec7/data/131b0ae8-b7df-4d4d-a35c-5b10d1948de3
GET https://my-api/token/1ccad17e-a51c-4a6b-9f35-d877f2bbd452/data/bcacc232-8173-4cf7-bc12-7591f9f686dd
...into this:
GET https://my-api/token/$UUID/data/$UUID
- query parameter session IDs
- IPv6
- ignore-patterns
- JSON output
- session listing
- tests