Let's start out with a hypothesis. If this is incorrect then the rest of the idea is not going to work.

Premise: Most crashes occur because a running script does something it shouldn't (e.g. makes a null pointer reference)

Idea: By temporarily altering all scripts (or some selectable subset thereof) a trace of what was running at the time of the crash can be produced.

Rationale: Knowing where specifically a crash occurred can aid both the player (to have a less buggy experience) and the modder (to aid in the debugging process)

Implementation Needs:
A process to add log statements to the beginning and end of scripts identifying mod and script names.

The logging statement would need to be embedded in a critical section to ensure the write statement was executed before the crash. Could a new OBSE extension be created that supports critical sections?

A process to revert the scripts back to their original form.

Ok, that's about as far as I've gotten to this point. ConScribe looks like it can handle the output part of this already. So, if critical sections are doable, the it just comes down to embedding log statements into scripts on a grand scale.

Since my experience with modding Oblivion to this point consists of cursing at my computer while trying to figure out why I can't get all the mods I want to use to play nicely together (Bossed and Bashed), I would appreciate any of the collective wisdom of the experienced modding community as to whether this would be doable and, if so, useful.

Well, looking at this as a programmer (but not a modder), I'd say it's a pretty simple framework you're proposing... typically you have a "debug" mode that you switch to when you want all of the verbose info you're looking for.

The problem, of course, is how do you get debug info out of scripts that were not writen to produce any? You mention "altering" scripts to do this, but honestly I have no idea how you would go about that. It sure as heck is not going to be "cookie-cutter" work, that's for sure (I can only begin to imagine all of the special cases involved with the ocean of mods out there).

From what I know, it would probably be best to create a framework (using OBSE is probably a good idea, though I'm completely inexperienced with it on a modding level). That will provide a common interface, but will also limit the mods you can get debug info from. Create the framework and make it available to modders. There again, you can't force anyone to use it, but I imagine many would if it were available. Something like that could possibly help to track down those nagging issues that never seem to go away.

Just my $0.02,
veg

My thought was either to use a mini-script parser/decorator to patch the scripts automatically by inserting lines at the top and bottom of the scripts. My limited knowledge says that should work without interfering with the rest of the script's intended purpose. But I am relying on a rudimentary understanding of script syntax restrictions. If, for example nothing can happen before all variable are declared, then, the parser would have to be a bit smarter. Once the offending script was identified extra debug statements could be added by hand to find the actual offending line. Alternatively, we could ask the OBSE guys if they can provide script/entry exit hooks which would really make this simple to implement.

Three things:

1) That parser/decorator would probably be a nightmare to write, and even then would likely miss many special cases. I only say this because I have written many arbitrary parsers myself, and when you have no control over the content you are parsing, the complexity increases dramatically.

2) Even if you could write a "good" parser, there are other issues. What about the rights to alter other modders' code? Can you get permission from them all? Probably not.

3) I don't know if the Oblivion modding framework would even be able to do this. I am no expert, but I can't think of any mods that alter other mods' scripts. There are plugins that replace scripts, but I don't know of any that re-write them.

I don't know... I maybe just don't understand what is available, but this approach seems very problematic to me.

I don't know about altering scripts, but what about an anologue of the ShowQuestVariables console function, which will print the values of any quest script variables. AFAIK quest scripts are the only sort that run all the time, and so are the only ones that would not be simple to track down normally (ie. if you cast a spell and the game crashes, it's obvious the spell is bugged, but a quest script can bug at any time).

I know jack and squat about programming, so apologies if this is dumb:

Instead of trying to alter every script with additional code, would it be possible to create a log showing each script that executes so you could look at the log and see something like:

...6/02/10 20:30:15 OOOHelmetOfRudeness.scr6/02/10 20:30:16 AllNaturalRainOnYourParade.scr6/02/10 20:30:18 BobsUnstableMod.scrend of file

That way you could find the culprit.

Of course it would be nice if this log was only a few lines long and not a record of every script that executes ever. Maybe it could rewrite itself so it's not a million lines long.

Now that is a great idea! You'd be using info that's already there...

In my professional capacity I have constructed similar instrumentation systems embedded within Visual Studio to instrument C# code in the past, as a method of post-hoc crash anolysis. There are however a number of challenges associated with it. While the actual task of auto-instrumenting scripts is not challenging (though hardly trivial), the massive overhead of including this amount of IO would create a severe performance issue. I'd be very wary about attempting this - a large number of OB scripts do nothing for most of the time, only kicking in at relevant moments. A system like this would cause every one of those "empty" scripts to have to run and dump data. That may end up causing unanticipated issues and actually crash the game giving false positives.

