goaccess icon indicating copy to clipboard operation
goaccess copied to clipboard

docker-compose - reading gz logs + normal logs?

Open rwjack opened this issue 2 years ago • 2 comments

Hello,

I'm trying to read .gz and regular traefik logs while running goaccess inside docker-compose, but I can't seem to figure out a way to accomplish this.

docker-compose.yml

version: "3"

volumes:
  data:
  report:

services:
  nginx:
    image: nginx:latest
    restart: unless-stopped

    container_name: goaccess-nginx
    hostname: goaccess-nginx

    ports:
      - "10000:80"

    volumes:
      - report:/usr/share/nginx/html:ro

    depends_on:
      - goaccess

  goaccess:
    image: allinurl/goaccess:latest
    restart: unless-stopped
    entrypoint: sh
    command: -c 'zcat /srv/traefik-logs/access.log.*.gz | goaccess -'
    #command: -f /srv/traefik-logs/access.log

    container_name: goaccess
    hostname: goaccess

    volumes:
      - ./goaccess.conf:/etc/goaccess/goaccess.conf:ro
      - /mnt/traefik-logs/:/srv/traefik-logs/:ro
      - data:/srv/data
      - report:/srv/report

So the idea is -

  • First import gz logs with the current docker-compose layout
  • And then run only with the second command field (without entrypoint and first command), so goaccess reads existing gz logs and then stays online reading the actual logs.

goaccess.conf:

origin https://local.domain
ws-url wss://local.domain:443/live
log-format %h %^[%d:%t %^] "%r" %s %b "%R" "%u" %^ "%v" "%^" %Tms
date-format %d/%b/%Y
time-format %T
output /srv/report/index.html
db-path /srv/data
persist true
restore true
real-time-html true

Doing the following commands on my debian desktop gives me 2M total requests. First command yields 1.1M, the second one adds another 0.9M.

zcat logs/access.log.*.gz | goaccess -p ./goaccess.conf -
goaccess -p ./goaccess.conf -f logs/access.log

This doesn't make sense for the following reason - All logs should be around 5.69M requests. Unfortunately when goaccess parses only .gz logs (first command), the number of requests shown on the output report is 1.1M. Strangely when I do the second command, which should only parse access.log, it adds another 0.9M, instead of 0.57M - Which is the actual amount of requests in access.log

image

Commenting out #real-time-html true, parses the gz logs correctly for some reason: (5.7M)

image

Yeah and same for the regular access.log (0.57M)

image

Man, fuck this flag I'm legit busting my balls for the past 6 hours testing and documenting all this just for it to work now. Fuck.

Running docker-compose up -d with the first command (which should yield the same output as on my host) only parses 79k requests, which makes absolutely 0 sense. You'd think it perhaps parsed a single log, but that doesn't seem to be the case. image

All in all, I'm simply trying to read week old logs which are in gz format, just to save them to the goaccess db, and after that keep goaccess running as a container and keep parsing logs from access.log regularly, though I also don't understand how often does it automatically re-parse the current file for updates?

And also, how would this be best implemented with logrotate, since access.log rotates daily. Perhaps force an access.log parse before rotating?

rwjack avatar Jun 02 '22 20:06 rwjack

Workaround:

docker-compose.yml

  goaccess:
    image: allinurl/goaccess
    restart: unless-stopped
    entrypoint: /entrypoint.sh

    volumes:
      - /etc/timezone:/etc/timezone:ro
      - /etc/localtime:/etc/localtime:ro
      - ./entrypoint.sh:/entrypoint.sh:ro
      - ./read.sh:/read.sh:ro
      - ./conf:/srv/conf:ro
      - /mnt/traefik-logs/:/srv/traefik-logs/:ro
      - data:/srv/data
      - report:/srv/report

entrypoint.sh

#!/usr/bin/env sh

sh read.sh | egrep -v "whatever|filtering|you|want" | goaccess -p /srv/conf/default.conf --db-path /srv/data/global -o /srv/report/global/index.html  -

sleep 15m

read.sh

#!/usr/bin/env sh

