Apache piped logging doesn't work

Hi guys!

I struggle now for days with the problem that the Apache piped logging doesn’t work (properly). I tried really a lot of option-, LogFormat- and Apache config combinations but can’t get it to work. When I hit the log-import manually over bash shell it works fine but not as Apache piped logging. I also checked the Apache mods if I maybe miss something. But also don’t get any errors in my logs. It’s like Apache or the Python script don’t give a fluff about the visitor.

This is my latest CustomLog-Config:

#
# "Normal" logging
#
LogFormat "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\"" matomoLogFormat
ErrorLog ${APACHE_LOG_DIR}/whoogle-error.log
CustomLog ${APACHE_LOG_DIR}/whoogle-access.log matomoLogFormat
#
# Apache piped logging to Matomo
#
CustomLog "|/var/www/analytics.[CENSORED].de/misc/log-analytics/import_logs.py --idsite=[CENSORED] --token-auth=[CENSORED] --hostname=whoogle.[CENSORED].de --enable-http-errors --enable-http-redirects --enable-bots --url=https://analytics.[CENSORED].de --recorders=2 --log-format-name=common_complete --debug --output=${APACHE_LOG_DIR}/matomo-debug.log -" matomoLogFormat

I have to mention that I use a reverse proxy for this service but I don’t know if this is an issue?

SSLProxyEngine Off
ProxyPreserveHost On
ProxyRequests Off
ProxyAddHeaders On
RemoteIPHeader X-Forwarded-For
RemoteIPInternalProxy 127.0.0.1
ProxyPass "/" "http://127.0.0.1:5000/"
ProxyPassReverse "/" "http://127.0.0.1:5000/"

After restart or reload of Apache I only get this in the matomo-debug.log:

808 2023-04-16 17:14:38,417: [DEBUG] Accepted hostnames: piped.[CENSORED].de,pipedapi.[CENSORED].de
809 2023-04-16 17:14:38,417: [DEBUG] Matomo Tracker API URL is: https://analytics.[CENSORED].de
810 2023-04-16 17:14:38,417: [DEBUG] Matomo Analytics API URL is: https://analytics.[CENSORED].de
811 2023-04-16 17:14:38,417: [DEBUG] Accepted hostnames: whoogle.[CENSORED].de
812 2023-04-16 17:14:38,417: [DEBUG] Authentication token token_auth is: [CENSORED]
813 2023-04-16 17:14:38,417: [DEBUG] Matomo Tracker API URL is: https://analytics.[CENSORED].de
814 2023-04-16 17:14:38,417: [DEBUG] Resolver: static
815 2023-04-16 17:14:38,417: [DEBUG] Matomo Analytics API URL is: https://analytics.[CENSORED].de
816 2023-04-16 17:14:38,417: [DEBUG] Authentication token token_auth is: [CENSORED]
817 2023-04-16 17:14:38,417: [DEBUG] Resolver: static
818 2023-04-16 17:14:38,585: [DEBUG] Launched recorder
819 2023-04-16 17:14:38,585: [DEBUG] Launched recorder
820 2023-04-16 17:14:38,585: [DEBUG] Launched recorder
821 2023-04-16 17:14:38,585: [DEBUG] Launched recorder

Then after nothing anymore. I tried to simulate visitors via Brave’s Tor service and different online proxy but no records. I had also set %v at start of LogFormat and removed it. After the restart the was a pending record. But I don’t know if it was made by myself or by a foreign visitor.

=== Matomo System Check ===

Click to view System Check

Mandatory checks

PHP-Version >= 7.2.5:

:heavy_check_mark: 8.2.4

PDO Erweiterung:

:heavy_check_mark:

PDO\MYSQL Erweiterung:

:heavy_check_mark:

MYSQLI Erweiterung:

:heavy_check_mark:

Weitere erforderliche Anforderungen:

:heavy_check_mark: zlib :heavy_check_mark: json :heavy_check_mark: filter :heavy_check_mark: hash :heavy_check_mark: session

Erforderliche Funktionen:

:heavy_check_mark: debug_backtrace :heavy_check_mark: eval :heavy_check_mark: hash :heavy_check_mark: gzcompress :heavy_check_mark: gzuncompress :heavy_check_mark: pack

Benötigte PHP Konfiguration (php.ini):

:heavy_check_mark: session.auto_start = 0 :heavy_check_mark: max_execution_time = 0 OR = -1 OR >= 30

