Page 1 of 2
Fixing data stage spam
Posted: Sun Jun 02, 2019 10:28 pm
by Rseding91
This has been bugging me since the ability to log() during the data stage was added and mostly it's my fault for not accounting for it when it was first added.
Ever since log() was made available during the data stage in Factorio modding mods have been spamming log files. It's so bad that log files end up 10s of thousands of lines adding up to several megabytes worth of useless nothing.
Today while talking with about a bug with another dev it was brought up again and we decided that we want to try to fix it.
My initial plan - unless something better is thought up - is to make log() during data stage do nothing unless you also have --enable-data-log set through the command line. I specifically don't want to make it a config option because it should always be a conscious decision to have it enabled at any point and not something you enable in the config and forget it's enabled.
Another plan (by Bilka): record everything sent through log() during the data stage and if an error is triggered during the data stage or by scenarios then actually write it to the log file. This would also have the --enable-data-log option to force everything to be written instead of buffered.
Re: Fixing data stage spam
Posted: Sun Jun 02, 2019 10:40 pm
by DaveMcW
Why not have log() output to a different file?
Re: Fixing data stage spam
Posted: Sun Jun 02, 2019 11:35 pm
by Nexela
I would love a write_file() in the data stage and I wouldn't have to log!
Re: Fixing data stage spam
Posted: Mon Jun 03, 2019 12:18 am
by Sunnova
please add enable-data-log to the config.ini file instead of the command line, true or false.
Re: Fixing data stage spam
Posted: Mon Jun 03, 2019 1:07 am
by Bilka
This will make mod authors lose viable info when asking for log files from users such as "x mod decided to delete your tile prototypes" which is currently being logged by mod x. For this, and similar "fixing users bugs" reasons, I would prefer to not do the proposed change.
Instead, add something like write file to allow proper debugging without log(), or even a special debug log function that needs the command line parameter that you describe. In the end, you cannot change shitty mods/mod authors that spam logs, they will/can do the same in the control stage. I'd even say that by adding the command line parameter, you make log() spam completely ignorable to mod authors because "it has a command line option". So anyone who has the option on will have even worse log files than before. The annoying overuse of log_debug and ""informational asserts"" in the source code is an example of that dynamic.
Re: Fixing data stage spam
Posted: Mon Jun 03, 2019 1:24 am
by keyboardhack
Maybe write log() to another file(like factorio-current-mods.log) when the game is running and when the game closes/crashes add the log file to the end of the factorio-current.log file. That way the log is still part of the factorio-current.log file but you don't have to look at it unless you scroll down to it. Why append the log to the end of the file? Because uploading two different files is apparently more difficult than uploading one(always assume the end user is stupid) and a mod author may need it to fix any issues with the mod.
Re: Fixing data stage spam
Posted: Mon Jun 03, 2019 5:07 am
by darkfrei
We have script-output folder, why we cannot write the log here?
It makes vanilla log file much lighter and in this way we can make mod parts semi-automatically, for example export locale draft to the file, that can be used as draft for locale for this mod.
Re: Fixing data stage spam
Posted: Mon Jun 03, 2019 7:15 am
by eradicator
Rseding91 wrote: ↑Sun Jun 02, 2019 10:28 pm
My initial plan - unless something better is thought up - is to make log() during data stage do nothing unless you also have --enable-data-log set through the command line. I specifically don't want to make it a config option because it should always be a conscious decision to have it enabled at any point and not something you enable in the config and forget it's enabled.
People will put that into batch files, shortcuts, or steam command line options when the first mod author asks them to do it and then forget about it anyway.
Rseding91 wrote: ↑Sun Jun 02, 2019 10:28 pm
Another plan (by Bilka): record everything sent through log() during the data stage and if an error is triggered during the data stage or by scenarios then actually write it to the log file. This would also have the --enable-data-log option to force everything to be written instead of buffered.
What if someone just wants to look at their mod log without any error happening? Besides it's unexpected behavior to have the log suddenly appear from "nowhere". And the order would probably look weird in a terminal.
Nexela wrote: ↑Sun Jun 02, 2019 11:35 pm
I would love a write_file() in the data stage and I wouldn't have to log!
This, for so many reasons. Writefile should just be always accessible globally in all stages. Having it only *inside* of events is a major limitation. It's not a complete replacement for logging though, when i tell users "send me the log" i don't want to teach them how to find yet another file buried somewhere in /script-output.
Bilka wrote: ↑Mon Jun 03, 2019 1:07 am
This will make mod authors lose viable info when asking for log files from users such as "x mod decided to delete your tile prototypes" which is currently being logged by mod x. For this, and similar "fixing users bugs" reasons, I would prefer to not do the proposed change.
+1000000
The only point i have logging enabled at all in user-builds is bug fixing. I even added a mod-setting to only enable full logging if something really bad happens, and by default it only logs important things. On my dev-build i don't even use log but print() instead. But obviously i can't ask users to run with an attached terminal.
keyboardhack wrote: ↑Mon Jun 03, 2019 1:24 am
Maybe write log() to another file(like factorio-current-mods.log)
+1. Just split it off if you don't want it, but don't kill it for everyone else. Or you could just mark mod made log() entries with some (possibly invisible) control character so you can easily RegEx delete them.
Re: Fixing data stage spam
Posted: Mon Jun 03, 2019 9:20 am
by Deadlock989
Bilka wrote: ↑Mon Jun 03, 2019 1:07 am
This will make mod authors lose viable info when asking for log files from users such as "x mod decided to delete your tile prototypes" which is currently being logged by mod x. For this, and similar "fixing users bugs" reasons, I would prefer to not do the proposed change.
Instead, add something like write file to allow proper debugging without log(), or even a special debug log function that needs the command line parameter that you describe. In the end, you cannot change shitty mods/mod authors that spam logs, they will/can do the same in the control stage. I'd even say that by adding the command line parameter, you make log() spam completely ignorable to mod authors because "it has a command line option". So anyone who has the option on will have even worse log files than before. The annoying overuse of log_debug and ""informational asserts"" in the source code is an example of that dynamic.
+1.
Re: Fixing data stage spam
Posted: Tue Jun 04, 2019 2:36 pm
by mrvn
And often enough I wondered about something mid game and switched to looking at the logs. Now I have to save the game, quit, start with --enable-logs, load the game, hope the bug still or again happens and then remember to start factorio without --enable-logs again next time.
I like the suggestion to log mod output to individual files per mod.
Re: Fixing data stage spam
Posted: Tue Jun 04, 2019 3:06 pm
by Cadde
Why not do this?
Code: Select all
...
Data stage:
{
log()
log()
log()
log()
log()
log()
...
}
This way, any log() output is bracketed in the data stage so you can collapse the brackets in your text editor or whatever else you use.
EDIT: Won't solve the 10 MB file issue though.
Perhaps have a limit on how much log output a single mod is allowed to do in the data stage and use your aforementioned command line switch to remove the limit.
Re: Fixing data stage spam
Posted: Tue Jun 04, 2019 6:49 pm
by eduran
Mods spamming the log file are annoying for sure, but any solution to that would also hit responsible mod authors who deactivate logging for their release builds. Also, out of curiosity: why is it only data-stage spam that you are worried about and not control stage logging?
If you do change it, I vote for one separate log file for mods (e.g. factorio-current-mod.log).
Re: Fixing data stage spam
Posted: Tue Jun 04, 2019 6:53 pm
by darkfrei
eduran wrote: ↑Tue Jun 04, 2019 6:49 pm
Also, out of curiosity: why is it only data-stage spam that you are worried about and not control stage logging?
While mod authors can use
LuaGameScript.write_file for big data.
Re: Fixing data stage spam
Posted: Tue Jun 04, 2019 7:45 pm
by Deadlock989
eduran wrote: ↑Tue Jun 04, 2019 6:49 pm
If you do change it, I vote for one separate log file for mods (e.g. factorio-current-mod.log).
+1.
Re: Fixing data stage spam
Posted: Tue Jun 04, 2019 8:08 pm
by Rseding91
eduran wrote: ↑Tue Jun 04, 2019 6:49 pm
Also, out of curiosity: why is it only data-stage spam that you are worried about and not control stage logging?
Data stage spam is incredibly common (people just log data.raw or portions of it). Runtime control.lua logging doesn't have a super easy huge table to log and so (so far) hasn't been a problem.
Re: Fixing data stage spam
Posted: Wed Jun 05, 2019 7:57 am
by eradicator
Rseding91 wrote: ↑Tue Jun 04, 2019 8:08 pm
eduran wrote: ↑Tue Jun 04, 2019 6:49 pm
Also, out of curiosity: why is it only data-stage spam that you are worried about and not control stage logging?
Data stage spam is incredibly common (people just log data.raw or portions of it). Runtime control.lua logging doesn't have a super easy huge table to log and so (so far) hasn't been a problem.
If that is the main problem an always-available write_file() sounds like the best solution. "People" would migrate on their own because the data dump would be much easier to read without the log decorations.
Re: Fixing data stage spam
Posted: Wed Jun 05, 2019 8:34 am
by Qon
eradicator wrote: ↑Wed Jun 05, 2019 7:57 am
If that is the main problem an always-available write_file() sounds like the best solution. "People" would migrate on their own because the data dump would be much easier to read without the log decorations.
log() is also simpler to write. No file name, no append flag, so trivial that you don't need to look up documentation, shorter name and less to write when you just want to quickly debug something and dump some data. Just wrap the x in log() and you can see its value. And then they forget to remove it or don't care.
Maybe make log write to the mods own log file and introduce a new function that lets us actually log to factorio-current.log with a much longer name. Something like
Code: Select all
log_to_factorio_current_but_only_for_critical_information_and_not_for_data_dumps_and_remember_to_remove_any_needless_use_of_it_for_release_or_Rseding91_will_be_disappointed()
is a good name. Until you put it in another variable with a shorter name... But at least there would be a reminder that you would be forced to see at least once before you use it. So that when I get factorio-current.log I actually get the critical data and don't have to ask them to also submit another file (which will be overwritten by then) or to use command line options and tell them to reproduce the bug again, which they don't want to or can't do.
Re: Fixing data stage spam
Posted: Wed Jun 05, 2019 10:13 am
by Optera
When I need to track errors between LTN and mods subscribing to LTN events having each write to a separate file makes it incredibly hard to get a full picture of what went on.
The same is true for 3rd or 4th degree mods patching another in data stage.
If anything we'd need to log more to get a complete picture. We will end up with every single of these mods dumping data.raw before and after they are done, maybe even several times in between.
Even 10MB for factorio-current.log can be compressed to some kB in an archive. The disk IO of each mod dumping everything into its own file on the other had will get insane.
Instead of making life harder on responsible authors add a way to get rid of crappy mods. Could be as simple as adding a thumbs up/down button in the portal and in game so we can vote badly written mods out.
Re: Fixing data stage spam
Posted: Wed Jun 05, 2019 10:16 am
by darkfrei
Is it possible to use it as log(data, filename)? It can be same Factorio/factorio-current.log or if filename is not nil then Factorio/logs/filename.log
Re: Fixing data stage spam
Posted: Wed Jun 05, 2019 10:25 am
by darkfrei
Optera wrote: ↑Wed Jun 05, 2019 10:13 am
Instead of making life harder on responsible authors add a way to get rid of crappy mods. Could be as simple as adding a thumbs up/down button in the portal and in game so we can vote badly written mods out.
The voting "like-dislike" is the worst solution to get the mod authors right feedback. It's always better to write a message and say what is actually goes wrong with his mod.
If someone has made the first version and it was not good enough, he can make update and it works perfectly. Are old dislikes can give the right information about mod quality?
How many mods was perfect by first release?