for file in /srv/traefik-logs/*; do
    if [ $(basename "$file") == "access.log" ]; then
        cat "$file"
    else
        zcat "$file"
    fi
done

rwjack avatar Aug 17 '22 08:08 rwjack

Awesome, thanks a lot for sharing those findings.

allinurl avatar Aug 17 '22 16:08 allinurl

Hey, this does not work as I expected it to. It keeps accumulating logs and adding them together, instead of skipping ones already added.

Eg. access.log - 5 requests access.log.1.gz - 10 requests delete all db files -> run container -> report says: 15 total requests (as it should be)

When this container entrypoint.sh runs again in 24 hours: 30 requests When this container entrypoint.sh runs again in 48 hours: 45 requests ^ If we take the assumption that no logs were made in these 48 hours ^

Not sure if I'm explaining this correctly, but it seems I'm somehow just compounding everything instead of ignoring existing logs in the db.

rwjack avatar Dec 02 '22 12:12 rwjack

And something seems very odd, since I'm doing it like this, and it just keeps incrementing the logs every time it runs (every 30 seconds for about ~+2500 requests), which makes no sense since the logs are test files which don't change in content.

docker-compose.yml:

 goaccess:
    image: allinurl/goaccess:latest
    restart: unless-stopped
    entrypoint: /entrypoint.sh

    container_name: goaccess-test
    hostname: goaccess-test

    volumes:
      - /etc/timezone:/etc/timezone:ro
      - /etc/localtime:/etc/localtime:ro
      - ./entrypoint.sh:/entrypoint.sh:ro
      - ./read.sh:/read.sh:ro
      - ./conf:/srv/conf:ro
      - /mnt/traefik-logs/:/srv/traefik-logs/:ro
      - data-test:/srv/data
      - report-test:/srv/report

global.conf:

log-format %h %^[%d:%t %^] "%r" %s %b "%R" "%u" %^ "%v" "%^" %Tms
date-format %d/%b/%Y
time-format %T

persist true
restore true

keep-last 2
hour-spec min

read.sh:

#!/usr/bin/env sh

cat /srv/traefik-logs/test.log

zcat /srv/traefik-logs/test.log.1.gz

entrypoint.sh:

#!/bin/sh

for service in global; do
    if [ ! -d /srv/data/$service ]; then
        mkdir /srv/data/$service
    fi

    if [ ! -d /srv/report/$service ]; then
        mkdir /srv/report/$service
    fi


    case $service in
        global)
            sh read.sh | goaccess -p /srv/conf/default.conf --db-path /srv/data/global -o /srv/report/global/index.html  -
            ;;

    esac
done

sleep 30s

rwjack avatar Dec 02 '22 12:12 rwjack

So a simplified version of what I'm looking for is:

zcat access.log.*.gz | goaccess # create the report from all logs

cat access.log | goaccess --real-time-html # and continue reading from the active access.log, and append to the same db

Is this doable?

rwjack avatar Dec 02 '22 12:12 rwjack

I can't seem to figure out a way to juggle gz + regular files, without missing something in the report.

If I first read all gz files and persist them, and then tail -f and restore+persist the access.log file, Then the final report misses 100% of the access.log file, minus 10 lines of the tail -f command, excluding all future output.

If I first read all gz files + access.log and persist them and then tail -f and restore+persist the access.log file, Then the final report has duplicate 10 log entries of the tail -f command

Ah, so while writing this a solution came to my mind: If I first read all gz files + access.log and persist them and then tail -f -n0 and restore+persist the access.log file, I should have a report with non duplicate entries, and continued live reporting?

rwjack avatar Dec 02 '22 14:12 rwjack

Ugh, I busted my balls, but this might be a decent solution:

docker-compose.yml:

version: "3"

volumes:
  data:
  report:
  dangling-volume:

services:
  goaccess:
    image: allinurl/goaccess:latest
    restart: unless-stopped
    entrypoint: /entrypoint.sh

    container_name: goaccess
    hostname: goaccess

    ports:
      - "20000:20000"
      - "20001:20001"
      # etc...

    volumes:
      - ./read.sh:/read.sh:ro
      - ./conf:/srv/conf:ro
      - /traefik-logs/:/srv/traefik-logs/:ro
      - data:/srv/data
      - report:/srv/report
      - dangling-volume:/var/www/goaccess
      - /etc/timezone:/etc/timezone:ro
      - /etc/localtime:/etc/localtime:ro
      - ./entrypoint.sh:/entrypoint.sh:ro

read.sh:

#!/usr/bin/env sh

#for file in $(find "$log_dir" -type f -name "access.log.*.gz" -printf "%T+\t%p\n" | sort | awk '{print $2}'); do # no -printf on busybox wtf
for file in $(find "$log_dir" -type f -name "access.log*.gz" -exec stat -c "%Y %n" {} \; | sort | awk '{print $2}'); do
    zcat "$file"
done

cat "$log_dir"/access.log

entrypoint.sh:

#!/bin/sh

## find out how to persist gz logs and continue reading new ones
# first read gz, persist
# then restore+persist with tail -n0 regular log file

export db_dir="/srv/data"
export report_dir="/srv/report"
export conf_dir="/srv/conf"
export log_dir="/srv/traefik-logs"
initialize=0

#sleep 1h

query_logs () {
    local service=$1
    local config=$2
    local query=$3

    echo "$(date +"[%Y-%m-%d %H:%M:%S]") [*] Initializing $service: $config config: query - \"$query\""

    if [ -z "$query" ]; then
        sh /read.sh | goaccess \
            --config-file=$conf_dir/$config.conf \
            --db-path=$db_dir/$service \
            --output=$report_dir/$service/index.html - > /dev/null 2>&1
    else
        sh /read.sh | egrep "$query" | goaccess \
           --config-file=$conf_dir/$config.conf \
           --db-path=$db_dir/$service \
           --output=$report_dir/$service/index.html - > /dev/null 2>&1
    fi

    initialize=0
}

start_live_query() {
    local service=$1
    local config=$2
    local query=$3
    local port=$4
    localdomain=your.domain

    echo "$(date +"[%Y-%m-%d %H:%M:%S]") [*] Starting WSS for $service, on port $port"
    echo

    if [ -z "$query" ]; then
        tail -f -n0 $log_dir/access.log | goaccess \
            --ws-url=wss://$service.$localdomain:443 --port=$port --real-time-html --restore \
            --config-file=$conf_dir/$config.conf \
            --db-path=$db_dir/$service \
            --output=$report_dir/$service/index.html - > /dev/null 2>&1 &
    else
        tail -f -n0 $log_dir/access.log | egrep "$query" | goaccess \
           --ws-url=wss://$service.$localdomain:443 --port=$port --real-time-html --restore \
           --config-file=$conf_dir/$config.conf \
           --db-path=$db_dir/$service \
           --output=$report_dir/$service/index.html - > /dev/null 2>&1 &
    fi

}


for service in global service1; do # service2 etc....
    echo "$(date +"[%Y-%m-%d %H:%M:%S]")  [+] Configuring $service"

    if [ ! -d "$db_dir"/$service ]; then
        echo "$(date +"[%Y-%m-%d %H:%M:%S]") [*] Didn't find "$db_dir"/$service. Creating..."
        mkdir "$db_dir"/$service
        initialize=1
    fi

    if [ ! -d "$report_dir"/$service ]; then
        echo "$(date +"[%Y-%m-%d %H:%M:%S]") [*] Didn't find "$report_dir"/$service. Creating..."
        mkdir "$report_dir"/$service
        initialize=1
    fi

    # if the container was down, there will be missed logs since dirs exist
    # and the container missed to live parse/save actual logs, that is okay because it won't change the statistics much

    # a clean run will fix those ^ issues, maybe once a month backup/delete volumes and restart the stack?


    case "$service" in
        global)
            if [ "$initialize" -eq 1 ]; then
                query_logs $service global ""
            fi

            start_live_query $service global "" 20000
            ;;
        service1)
            if [ "$initialize" -eq 1 ]; then
                query_logs $service default "traefik-router-query-for-service-1"
            fi

            start_live_query $service default "traefik-router-query-for-service-1" 20001
            ;;
        #service2)
        #;; # etc....
    esac

done

echo "$(date +"[%Y-%m-%d %H:%M:%S]") [+] All done, now sleeping till the end of time.."
sleep infinity

rwjack avatar Dec 02 '22 20:12 rwjack

Like you said, I'd read first the gz files and persist them, then I'd simply run the uncompressed access log directly with goaccess using --restore and --persist. Also, please try running goaccess without any docker stuff and see if that helps. Also make sure you are using the latest version (v1.6.5 as we speak).

allinurl avatar Dec 04 '22 18:12 allinurl

Hey @allinurl,

So that's exactly what I did, I just forgot to paste my config file.

Basically in both cases goaccess should persist, be it reading old gz logs (query_logs function), or running in live mode and reading the current day log (start_live_query function), though it also restores data when running in live mode, which is configured with the cli flag.

log-format %h %^[%d:%t %^] "%r" %s %b "%R" "%u" %^ "%v" "%^" %Tms
date-format %d/%b/%Y
time-format %T

keep-last 30
hour-spec min

anonymize-ip true

persist true

Except there's one issue with this approach: goaccess doesn't know when logrotate rotates the current log, so it doesn't know to start reading the new file.

Basically from what I posted above

  • reading "archived" gz logs works
  • reading the entire "current day" log works without duplicates (everything in access.log - until starting goaccess)
  • reading the "current day" log from the point of initialization works, BUT ONLY up until the logrotation moment

And since my docker machine is not the machine running traefik, I'll have to figure out a way to get around this. My initial thoughts were to simply restart the goaccess stack at a certain time, though I'm not sure if logrotate runs at exactly the same time, every time...

rwjack avatar Dec 04 '22 21:12 rwjack

Do you know if you are truncating the log upon rotation? unless copytruncate is used in logrotate, it just renames the log. If it just moves the file and is within the file system boundaries, then it should just perform a metadata change, so it should preserve the inode number, which should work as expected :)

allinurl avatar Dec 05 '22 01:12 allinurl

Here's my logrotate.d/traefik file:

/var/log/traefik/access.log {
  daily
  rotate 2
  missingok
  notifempty
  compress
  postrotate
    kill -s USR1 $(pgrep traefik)
  endscript
}

The thing is, the log files are not within FS boundaries, because the entire log directory is mounted via nfs.

rwjack avatar Dec 05 '22 10:12 rwjack

That could be an issue. I'd run a test by rotating the log manually and see if the inode changes. e.g.,

ls -lathi /var/log/traefik/

allinurl avatar Dec 06 '22 01:12 allinurl

$ /bin/ls -lathi access.log
392838 -rw-r----- 1 321 321 13M Dec  6 11:17 access.log
$ logrotate -f /etc/logrotate.d/traefik
$ /bin/ls -lathi access.log
391327 -rw-r----- 1 321 321 2.9K Dec  6 11:21 access.log

Uhm Houston, we have a problem.

The inode changed on the traefik machine, where the log is located and rotated. (Meaning the inode also changed on the goaccess machine - they match)

I don't think sharing the log directory with the goaccess machine via nfs presents an issue here. This seems to be something logrotate related, or perhaps traefik doing something weird with that USR1 signal, which according to their documentation should be used.

https://doc.traefik.io/traefik/observability/access-logs/#log-rotation

rwjack avatar Dec 06 '22 10:12 rwjack

It seems I didn't quite understand your previous comment.

Adding copytruncate to logrotate seems to have fixed the issue!

rwjack avatar Dec 09 '22 09:12 rwjack

Yep, you want to preserve the inode number so goaccess knows where to start again. Glad that did the job.

Closing this. Feel free to reopen it if needed.

allinurl avatar Dec 16 '22 02:12 allinurl

Here's the latest version of my entrypoint:

#!/bin/sh

# first read gz, persist
# then restore+persist and tail regular access log

export db_dir="/srv/data"
export report_dir="/srv/report"
export conf_dir="/srv/conf"
export log_dir="/srv/traefik-logs"
initialize=0

query_logs () {
    local service=$1
    local config=$2
    local query=$3

    echo "$(date +"[%Y-%m-%d %H:%M:%S]") [*] Querying existing logs for: $service"

    if [ -z "$query" ]; then
        sh /read.sh | goaccess \
            --config-file=$conf_dir/$config.conf \
            --db-path=$db_dir/$service \
            --output=$report_dir/$service/index.html - > /dev/null 2>&1
    else
        sh /read.sh | egrep "$query" | goaccess \
           --config-file=$conf_dir/$config.conf \
           --db-path=$db_dir/$service \
           --output=$report_dir/$service/index.html - > /dev/null 2>&1
    fi

    initialize=0

    echo "$(date +"[%Y-%m-%d %H:%M:%S]") [+] Query complete"
}

start_live_query() {
    local service=$1
    local config=$2
    local query=$3
    local port=$4
    localdomain=your.domain

    echo "$(date +"[%Y-%m-%d %H:%M:%S]") [*] Starting WSS for $service, on port $port"

    if [ -z "$query" ]; then
        tail -f -n0 $log_dir/access.log | goaccess \
            --ws-url=wss://$service.$localdomain:443 --port=$port --real-time-html --restore \
            --config-file=$conf_dir/$config.conf \
            --db-path=$db_dir/$service \
            --output=$report_dir/$service/index.html - > /dev/null 2>&1 &
    else
        tail -f -n0 $log_dir/access.log | egrep "${query}" | goaccess \
           --ws-url=wss://$service.$localdomain:443 --port=$port --real-time-html --restore \
           --config-file=$conf_dir/$config.conf \
           --db-path=$db_dir/$service \
           --output=$report_dir/$service/index.html - > /dev/null 2>&1 &
    fi

    echo "$(date +"[%Y-%m-%d %H:%M:%S]") --------------------------------------------"
}

initialize_router() {
    service=$1
    config=$2
    query=$3
    port=$4

    echo "$(date +"[%Y-%m-%d %H:%M:%S]") [+] Initializing $service statistics"
    echo "$(date +"[%Y-%m-%d %H:%M:%S]") [*] GoAccess config: \"$config\""
    echo "$(date +"[%Y-%m-%d %H:%M:%S]") [*] Regex Query: \"$query\""

    if [ "$initialize" -eq 1 ]; then
        query_logs ${service} ${config} ${query}
    fi

    start_live_query ${service} ${config} ${query} ${port}
}


find "$report_dir" -maxdepth 1 -type f -name "*.html" -exec rm {} +


for service in global your-service-1 your-service-2; do
    echo "$(date +"[%Y-%m-%d %H:%M:%S]") [+] Configuring $service"

    if [ ! -d "$db_dir"/$service ]; then
        echo "$(date +"[%Y-%m-%d %H:%M:%S]") [*] Creating "$db_dir"/$service."
        mkdir "$db_dir"/$service
        initialize=1
    fi

    if [ ! -d "$report_dir"/$service ]; then
        echo "$(date +"[%Y-%m-%d %H:%M:%S]") [*] Creating "$report_dir"/$service."
        mkdir "$report_dir"/$service
        initialize=1
    fi

    case "$service" in
        # internal services, api/synapse-admin/mailcow/
        global)
            router='(int|ext)-router' # supports basic "or" regex, but not ".*" wildcards
            config=global
            port=20000
            ;;
        your-service-1)
            router='service-1-traefik-router-name'
            config=default
            port=20001
            ;;
        your-service-2)
            router='service-2-(traefik-)?-router-name' 
            config=default
            port=20002
            ;;

    esac
    initialize_router ${service} ${config} ${router} ${port}
done

echo "$(date +"[%Y-%m-%d %H:%M:%S]") [+] All done, now sleeping till the end of time.."
sleep infinity

rwjack avatar Dec 21 '22 12:12 rwjack

Awesome, thanks for sharing that!

allinurl avatar Dec 21 '22 20:12 allinurl