processone / ejabberd

Robust, Ubiquitous and Massively Scalable Messaging Platform (XMPP, MQTT, SIP Server)
https://www.process-one.net/en/ejabberd/
Other
6.11k stars 1.51k forks source link

ejabberd poduced many Warning logs in Postgres #3932

Closed IGImonster closed 1 year ago

IGImonster commented 2 years ago

OS = Debian Bullseye Ejabberd Version = 20.05 bpo Postgresql = 13.8

I noticed that ejabberd produces this message in postgres every 2-5min.

<2022-10-30 07:01:49.122 CET [807841] postgres@ejabberd_popeyetacos_db WARNUNG: nicht standardkonforme Verwendung von Escape in Zeichenkettenkonstante bei Zeichen 2622 2022-10-30 07:01:49.122 CET [807841] postgres@ejabberd_popeyetacos_db TIPP: Verwenden Sie die Syntax für Escape-Zeichenketten, z.B. E'\r\n'. 2022-10-30 07:01:49.177 CET [807843] postgres@ejabberd_test WARNUNG: nicht standardkonforme Verwendung von Escape in Zeichenkettenkonstante bei Zeichen 2622 2022-10-30 07:01:49.177 CET [807843] postgres@ejabberd_test TIPP: Verwenden Sie die Syntax für Escape-Zeichenketten, z.B. E'\r\n'.

After a little research I came across an issue where someone must have had exactly the same. https://github.com/processone/ejabberd/issues/1205

I have followed the instructions suggested there. Created a new database. Rebuilt Postgres and ejabberd. I tried ed with ejabberd 20.02 from the Bullseye release. It always came the same message.

After I in postgres the option 'log_statement = 'all' I got the following log entry.

2022-10-29 15:56:47.380 CEST [666126] postgres@ejabberd_test WARNUNG: nicht standardkonforme Verwendung von Escape in Zeichenkettenkonstante bei Zeichen 2622 2022-10-29 15:56:47.380 CEST [666126] postgres@ejabberd_test TIPP: Verwenden Sie die Syntax für Escape-Zeichenketten, z.B. E'\r\n'. 2022-10-29 15:56:47.380 CEST [666126] postgres@ejabberd_test LOG: Anweisung: SELECT current_database() AS db, schemaname, tablename, reltuples::bigint AS tups, relpages::bigint AS pages, otta, ROUND(CASE WHEN sml.relpages=0 OR sml.relpages=otta THEN 0.0 ELSE (sml.relpages-otta::numeric)/sml.relpages END,3) AS tbloat, CASE WHEN relpages < otta THEN 0 ELSE relpages::bigint - otta END AS wastedpages, CASE WHEN relpages < otta THEN 0 ELSE bs*(sml.relpages-otta)::bigint END AS wastedbytes, CASE WHEN relpages < otta THEN 0 ELSE (bs*(relpages-otta))::bigint END AS wastedsize, iname, ituples::bigint AS itups, ipages::bigint AS ipages, iotta, ROUND(CASE WHEN ipages=0 OR ipages<=iotta THEN 0.0 ELSE (ipages-iotta::numeric)/ipages END,3) AS ibloat, CASE WHEN ipages < iotta THEN 0 ELSE ipages::bigint - iotta END AS wastedipages, CASE WHEN ipages < iotta THEN 0 ELSE bs*(ipages-iotta) END AS wastedibytes, CASE WHEN ipages < iotta THEN 0 ELSE (bs*(ipages-iotta))::bigint END AS wastedisize, CASE WHEN relpages < otta THEN CASE WHEN ipages < iotta THEN 0 ELSE bs*(ipages-iotta::bigint) END ELSE CASE WHEN ipages < iotta THEN bs*(relpages-otta::bigint) ELSE bs*(relpages-otta::bigint + ipages-iotta::bigint) END END AS totalwastedbytes FROM ( SELECT nn.nspname AS schemaname, cc.relname AS tablename, COALESCE(cc.reltuples,0) AS reltuples, COALESCE(cc.relpages,0) AS relpages, COALESCE(bs,0) AS bs, COALESCE(CEIL((cc.reltuples*((datahdr+ma- (CASE WHEN datahdr%ma=0 THEN ma ELSE datahdr%ma END))+nullhdr2+4))/(bs-20::float)),0) AS otta, COALESCE(c2.relname,'?') AS iname, COALESCE(c2.reltuples,0) AS ituples, COALESCE(c2.relpages,0) AS ipages, COALESCE(CEIL((c2.reltuples*(datahdr-12))/(bs-20::float)),0) AS iotta FROM pg_class cc JOIN pg_namespace nn ON cc.relnamespace = nn.oid AND nn.nspname <> 'information_schema' LEFT JOIN ( SELECT ma,bs,foo.nspname,foo.relname, (datawidth+(hdr+ma-(case when hdr%ma=0 THEN ma ELSE hdr%ma END)))::numeric AS datahdr, (maxfracsum*(nullhdr+ma-(case when nullhdr%ma=0 THEN ma ELSE nullhdr%ma END))) AS nullhdr2 FROM ( SELECT ns.nspname, tbl.relname, hdr, ma, bs, SUM((1-coalesce(null_frac,0))*coalesce(avg_width, 2048)) AS datawidth, MAX(coalesce(null_frac,0)) AS maxfracsum, hdr+( SELECT 1+count(*)/8 FROM pg_stats s2 WHERE null_frac<>0 AND s2.schemaname = ns.nspname AND s2.tablename = tbl.relname ) AS nullhdr FROM pg_attribute att JOIN pg_class tbl ON att.attrelid = tbl.oid JOIN pg_namespace ns ON ns.oid = tbl.relnamespace LEFT JOIN pg_stats s ON s.schemaname=ns.nspname AND s.tablename = tbl.relname AND s.inherited=false AND s.attname=att.attname, ( SELECT (SELECT current_setting('block_size')::numeric) AS bs, CASE WHEN SUBSTRING(SPLIT_PART(v, ' ', 2) FROM '#\[0-9]+.[0-9]+#\%' for '#') IN ('8.0','8.1','8.2') THEN 27 ELSE 23 END AS hdr, CASE WHEN v ~ 'mingw32' OR v ~ '64-bit' THEN 8 ELSE 4 END AS ma FROM (SELECT version() AS v) AS foo ) AS constants WHERE att.attnum > 0 AND tbl.relkind='r' GROUP BY 1,2,3,4,5 ) AS foo ) AS rs ON cc.relname = rs.relname AND nn.nspname = rs.nspname LEFT JOIN pg_index i ON indrelid = cc.oid LEFT JOIN pg_class c2 ON c2.oid = i.indexrelid ) AS sml WHERE sml.relpages - otta > 0 OR ipages - iotta > 10 ORDER BY totalwastedbytes DESC LIMIT 10;

