Log excessively filled with entries such as "TCP xx.xx.xx.xx:xx, 20 total"

[oven8Mitts]

Hello,

I'm running Debian Buster, with ElectrumX 1.15. All python packages have been updated. I've had this issue for the past few versions of ElectrumX.

At the moment, my instance will fill log files with this sort of message:

: INFO:ElectrumX:[12] TCP xx.xx.xx.xx:xx, 5 total
: INFO:ElectrumX:[13] TCP xx.xx.xx.xx:xx, 5 total
: INFO:ElectrumX:[14] TCP xx.xx.xx.xx:xx, 6 total
: INFO:PeerManager:[ **removed**:50002 SSL] verified in 0.9s
: INFO:ElectrumX:[15] TCP xx.xx.xx.xx:xx, 7 total
: INFO:ElectrumX:[15] attempting to crash old client with version 3.2.2
: INFO:ElectrumX:[16] TCP xx.xx.xx.xx:xx, 6 total
: INFO:ElectrumX:[17] SSL xx.xx.xx.xx:xx, 7 total
: INFO:ElectrumX:[18] TCP xx.xx.xx.xx:xx, 8 total
: INFO:ElectrumX:[19] TCP xx.xx.xx.xx:xx, 9 total
: INFO:ElectrumX:[20] TCP xx.xx.xx.xx:xx, 9 total
: INFO:ElectrumX:[21] TCP xx.xx.xx.xx:xx, 6 total
: INFO:ElectrumX:[22] TCP xx.xx.xx.xx:xx, 7 total
: INFO:ElectrumX:[23] TCP xx.xx.xx.xx:xx, 7 total
: INFO:ElectrumX:[23] attempting to crash old client with version 3.2.2
: INFO:ElectrumX:[24] SSL xx.xx.xx.xx:xx, 6 total
: INFO:ElectrumX:[25] TCP xx.xx.xx.xx:xx, 7 total
: INFO:ElectrumX:[26] TCP xx.xx.xx.xx:xx, 8 total
: INFO:ElectrumX:[27] TCP xx.xx.xx.xx:xx, 8 total
: INFO:ElectrumX:[28] TCP xx.xx.xx.xx:xx, 9 total
: INFO:ElectrumX:[29] TCP xx.xx.xx.xx:xx, 8 total
: INFO:ElectrumX:[30] TCP xx.xx.xx.xx:xx, 9 total
: INFO:ElectrumX:[31] TCP xx.xx.xx.xx:xx, 10 total

The xx.xx.xx.xx:xx would be replaced by an IP/port if ANON_LOGS was not set. For now, I disable the NOTICE level in logging as to not fill my syslog.

What exactly causes this message and how can I prevent it from spamming my log?

Thank you

[smmalis37]

This message indicates that someone new has connected to your server. If you want to remove the message you can either block incoming connections to your server, or do what you're already doing with the logging level.

[oven8Mitts]

Thank you for the descriptor.

Does anyone vouch to lower these messages to the DEBUG level? They certainly make reading the log a bit harder to read, and with features such as ANON_LOGS enabled, one could argue that they are not too useful altogether for a public server operator.

Open to discussion

[github12101]

I experienced exactly the same issue.

My description (I created duplicate issue, closed now):

In default setting, ElectrumX is spamming messages like this to INFO output level:

INFO:ElectrumX:[1195011] changing task concurrency from 10 to 8
INFO:ElectrumX:[1195011] SSL 186.3.207.118:52858, 678 total

Yes my friends, this is line number 1,195,011. 1.2M output messages like this and 3M of lines (counted by cat -n command) in total (including other messages, which are counted separately, as I understand). This is on default INFO level. When I switch to WARNING level (one level up), I see nothing, no informative messages about peers, network, configuration, nothing, just errors when peer is blacklisted or something like that. I want to see relevant information, starting and DB info, connection info, peer summary (configured via LOG_SESSIONS variable). But when I go back to LOG_LEVEL=info, I will have 3M of messages per day, which amounted to 250MB on the disk. That's like 34 messages per second!

Can we please move messages like:

INFO:ElectrumX:[1195011] changing task concurrency from 10 to 8
INFO:ElectrumX:[1195011] SSL 186.3.207.118:52858, 678 total

to DEBUG level, instead INFO level? This is certainly DEBUG message and I should not see it during normal operation. Not a million of them per day, at least. Thanks!

[github12101]

Any update on this? Does anyone know how to comment-out this spam messages, in source files? I'd like to fix it, I am not a developer, unfortunately. Thanks.

[SomberNight]

@curious0101 relevant lines are here: https://github.com/spesmilo/electrumx/blob/9ca59facfdb50daf063a5813fc9b08eb6fa1b246/electrumx/server/session.py#L837-L838 https://github.com/kyuupichan/aiorpcX/blob/bd2185aaeb7cd8b18e24866c4a04387650ff4834/aiorpcx/session.py#L209

I find the session-count line somewhat helpful when looking at long logs when e.g. a submodule dies, to see if new sessions are still being established at certain times. Perhaps it could be rate-limited to e.g. one line per minute; or maybe I should just set the log level to DEBUG for my own servers (and set that log line to DEBUG too).

[github12101]

Thanks for your reply. I am a bit confused, this is spesmilo electrumX issue, but you linked file in kyuupichan electrumX?

[oven8Mitts]

@curious0101 aiorpxX is a dependent python library of electrumx, and was maintained by kyuupichan, it's likely that there was no need to fork the code since it should work across multiple currencies.

[github12101]

Thank you. I found pip package aiorpcX installed in my system and I located session.py file successfully. However, other INFO messages (below), are not in that file. I checked all other .py files in aiorpcX too. Can someone make a commit and fix the problem I mentioned please?

Messages like: "changing task concurrency" should go to debug level (edit sessionpy in aiorpcX) "SSL xx.xx.xx.xx:xx, 6 total" should go to debug level (don't know where to fix that..) "TCP xx.xx.xx.xx:xx, 7 total" should go to debug level (don't know where to fix that..) "disconnected whilst throttled" (don't know where to fix that..) this message thousand times is totally meaningless and definitely should go to debug level.