#1460 Gajim and Prosody "talk" causes prosody.log to explode

Reporter sebastian
Owner MattJ
Created
Updated
Stars ★ (1)
Tags
  • Type-Defect
  • Priority-Medium
  • Status-New
  1. sebastian on

    This might as well be a bug that needs fixing on Gajim, however i only have logs for Prosody and I also think, a client gone wild should not affect a server. I am happy to carry this over to the Gajim people, as soon as it is clear it is not a prosody defect but Gajim misbheaviour. High level description: ------------------------ The following happened today, for the third time in ~4 weeks. Let me start with my Setup: I'm running prosody on a virtual machine at home. Prosody has s2s connection to some of my friends Prosodys and I'm using my primary account from at least 3 devices, two of which are Gajims and up to two Conversations. At ~22.00 this evening i noticed that again my Gajim was offline, as my laptop is connected via ethernet in the same subnet as the VM running prosody, I could be confident it is not a networking issue. So i knew it was "that one problem again". It seems that some times when i connect my Gajim, it will start talking to prosody non-stop, amassing gigabytes of logfiles on the prosody machine. It even spreads out via s2s, so that at least one time it made one of my friends prosody stop working as well - not only mine! It will run until the small hard disk is full. Versions: ----------- Client: - OS: Linux Mint 19.3 - Gajim version: 1.0.1 (from the Repo) - GTK+ Version: 3.22.30 - PyGObject Version: 3.26.1 - python-nbxmpp Version: 0.6.4 Server: Linux penguin 4.9.0-4-amd64 #1 SMP Debian 4.9.65-3+deb9u1 (2017-12-23) x86_64 GNU/Linux Prosody hg:29733134c76c Lua version: Lua 5.1 Steps to reproduce: ------------------- There is no clear steps to reproduce, but I do defect management for a living and i know as much info as possible is good. 1. Connect Gajim 2. Wait for 2-3 hours Expected behaviour: Everything is normal Actual behaviour: Sometimes it happens that the log file explodes. There is millions of log lines. I know having the log on debug-level might be counter-productive, but during normal operation this does not cause soo much logs and maybe now it helps to fix this bug (or at least weird behaviour if it is not a bug) When it happened today, i did the following: I produced a list of Hours in the logs and how many lines per Hour were in the log: cat prosody.log | awk '{print $3}' | awk -F":" '{print $1}' | uniq -c 454 03 502 04 1476 05 8813 06 2326 07 2960 08 1934 09 5668 10 4722 11 4983 12 4338 13 6516 14 5302 15 3881 16 640853 17 11705361 18 17044960 19 16121773 20 9206457 21 (at 21:... something the disk was full) So i could see that at 17:something the problem started Now per minute from 17:00-17:59: cat prosody.log | grep "Nov 12 17:" | awk '{print $3}' | awk -F":" '{print $2}' | uniq -c 5 37 14 38 523 39 59 40 136 41 3 42 387 43 129 44 13 46 21639 47 42613 48 44095 49 At 17:47, the minute that the count of loglines went from a couple of hundreds per minute to >20000 was when i connected my Gajim running on my laptop at home. I spent the last 30 minutes sanitizing the log for personal information but I hope it is still useful. I uploaded it here: PASSWORD: prosody Expires 2019-12-12 https://paste.jaegers.net/?73e13d74b0a4f231#EwyywRwrPYf4oqeeAewLP7Vey1M566GmSLPAiLqRqAEJ So, can you tell me if this is "normal"? I don't know for sure the specs of the VM, but i think i sized it raspberry-like. 1GB of RAM and 16GB of disk. It usually runs without any issues, but when this happens prosody goes into heavy load and stops responding after some time. Also, one time it caused load on another server. Last time, when i apparently did not have the energy to put this into a defect, i could stop Gajim and the behaviour would stop. When I started Gajim again, the massive amount of log lines started again. And I repeated this two more times. To me it is obvious there is a problem between Gajim and Prosody, which I hope you can read from the logs. If you need further info like prosody.cfg.lua or any other information, let me know.

  2. MattJ on

    Hi, thanks for the report! > So, can you tell me if this is "normal"? Rest assured, this is obviously not normal (people even run Prosody on things smaller than a Rasperry Pi). The first thing I will comment: you have debug logs enabled. These *are* expected to be quite noisy, and should not generally be enabled unless you are debugging a problem. They log a load of very detailed stuff that you generally don't need to know. That said... there is clearly a problem here. Turning off debug logging will very likely stop the disk filling up, but it looks like there may be some issue between Prosody and Gajim that might still affect Prosody's performance. I'll take a look through the logs you submitted and see if I can figure out what's going on.

    Changes
    • owner MattJ
  3. sebastian on

    As dicussed on MUC here are prosodyctl about ----------------------------------- Prosody hg:29733134c76c # Prosody directories Data directory: /usr/local/var/lib/prosody Config directory: /usr/local/etc/prosody Source directory: /usr/local/lib/prosody Plugin directories: /home/sebastian/prosody-modules/ - prosody-modules rev: 860802ab941f /usr/local/lib/prosody/modules/ # Operating system Linux 4.9.0-4-amd64 # Lua environment Lua version: Lua 5.1 Lua module search paths: /usr/local/lib/prosody/?.lua /usr/local/share/lua/5.1/?.lua /usr/local/share/lua/5.1/?/init.lua /usr/local/lib/lua/5.1/?.lua /usr/local/lib/lua/5.1/?/init.lua /usr/share/lua/5.1/?.lua /usr/share/lua/5.1/?/init.lua Lua C module search paths: /usr/local/lib/prosody/?.so /usr/local/lib/lua/5.1/?.so /usr/lib/x86_64-linux-gnu/lua/5.1/?.so /usr/lib/lua/5.1/?.so /usr/local/lib/lua/5.1/loadall.so LuaRocks: Not installed # Network Backend: select # Lua module versions lfs: LuaFileSystem 1.6.3 lxp: LuaExpat 1.3.0 socket: LuaSocket 3.0-rc1 ssl: 0.6 prosody.cfg.lua ----------------------------------- admins = {"sebastian@mydomain.tld" } pidfile = "/var/run/prosody/prosody.pid" -- this is the default on Debian plugin_paths = {"/home/sebastian/prosody-modules/"} modules_enabled = { -- Generally required "roster"; -- Allow users to have a roster. Recommended ;) "saslauth"; -- Authentication for clients and servers. Recommended if you want to log in. "tls"; -- Add support for secure TLS on c2s/s2s connections "dialback"; -- s2s dialback support "disco"; -- Service discovery --"compression"; "csi"; "smacks"; "http_upload"; "post_msg"; -- Not essential, but recommended "carbons"; -- Keep multiple clients in sync "pep"; -- Enables users to publish their mood, activity, playing music and more "private"; -- Private XML storage (for room bookmarks, etc.) "blocklist"; -- Allow users to block communications with other users "vcard"; -- Allow users to set vCards -- -- must go into componenten "vcard_muc"; "bookmarks"; "vcard_legacy"; -- Nice to have "version"; -- Replies to server version requests "uptime"; -- Report how long server has been running "time"; -- Let others know the time here on this server "ping"; -- Replies to XMPP pings with pongs "register"; -- Allow users to register on this server using a client and change passwords "mam"; -- Store messages in an archive and allow users to access it -- mus be aberafter MUC Componenten... mam_muc; -- MUC MAM.... -- Admin interfaces "admin_adhoc"; -- Allows administration via an XMPP client that supports ad-hoc commands "admin_telnet"; -- Opens telnet console interface on localhost port 5582 -- HTTP modules "bosh"; -- Enable BOSH clients, aka "Jabber over HTTP" "websocket"; -- XMPP over WebSockets "http_files"; -- Serve static files from a directory over HTTP -- Other specific functionality --"limits"; -- Enable bandwidth limiting for XMPP connections "groups"; -- Shared roster support "server_contact_info"; -- Publish contact information for this service "announce"; -- Send announcement to all online users --"welcome"; -- Welcome users who register accounts --"watchregistrations"; -- Alert admins of registrations --"motd"; -- Send a message to users when they log in --"legacyauth"; -- Legacy authentication. Only used by some old clients and bots. -- "proxy65"; -- Enables a file transfer proxy service which clients behind NAT can use } -- These modules are auto-loaded, but should you want -- to disable them then uncomment them here: modules_disabled = { -- "offline"; -- Store offline messages -- "c2s"; -- Handle client connections -- "s2s"; -- Handle server-to-server connections -- "posix"; -- POSIX functionality, sends server to background, enables syslog, etc. } contact_info = { admin = { "mailto:sebastian@myotherdomain.tld", "xmpp:sebastian@mydomain.tld" }; abuse = { "mailto:sebastian@myotherdomain.tld", "xmpp:sebastian@mydomain.tld" }; feedback = { "mailto:sebastian@myotherdomain.tld", "xmpp:sebastian@mydomain.tld" }; security = { "mailto:sebastian@myotherdomain.tld", "xmpp:sebastian@mydomain.tld" }; support = { "mailto:sebastian@myotherdomain.tld", "xmpp:sebastian@mydomain.tld" }; }; cross_domain_bosh = true cross_domain_websocket = { "https://web.mydomain.tld:6531", "https://web.mydomain.tld:6531/converse" } proxy65_ports = { 65001, 5000 } allow_registration = false c2s_require_encryption = true s2s_require_encryption = true s2s_secure_auth = false authentication = "internal_hashed" archive_expires_after = "1w" -- Remove archived messages after 1 week log = { info = "/var/log/prosody/prosody.log"; -- Change 'info' to 'debug' for verbose logging error = "/var/log/prosody/prosody.err"; debug = "/var/log/prosody/prosody.log"; -- "*syslog"; -- Uncomment this for logging to syslog -- "*console"; -- Log to the console, useful for debugging with daemonize=false } ssl = { --key = "/var/lib/prosody/certs/privkey3.key"; --#certificate = "/var/lib/prosody/certs/fullchain3.cer"; key = "/etc/ssl/certs/mydomain.tld/mydomain.tld.key"; certificate = "/etc/ssl/certs/mydomain.tld/mydomain.tld_fullchain.pem"; options = { "no_sslv2", "no_sslv3", "no_ticket", "no_compression", "cipher_server_preference", "single_dh_use", "single_ecdh_use" } } Include "conf.d/*.cfg.lua" http_upload_file_size_limit = 20623360 -- 1024*1024*10 http_upload_expire_after = 60 * 60 * 24 * 7 -- a week in seconds legacy_ssl_ports = { 5223 } conf.d/mydomain.cfg.lua ----------------------------------- VirtualHost "mydomain.tld" enabled = true plugin_paths = {"/home/sebastian/prosody-modules/"} Component "conference.mydomain.tld" "muc" modules_enabled = { "mam_muc", "vcard_muc"} muc_log_by_default = true muc_log_all_rooms = true muc_log_presences = false log_all_rooms = true muc_log_expires_after = "1w" muc_log_cleanup_interval = 4 * 60 * 60 Component "proxy.mydomain.tld" "proxy65" proxy65_address = "mydomain.tld" http_upload_file_size_limit = 20623360 -- 1024*1024*10 ssl = { --key = "/var/lib/prosody/certs/privkey3.key"; --#certificate = "/var/lib/prosody/certs/fullchain3.cer"; key = "/etc/ssl/certs/mydomain.tld/mydomain.tld.key"; certificate = "/etc/ssl/certs/mydomain.tld/mydomain.tld_fullchain.pem"; options = { "no_sslv2", "no_sslv3", "no_ticket", "no_compression", "cipher_server_preference", "single_dh_use", "single_ecdh_use" } }

  4. sebastian on

    For documentation: changed from vcard+vcard_legacy to vcard4 + vcard_legacy modules as suggested by the guys on prosody muc. Will monitor for problems and get Gajim logs if necessary.

New comment

Not published. Used for spam prevention and optional update notifications.