Note that I'm not saying it's a bad idea, but perhaps you'd need to limit it to instrumenting a subset of the scripts at any given time.

Another non-programmer here. What's wrong with Pimp's idea? Sounds like a good "let the air out of the tires to free the truck" proposal.

Thaellar

An important point, this. I'm not sure how you'd go about narrowing it down to just those scripts that ran at the time of crash though. If it's possible to get the stuff to run only when the game crashes and only collect info from scripts that just ran when it crashed, this could be pretty good.

Pimpskinny's idea is pretty good too though, giving you a list of potential causes which you can then investigate in more detail - perhaps this could be part of a two-depth debug, where the first level identifies potential causes, and then you can activate a second level in an ini or something that will print out the detailed variable information?

Just to note that in such things as this, I am also a non-programmer.

There's nothing wrong with any of the ideas, but you have practical concerns dealing with what is available and, as HeX_0ff aptly pointed out, the balance between providing something useful and demanding even more of the system and inevitably bogging it down.

When I first read this, I envisioned something that would not run all the time. Rather, you would enable it when you were having problems, understanding that there will be a performance hit. I work with Web applications, and by their very nature they don't have much room for debugging and verbose logging. If the debugging aspects were turned on all the time, our sites would be practically unusable due to the performance hit. So naturally I was thinking of this in the same way. It may be possible to create something that runs constantly while you're playing, but almost certainly not without a performance hit.

My approach would be to create something that you use only when needed. If the user knows s/he is in a diagnostic mode, they will likely accept poor performance in order to solve the problem. Further, if you can create this thing with those expectations in mind, you can go after what you really need without having to worry about hurting game performance.

veg

EDIT: added quote for reference

You may be correct. I don't know. However, unless the scripts have very strict syntax rules (which I don't think they do), adding a line of code to execute before and after the main body of the script should be straightforward and quite doable.


Since you are not proposing to distribute the "altered" code, rights do not come into play. We currently clean other modders' mods without their permission. This would be a very similar process.


Since we have direct access to the script, we can treat it as data and do whatever we want to it. The question as I see it more along the lines of can the debug line be dumped to a file before a crash happens (hence the question about the viability of critical sections).


Sorry, it's the best one I can come up with to address what I see as a glaring lack in the Oblivion extension implementation.



Actually casting a spell could tweak a problem in a running script and cause the game to crash as a side effect rather than a direct effect of the spell. The goal for me is to get a better of idea of what the game was doing when the crash happened. I've used automated decoration of code in the past to address similar problems. I don't know if it will work here.



This was the only way I could come up with to create that log. I don't see anything currently in Oblivion that would support generating the log entries unless we add something like this.


Point taken. I think some experimentation will let us know how bad this would make things. It's certainly a good idea to be able to limit the scripts being checked anyway so as to lessen the size of the logfile. Somewhere I had some stats on the cost of disk writes but I haven't looked at it in years. And clearly you'd only want to run something like this when you are trying to diagnose a problem.


Thank you all for all the feedback so far. Hopefully, together, we'll be able to design something that will work.

Yea that would be good. That's how I use FormID. I only install it when I find a missing mesh.

This would be a great accomplishment. I once shredded my build trying to find out why I couldn't enter the Arcane University. Months later read a little update saying it was Mayu's Animation Overhaul. Random. Never would've suspected that.

Yes, I never thought of adding something that ran all the time. I'm hopeful (but not certain) that we can get it to run at all. One of the other issues is to make sure we can cleanly restore the original mods without borking the user's setup.

One fast cut approach might be to turn it on for individual mods. The ID of the script should tell you which mod it's from then only instrument those that are selected. That way you can bypass running it on all the vanilla scripts for example, or just check out the ones from specific mods.

Being able to do this would be an invaluable tool for script-heavy mod developers like myself. I have a lot debug statements, but it's a pain to create them in such a way that they can easily be switched on and off, and I tend to pull a lot of them out before releasing, since it adds a lot of unnecessary overhead having so many conditional print statements.

I's suggest that you might want to liase directly with shademe, since this feels like something that could be a part of conscribe, and he's already doing extensive work on extending the CS.

I like discussions like this because I've been around programmers long enough to know that not long after the sound of O'Reilly books being cracked open something useful usually emerges. :celebration:

Thaellar

I think that that is not quite true... many crashes due occur from script errors but many others from other problems... but enough crashes from script failures to be worthwhile I think.

