Logs, logs, so many logs, **too many logs!**

Describe your issue in detail

Pydio Cells is chatty. Well, at least, it’s chatty to the log file(s). And to the console. And to journalctl (which gets what the console writes). And to ./services/pydio.grpc.log/* (6 GBytes and growing) And possibly to the database as well? (What is this data_meta table which has almost 300,000 rows?!)

That’s… really, that’s too much.

Now, my issue here is not the logs per se. We need logs. My concern is the constant hammering on disk due to the almost uninterrupted stream of logging that Cells is doing — even when it’s not doing anything.

I’m on Ubuntu Linux and launching Cells from systemd and the logging options I’m now using are --log=error --log_json=true --log_to_file=false — nevertheless, I see on jornalctl -u cells -f that there are as many messages to info as before (see Logs included below).

Shouldn’t the log entries be only written out if they were errors?

Where, then, should I force the configuration to only log messages of level “error”?

What version of Cells are you using?

# ./cells version
Pydio Cells Home Edition
 Version: 	4.2.6
 Built: 	08 Sep 23 14:32 +0000
 Git commit: 	b8c970d06b15c30a8f8c3879c8e86f6823867bfa
 OS/Arch: 	linux/amd64
 Go version: 	go1.19.12

What is the server OS? Database name/version? Browser name or mobile device description (if issue appears client-side)?

Server OS: Ubuntu 22.04.3 LTS
Database: mysql Ver 15.1 Distrib 10.6.12-MariaDB, for debian-linux-gnu (x86_64) using EditLine wrapper

I use several browsers when testing out if everything is working properly, but this issue is not client-side.

What steps have you taken to resolve this issue already?

For now, just added the extra fields for limiting (?..) logs on the command line as shown above.

For the sake of completeness, I did add environment variables as well (even knowing that some are already being flagged as deprecated).

It seems that, at least from what I can see, as expected, the logs are not being written to file any longer — only to the console (which, in turn, will get ‘captured’ by systemd and written to the journal).

The difference in terms of overall performance, however, is zero; in other words, simultaneously logging to the journal and a separate file consumes the same amount of resources (CPU, memory, I/O operations) as just to the journal; in other words, the existence of an additional log file, by itself, is irrelevant. I just suspect that injecting several dozens of log messages per second into the journal system is dragging it down to its knees.

It should also be noted that Cells keeps at least 16 (!) connections open to MariaDB at all times, but the number of queries per second is relatively low (merely 20 or so) — it just makes MariaDB consume more memory (and perhaps a few more file descriptors) — so I’m not overly concerned with that (perhaps I should be?).

Logs

Note: some details anonymised for the sake of privacy. Nevertheless, it’s important to take into consideration that the paths to the configuration files are correct.

These are just the first entries when Cells boots. It’s clear that it’s not respecting any command-line directives and/or environment variables, since info-level messages are being logged.

Sep 11 19:20:30 <MYHOSTNAME> systemd[1]: Starting Pydio Cells...
Sep 11 19:20:30 <MYHOSTNAME> systemd[1]: Started Pydio Cells.
Sep 11 19:20:30 <MYHOSTNAME> cells[3351637]: Binary:
Sep 11 19:20:30 <MYHOSTNAME> cells[3351637]:   Package:        Pydio Cells Home Edition
Sep 11 19:20:30 <MYHOSTNAME> cells[3351637]:   Version:        4.2.6
Sep 11 19:20:30 <MYHOSTNAME> cells[3351637]:   BuildTime:        08 Sep 23 14:32 +0000
Sep 11 19:20:30 <MYHOSTNAME> cells[3351637]:   Git Commit:        b8c970d06b15c30a8f8c3879c8e86f6823867bfa
Sep 11 19:20:30 <MYHOSTNAME> cells[3351637]:   Go Version:        go1.19.12
Sep 11 19:20:30 <MYHOSTNAME> cells[3351637]:   OS/arch:        linux/amd64
Sep 11 19:20:30 <MYHOSTNAME> cells[3351637]: Drivers:
Sep 11 19:20:30 <MYHOSTNAME> cells[3351637]:   Registry:        mem:///registry
Sep 11 19:20:30 <MYHOSTNAME> cells[3351637]:   Broker:        mem:///broker
Sep 11 19:20:30 <MYHOSTNAME> cells[3351637]:   Config:        file:///path/to/my/cells/installation/pydio.json
Sep 11 19:20:30 <MYHOSTNAME> cells[3351637]:   Vault:        file:///path/to/my/cells/installation/pydio-vault.json
Sep 11 19:20:30 <MYHOSTNAME> cells[3351637]:   Keyring:        file:///path/to/my/cells/installation/cells-vault-key
Sep 11 19:20:30 <MYHOSTNAME> cells[3351637]:   Certificates:        file:///path/to/my/cells/installation/certs
Sep 11 19:20:30 <MYHOSTNAME> cells[3351637]:   Cache:        bigcache:///cache
Sep 11 19:20:30 <MYHOSTNAME> cells[3351637]:   ShortCache:        pm:///shortcache
Sep 11 19:20:30 <MYHOSTNAME> cells[3351637]:   Queue:        mem:///queue
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]:   Persisting Queue:        file:///queue
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]: Networking:
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]:   Hostname:        <MYHOSTNAME>
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]:   Advertise:        127.0.0.1
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]: Monitoring:
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]:   Metrics:        false
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]:   Profiles:        false
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]: Build Settings:
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]:   -compiler:        gc
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]:   -trimpath:        true
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]:   CGO_ENABLED:        1
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]:   GOARCH:        amd64
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]:   GOOS:        linux
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]:   GOAMD64:        v1
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]:   vcs:        git
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]:   vcs.revision:        b8c970d06b15c30a8f8c3879c8e86f6823867bfa
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]:   vcs.time:        2023-09-08T14:30:23Z
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]:   vcs.modified:        false
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]: {"level":"info","ts":"2023-09-11T19:20:30+01:00","logger":"pydio.grpc.broker","msg":"ready"}
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]: {"level":"info","ts":"2023-09-11T19:20:30+01:00","logger":"pydio.grpc.config","msg":"ready"}
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]: {"level":"info","ts":"2023-09-11T19:20:30+01:00","logger":"pydio.grpc.registry","msg":"ready"}
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]: {"level":"info","ts":"2023-09-11T19:20:31+01:00","logger":"pydio.grpc.log","msg":"ready"}
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]: {"level":"info","ts":"2023-09-11T19:20:31+01:00","logger":"pydio.server.manager","msg":"Discovery services started, carry on to other services"}
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]: {"level":"info","ts":"2023-09-11T19:20:31+01:00","logger":"pydio.gateway.grpc","msg":"Configuring self-signed configuration for gRPC gateway to allow full TLS chain."}
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]: {"level":"info","ts":"2023-09-11T19:20:31+01:00","logger":"pydio.gateway.wopi","msg":"ready"}
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]: {"level":"info","ts":"2023-09-11T19:20:31+01:00","logger":"pydio.rest.policy","msg":"starting","service":"pydio.rest.policy","hook router to":"/a/policy"}
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]: {"level":"info","ts":"2023-09-11T19:20:31+01:00","logger":"pydio.rest.templates","msg":"starting","service":"pydio.rest.templates","hook router to":"/a/templates"}
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]: {"level":"info","ts":"2023-09-11T19:20:31+01:00","logger":"pydio.rest.update","msg":"starting","service":"pydio.rest.update","hook router to":"/a/update"}
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]: {"level":"info","ts":"2023-09-11T19:20:31+01:00","logger":"pydio.rest.jobs","msg":"starting","service":"pydio.rest.jobs","hook router to":"/a/jobs"}
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]: {"level":"info","ts":"2023-09-11T19:20:31+01:00","logger":"pydio.rest.acl","msg":"starting","service":"pydio.rest.acl","hook router to":"/a/acl"}
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]: {"level":"info","ts":"2023-09-11T19:20:31+01:00","logger":"pydio.rest.meta","msg":"starting","service":"pydio.rest.meta","hook router to":"/a/meta"}
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]: {"level":"info","ts":"2023-09-11T19:20:31+01:00","logger":"pydio.rest.auth","msg":"starting","service":"pydio.rest.auth","hook router to":"/a/auth"}
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]: {"level":"info","ts":"2023-09-11T19:20:31+01:00","logger":"pydio.rest.share","msg":"starting","service":"pydio.rest.share","hook router to":"/a/share"}
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]: {"level":"info","ts":"2023-09-11T19:20:31+01:00","logger":"pydio.rest.tree","msg":"starting","service":"pydio.rest.tree","hook router to":"/a/tree"}
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]: {"level":"info","ts":"2023-09-11T19:20:31+01:00","logger":"pydio.rest.log","msg":"starting","service":"pydio.rest.log","hook router to":"/a/log"}
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]: {"level":"info","ts":"2023-09-11T19:20:31+01:00","logger":"pydio.rest.activity","msg":"starting","service":"pydio.rest.activity","hook router to":"/a/activity"}
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]: {"level":"info","ts":"2023-09-11T19:20:31+01:00","logger":"pydio.rest.user-meta","msg":"starting","service":"pydio.rest.user-meta","hook router to":"/a/user-meta"}
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]: {"level":"info","ts":"2023-09-11T19:20:31+01:00","logger":"pydio.rest.graph","msg":"starting","service":"pydio.rest.graph","hook router to":"/a/graph"}
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]: {"level":"info","ts":"2023-09-11T19:20:31+01:00","logger":"pydio.rest.workspace","msg":"starting","service":"pydio.rest.workspace","hook router to":"/a/workspace"}
Sep 11 19:20:31 <MYHOSTNAME> cells[3351637]: {"level":"info","ts":"2023-09-11T19:20:31+01:00","logger":"pydio.rest.user","msg":"starting","service":"pydio.rest.user","hook router to":"/a/user"}
[...]

data_meta is necessary
./services/pydio.grpc.log/* can be periodically deleted.
But yes, there are lots of log files. Scheduler and other GRPC-related tasks often crash due to the absurd amount of syslog.bleve files…

=> switch to MongoDB instead of bolt/bleve based storages ! much easier to clean up!

This topic was automatically closed 60 days after the last reply. New replies are no longer allowed.