Verzeichnisse mit Schreibzugriff:

:heavy_check_mark: $DOC_ROOT/tmp :heavy_check_mark: $DOC_ROOT/tmp/assets :heavy_check_mark: $DOC_ROOT/tmp/cache :heavy_check_mark: $DOC_ROOT/tmp/climulti :heavy_check_mark: $DOC_ROOT/tmp/latest :heavy_check_mark: $DOC_ROOT/tmp/logs :heavy_check_mark: $DOC_ROOT/tmp/sessions :heavy_check_mark: $DOC_ROOT/tmp/tcpdf :heavy_check_mark: $DOC_ROOT/tmp/templates_c

Optional checks

Verzeichnisse, welche privat sein müssen:

:heavy_check_mark: Alle privaten Verzeichnisse sind nicht aus dem Internet zugänglich.

Empfohlene private Verzeichnisse:

:heavy_check_mark: Alle privaten Verzeichnisse sind nicht aus dem Internet zugänglich.

Dateiintegrität:

:heavy_check_mark:

64-bit PHP Binär:

:heavy_check_mark:

Tracker-Status:

:heavy_check_mark:

Speicherlimit:

:heavy_check_mark: 128M

Zeitzone:

:heavy_check_mark:

Öffnen einer URL:

:heavy_check_mark: curl

PageSpeed ist deaktiviert:

:heavy_check_mark:

GD > 2.x + FreeType (Grafiken):

:heavy_check_mark:

Andere Erweiterungen:

:heavy_check_mark: json :heavy_check_mark: libxml :heavy_check_mark: dom :heavy_check_mark: SimpleXML :heavy_check_mark: openssl

Andere Funktionen:

:heavy_check_mark: shell_exec :heavy_check_mark: set_time_limit :heavy_check_mark: mail :heavy_check_mark: parse_ini_file :heavy_check_mark: glob :heavy_check_mark: gzopen :heavy_check_mark: md5_file

Dateisystem:

:heavy_check_mark:

Cron einrichten - Prozesse via CLI steuern:

:heavy_check_mark: OK

Letzter erfolgreicher Abschluss der Archivierung:

:heavy_check_mark: Der Archivierungsprozess wurde vor 00:00:27 erfolgreich abgeschlossen.

Datenbankfähigkeiten:

:heavy_check_mark: UTF8mb4 charset :heavy_check_mark: LOAD DATA INFILE :heavy_check_mark: CREATE TEMPORARY TABLES :heavy_check_mark: Changing transaction isolation level

Maximale Packetgröße:

:heavy_check_mark:

Erzwungene SSL Verbindung:

:heavy_check_mark:

Standorterkennung:

:heavy_check_mark: geoip2php (continent_code, continent_name, country_code, country_name, region_code, region_name, city_name, postal_code, lat, long)

Update über HTTPS:

:heavy_check_mark:

Schreibbarer JavaScript-Tracker (“/matomo.js” & “/piwik.js”):

:heavy_check_mark:

Informational results

Matomo Version:

4.14.1

Matomo Update History:

4.11.0,4.10.1,4.8.0,4.6.1,4.5.0,4.4.1

Matomo Install Version:

Unknown - pre 3.8.

Latest Available Version:

4.14.1

Is Git Deployment:

0

PHP_OS:

Linux

PHP SAPI:

apache2handler

Timezone Version:

0.system

PHP Timezone:

UTC

PHP Time:

1681659329

PHP Datetime:

2023-04-16 15:35:29

PHP INI max_execution_time:

30

PHP INI post_max_size:

8M

PHP INI max_input_vars:

1000

PHP INI zlib.output_compression:

Curl Version:

7.74.0, OpenSSL/1.1.1n

Suhosin Installed:

0

DB Prefix:

piwik_

DB Charset:

utf8mb4

DB Adapter:

PDO\MYSQL

MySQL Version:

10.5.18-MariaDB-0+deb11u1

Num Tables:

525

Browser Segment Archiving Enabled:

1

Development Mode Enabled:

0

Internet Enabled:

1

Multi Server Environment:

0

Auto Update Enabled:

1

Custom User Path:

0

Custom Include Path:

0

Release Channel:

latest_stable

Plugins Activated:

