I've been playing with this and querying seems fundamentally broken. I've built from db39e42 and have been sending data with netcat
. I get a strange issue where characters from log lines overwrite characters in other log lines.
Here's a quick and nasty script to demonstrate:
pkill vmstorage
pkill vmselect
pkill vminsert
sleep 5
rm -rf vmstorage-data/
nohup bin/vmstorage > vmstorage.log 2>&1 &
nohup bin/vmselect -storageNode 127.0.0.1:8401 > vmselect.log 2>&1 &
nohup bin/vminsert -storageNode 127.0.0.1:8400 -importerListenAddr 127.0.0.1:2003 > vminsert.log 2>&1 &
sleep 30
echo 'loki{foo="bar"} "The course of true love never did run smooth."' | nc -vN 127.0.0.1 2003
sleep 1
curl -s http://127.0.0.1:8481/select/0/loki/api/v1/query_range --data-urlencode 'query={foo="bar"}' --data-urlencode 'step=60' | jq
echo 'loki{foo="bar"} "All that glisters is not gold."' | nc -vN 127.0.0.1 2003
sleep 2
curl -s http://127.0.0.1:8481/select/0/loki/api/v1/query_range --data-urlencode 'query={foo="bar"}' --data-urlencode 'step=60' | jq
echo 'loki{foo="bar"} "Whats in a name? That which we call a rose By any other name would smell as sweet."' | nc -vN 127.0.0.1 2003
sleep 3
curl -s http://127.0.0.1:8481/select/0/loki/api/v1/query_range --data-urlencode 'query={foo="bar"}' --data-urlencode 'step=60' | jq
echo 'loki{foo="bar"} "Once more unto the breach, dear friends, once more, Or close the wall up with our English dead!"' | nc -vN 127.0.0.1 2003
sleep 4
curl -s http://127.0.0.1:8481/select/0/loki/api/v1/query_range --data-urlencode 'query={foo="bar"}' --data-urlencode 'step=60' | jq
echo 'loki{foo="bar"} "By the pricking of my thumbs, Something wicked this way comes. Double, double toil and trouble; Fire burn, and cauldron bubble."' | nc -vN 127.0.0.1 2003
sleep 5
curl -s http://127.0.0.1:8481/select/0/loki/api/v1/query_range --data-urlencode 'query={foo="bar"}' --data-urlencode 'step=60' | jq
echo 'loki{foo="bar"} "log log log log"' | nc -vN 127.0.0.1 2003
curl -s http://127.0.0.1:8481/select/0/loki/api/v1/query_range --data-urlencode 'query={foo="bar"}' --data-urlencode 'step=60' | jq
sleep 15
curl -s http://127.0.0.1:8481/select/0/loki/api/v1/query_range --data-urlencode 'query={foo="bar"}' --data-urlencode 'step=60' | jq
The expected final response is 5 Shakespeare quotes and the line "log log log log" but what we actually get is:
{
"status": "success",
"data": {
"resultType": "streams",
"result": [
{
"stream": {
"__name__": "loki",
"foo": "bar"
},
"values": [
[
"1606968840550000000",
"By the pricking of my thumbs, Something wicke"
],
[
"1606968841583000000",
" this way comes. Double, doubl"
],
[
"1606968843619000000",
" toil and trouble; Fire burn, and cauldron bubble.\u000flog log log log smell as sweet."
],
[
"1606968846650000000",
"Once more unto the breach, dear friends, once more, Or close the wall up with our English dead!"
],
[
"1606968850686000000",
"By the pricking of my thumbs, Something wicked this way comes. Double, double toil and trouble; Fire burn, and cauldron bubble."
],
[
"1606968855719000000",
"log log log log"
]
]
}
]
}
}
You'll notice that my "log" messages are truncated, repeating, missing and (most surprising of all, "log log log log"
is overlaid over the top of (half) a Shakespeare quote: "toil and trouble; Fire burn, and cauldron bubble.\u000flog log log log smell as sweet."
If you review the output of vminsert
(e.g with tail vminsert.log
), there was no problems reported writing the logs (e.g I've seen missing a end quote char will correctly return an error about being unable to umarshal.)
In Grafana, it looks like this (now-15m to now
):
Furthermore, if I change the Time Range in Grafana, entire log lines disappear:
now-1h to now
:
Note: There are less lines than above!
now-6h to now
:
Note There are even less lines than above!