IGImonster commented 2 years ago

Oh well, these are logs from a completely empty ejabberd + database These messages are not caused by the postgres ejabberduser "test" but by postgres. There is nothing in the ejabberd debuglog.

IGImonster commented 2 years ago

The closing of the issue was not intentional

licaon-kter commented 2 years ago

So is that ejabberd 21.01 or ejabberd 22.05 from backports? There was no 20.05 and no 20.02 in Bullseye.

Do put the ejabberd.yml contents (after cleaning) on https://gist.github.com

Did you use pg.new.sql right?

IGImonster commented 2 years ago

The closing of the issue was not intentional No i use the pg.sql The ejabberd is the default yml after install. I add only the sql part in there. https://gist.github.com/IGImonster/b56a15056c035b32b03ada7c42ca08ab#file-gistfile1-txt

licaon-kter commented 2 years ago

This Postgresql instance has more than one DB? How do you know the warnings are from ejabberd?

How did you import the db exactly? Command line?

Pls confirm exact ejabberd version too.

IGImonster commented 2 years ago

The version is ejabberd 22.05-1~bpo11+1 The command for the db is postgres=# CREATE USER test WITH PASSWORD '1234'; postgres=# CREATE DATABASE ejabberd_test WITH OWNER test;

postgres@pgsql02:~$ psql -h localhost -U test -d ejabberd_test < pg.sql

After the first connect from ejabberd to the db come the warning 2022-10-30 11:36:47.546 CET [848254] postgres@ejabberd_test WARNUNG: nicht standardkonforme Verwendung von Escape in Zeichenkettenkonstante bei Zeichen 2622 2022-10-30 11:36:47.546 CET [848254] postgres@ejabberd_test TIPP: Verwenden Sie die Syntax für Escape-Zeichenketten, z.B. E'\r\n'.

licaon-kter commented 2 years ago

Have users with special chars in name or password?

IGImonster commented 2 years ago

Its a special emty test ejabberd. Its a raw database and no user no groups, nothing

Neustradamus commented 2 years ago

@IGImonster: Please do not push on the bad button, the good button is "Comment".

prefiks commented 2 years ago

So if this query you listed above SELECT current_database() AS db, schemaname, tablename ... was responsible for that warning (and looking at times of those entries i guess so) then i don't think this is ejabberd what's doing that - there is no such query in ejabberd, that looks like some kind of script that tracks slow queries maybe?

IGImonster commented 2 years ago

I have asked in the irc channel of postgres. There was said that it is at the parameter standard_conforming_strings which ejabberd sets to off at startup.

2022-10-31 11:37:25.912 CET [1060129] test@ejabberd_test ANWEISUNG: alter database "ejabberd_test" set standard_conforming_strings='off';

If I now set the value in psql to on, the log remains empty.

alter database "ejabberd_test" set standard_conforming_strings='on';

How is this value with you?