API, Actions, Annotations, BulkTracking, Contents, CoreAdminHome, CoreConsole, CoreHome, CorePluginsAdmin, CoreUpdater, CoreVisualizations, CoreVue, CustomDimensions, CustomJsTracker, CustomVariables 4.1.3, DBStats, Dashboard, DevicePlugins, DevicesDetection, Diagnostics, Events, GeoIp2, Heartbeat, ImageGraph, Insights, Installation, Intl, IntranetMeasurable, LanguagesManager, Login, Marketplace, MobileAppMeasurable, Monolog, Morpheus, MultiSites, Overlay, PagePerformance, PrivacyManager, Provider 4.0.5, Proxy, Referrers, Resolution, SEO, ScheduledReports, SegmentEditor, SitesManager, Tour, Transitions, TwoFactorAuth, UserCountry, UserCountryMap, UserId, UserLanguage, UsersManager, VisitFrequency, VisitTime, VisitorInterest, VisitsSummary, WebsiteMeasurable, Widgetize

Plugins Deactivated:

Ecommerce, ExampleRssWidget 1.0, Feedback, Goals, Live, MobileMessaging, ProfessionalServices, RssWidget, TagManager, Zeitgeist 4.14.1

Plugins Invalid:

Server Info:

Apache

Had visits in last 1 day:

1

Had visits in last 3 days:

1

Had visits in last 5 days:

1

Archive Time Last Started:

2023-04-16 15:35:02

Archive Time Last Finished:

2023-04-16 15:35:02

User Agent:

Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/112.0.0.0 Safari/537.36

Browser Language:

de-de,de,en-us,en

Total Invalidation Count:

0

In Progress Invalidation Count:

0

Scheduled Invalidation Count:

0

Earliest invalidation ts_started:

Latest invalidation ts_started:

Earliest invalidation ts_invalidated:

Latest invalidation ts_invalidated:

Number of segment invalidations:

0

Number of plugin invalidations:

0

List of plugins being invalidated:

Anonymize Referrer:

Do Not Track enabled:

1

=== System Info ===

  • OS: Debian 11.6 (5.10.0-21-amd64)
  • Apache: 2.4.56
  • Python: 3.9.2

I imported the data manually today an discovered following:

135 Parsing log /var/log/apache2/whoogle-access.log...
136
137 Logs import summary
138 -------------------
139
140     0 requests imported successfully
141     0 requests were downloads
142     244 requests ignored:
143         0 HTTP errors
144         0 HTTP redirects
145         244 invalid log lines
146         0 filtered log lines
147         0 requests did not match any known site
148         0 requests did not match any --hostname
149         0 requests done by bots, search engines...
150         0 requests to static resources (css, js, images, ico, ttf...)
151         0 requests to file downloads did not match any --download-extensions
152
153 Website import summary
154 ----------------------
155
156     0 requests imported to 1 sites
157         1 sites already existed
158         0 sites were created:
159
160     0 distinct hostnames did not match any existing site:
161
162
163
164 Performance summary
165 -------------------
166
167     Total time: 0 seconds
168     Requests imported per second: 0.0 requests per second
169
170 Processing your log data
171 ------------------------
172
173     In order for your logs to be processed by Matomo, you may need to run the following command:
174      ./console core:archive --force-all-websites --url='https://analytics.jotoma.de'

The line I want relate to is #145: 244 invalid log lines.

A log line looks for example like this:

2a02:810d:b63f:fdc8:98fb:30b4:5921:bd2 - - [18/Apr/2023:10:05:45 +0200] "GET /element?url=gAAAAABkPk9Zi7A3mkUYqmMM1kZxa-m_ImFQ-MzHVvUPkgIBj6TgWIV3B1u5DueIyqtaaHQg446nVcUH4zo3Mem05xiOIWonv6MiHv_cNg9pBgD1pAyyTyLXpEUHVMyDmJzhfEgFftmUTrSw0Fm1Qp8slkIdHcmV38Gc8AjfDqkDLLeEtgJBmRyWgDzOBDqU0YHMrNiXQGYz8CRcKkJFH9cehrSPlNV56M cJcSLg6TJBLmQO3ciuL8E=&type=image/png HTTP/1.1" 200 6745 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/112.0.0.0 Safari/537.36"

But it doesn’t matter if it’s IPv4 or IPv6.


Edit #1: HA! Okay I added to %v again at start of LogFormat and the manually import works fine but the piped not.

Strange… I leaved it as it is and now I got records…