devnulli
Potential critical bug in source code. [Error][Collection was modified; enumeration operation may not execute]
[Error][Collection was modified; enumeration operation may not execute]
Me, as recent user of this wonderful soft, reporting. There is a nasty bug somewhere, that stops parsing new journal entries. In debug logs, it had many 131 rules entries, and in the end mentioned that error.
Due to it, my server was open to 2 full days of relentless attacks (during weekends). When today i noticed it, wasn't able to determine first, what was wrong, or what did broke suddenly (is it OS? is it soft? is it firewall?) , but new ip-s weren't pushed to the block list, completely broken, because main routine of parsing wasn't working at all. In the end, decided trying to restart service, which did reanimate parsing logs. I'm not sure if it's rare or not, but i got this only after one week of using software (which is very bad uptime ratio until broken) Worst part is, if it wasn't for me manually checking logs, and comparing to what should be blocked, the program would be stuck as is, unable to unstuck itself, and time goes on, as if nothing is unusual. One may wonder, when would be the next time it stumbles upon same bug, and will stop doing it's only task its designed to.
I advice developer to re-check codebase, as to where a potential bug may appear related to this problem. For example, possible reason is discussed here (https://stackoverflow.com/questions/604831/collection-was-modified-enumeration-operation-may-not-execute)
This is already discussed in #88. Still happens in my servers but less frequently with latest releases.
Oh, thanks for mentioning #88. Well, seems like it was closed prematurely, as bug still persists. In the meantime, i would be creating additional task that re-starts service once in a while as a preemptive measure.
Oh, I've been searching this little bug for a while now, currently think the frameworks EventLogReader might produce that problem.
May I ask you some questions:
-
What was the message directly before that occured, Was it "
Event Log {requiredEventType} was not found, tasks that require these events will not work and are disabled." ? -
did you have the EvlWatcher Console open when it first occured?
-
and the most important question: did the message repeat itself every 30 seconds, or did it occur once and then the service stoppe?
Hi, the logs were abolutely a mess, and I didn't have a chance to find out what exactly started it, or the message before it occured (possibly went past log default limit entries).
The Concolse was left open inside rdp session, and it repeated many failed messages (pertaining to 131 rule, in my case) at every 'check interval'. But with an actual [Error][...enumeration operation may not execute] at the end (once, it seems).
By coincidence, when I was typing reply, it got another freeze with same bug, and I have logs this time. logs.txt
UPD: if I switch console verbosity from Off to Debug, the timestamp gets updated to current time, with the same overall picture as in logs.txt. Only 1000 lines are copyable, and it looks like all those lines are generated every cycle, i.e. the enormous amount of debug lines ending with one 'enumeration error'.
UPD 2: Changed the limit to 30000, and restarted Console. See what it showed in 2nd dump of logs, maybe that would help to pinpoint whats going on there. logs2.zip
hi thanks for the logs, ill look into it
( btw: if you mean that
26.01.2024 15:10:46 - [Debug]: Booster: 131 26.01.2024 15:10:46 - [Debug]: Booster not in XML, aborting.
thats not an error message, at debug level it tells you everything what its thinking. in this case, it was checking if the word 131 was in the log, and because it wasnt, it did not have to investigate the message further )
added code so i can locate this bug in .61. lets hope we get the stacktrace next time this happens. closing this, and hoping the bug reoccurs with stacktrace
This is still an issue, now with more information in event log (spanish OS):
Colección modificada; puede que no se ejecute la operación de enumeración.
en System.ThrowHelper.ThrowInvalidOperationException(ExceptionResource resource)
en System.Collections.Generic.List`1.Enumerator.MoveNextRare()
en EvlWatcher.Tasks.GenericIPBlockingTask.GetTempBanVictims()
en EvlWatcher.EvlWatcher.Run()
In affected servers this log is found every 30/31 seconds.
thank you for running .61 and help me locate this! with your help i finally have the stacktrace so i can remove this bastard. will fix that today
there it is, it was there all the way , i just didnt see it.
also, it seems that this bug only occurs exactly one hour after manually removing any ip fom the temporary ban list. that is why it was so difficult to track, and thats why it occurs so rarely