1. I can do that very easily... with limited performance hit too (havent used ConScribe - which I aggree would be the best writer for the log - so can't say exactly how much hit it would create).. and for whatever mods are active, have scripts and are selected.
2. easy too
3. just unload the Bashed Patch
... Basically I would make another section of the Bashed Patch which would be named hmm something or other short and clear (not my strongsuit - any suggestions), and if the user has OBSE, ConScribe and the enableadvanced setting in Bash set to True, then it would be available, in which case it would have a list of all active mods with options of when to save info (ie just on gamemode, just on menu mode, all begin types); when run this patcher would then copy all selected mod's scripts to the bashed patch (as override ofc) then edit the compiled script to insert this information at the top of gamemode/menumode/all begin blocks.
So it would be fairly easy... if people like that idea it could almost certainly go into Wrye Bash 286.
What it couldn't do via that method would be to do conditional statements like 'if var x == z:'... but would point to problem scripts for hand bug hunting.
Pacific Morrowind

Performance is really going to be an issue if you plan to print debug messages. ConScribe itself should have trouble coping with the amount of output instructions your proposed implementation would spew, as I flush the log stream after each write (essentially after each message to the console). This can be taken care of on my end but you'd still have to worry about the game's performance.

In any case, here's what you could try - Hook at the IOManager's task queue processor (likely to need decoding), walk through the queue, pick out any QueuedReference, QueuedFileEntry(assuming quest scripts are run through this task object) (or figure out a way to get the task being processed currently) and dump your diagnostic messages. I don't think you'll be able to modify script contents directly as the runtime compiler is rather limited when it comes to local variables and such. You can however get the script data from the queued object's extradata list.

Note that this is entirely hypothetical as I'm basing it on nothing more than a minute's worth of going through OBSE's code. scruggsy should give you a more concrete answer.

With CSE's perprocessor, you can do it with relative ease. Something like:

scn test//define _DEBUG 1begin gameMode; super awesome codeif _DEBUG   printC "Debug message"endIfend

PM me if you'd like to try out the latest build.

I am giddy with excitement. I hadn't thought of using the patch this way, but it makes perfect sense. Only question I have is: how can you insure the new lines are executed as critical sections? I see you class that as easy; so I'm just looking for reassurance.




Perhaps forking an I/O thread would lessen some of the hit? It sounds like using PacificMorrowind's selective decoration approach and the bashed patch would give us the ability to test various backend logging implementations and see how we scale without making a major programming investment. It's been a while, but I'd be happy to look at any code to see if I can help solve bottlenecks (I used to be pretty good at making things go fast).

Thank you so much for moving this along so quickly.

RB

If I understand PacMo correctly, he intends to use Bash's bashed patch feature to add the logging script code to the active scripts before the game even starts.

That remains to be seen. Remember that a lot of scripts are queued every frame - Even adding a couple of Console_Print calls can cause a noticeable performance hit.

Wow! When I entered this conversation I had no idea it would head towards such low levels as forks and frames! This is where working with interpreted languages has limited me somewhat, to be sure...

Still, I have to ask... you Oblivion modders frequently manipulate frames and fork threads? Really? I had no idea you were able to get that low in the system through modding the game! Seriously... I am completely ignorant (as if that weren't abundantly clear already! lol) That is pretty far out... I had no idea.

Now I'm scared...
veg :ahhh:

Frequently? No, not at all. Very few modders work at that low a level since it requires the ability to reverse engineer parts of the game (as far as placing hooks and decoding data structures is reverse engineering). I'd be surprised if there were more than 10 active members that do so. Those that do so tend to be pretty talented

Well, to be honest, these fine folks are the last I'd be afraid of... outside the realm of TES, that is! Still, I am surprised to learn that you can get in that deep through ESPs, ESMs, and BSAs. I truly am ignorant about the finer points of these, (that wasn't a joke, ha, ha! ) but I never would have thought that. I assumed something more restrictive. But, as they say, you learn something every day!

As for talent, well, what can I say besides... :bowdown:

EDIT: Did that first sentence come across right? Nothing but the utmost respect for mad modding skillz should be inferred there!

Ah, I see the confusion now. You can't get that deep with esp/esm/bsa files. You have to write an OBSE plugin (or patch the executable itself, but that's bad form).

Oh for [something]'s sake! Those are DLLs, aren't they? Well, don't I feel foolish... And I even mentioned OBSE myself! :facepalm:

Thanks! Slowly, the fog begins to lift...

EDIT: And that's the second time I have failed to thank you for TQP! Can't live without it!