Long delay between "finished patching" and "writing output .esp"

[ghost]

Hey Piranha, there seems to be some kind of problem while running SynthEBD with record caching disabled and a large number of NPCs, Mix-Ins and Asset Packs.
I'm trying to run a stress test on a setup with 15k NPCs, 19 Primary Asset Packs, 4 Mix-Ins and a number of bodyslides. Patcher runs are taking around 2 hours with caching disabled, but I'm not getting that output writing message, no matter how much I wait. Yesterday I've left the patcher running overnight, and there was no "writing .esp" message in the morning. Trying again today, and it has been around 20 minutes since the 'finished patching' message, and still nothing.

Any ideas about what's happening?

Just for the record, this has also happened to me twice before, some 4-5 releases back, but running the patcher again usually solved the problem. This time I think all the new additions might be exacerbating the problem.

[Piranha91]

Do you see the asset assignment statistics? After the "Finished Patching" message, the following actions occur:

1: Write combination log to file (LogFolder\DateTime\Generated Combinations.txt)
2: Write BodyGen or OBody/AutoBody output files
3: If headparts are assigned, check if a face texture exists for each NPC. If not, forward it from the default Race head texture. If that also doesn't exist, warn the user
4: Write headparts output json
5: Write the asset assignment report to the logger (e.g.:

Primary asset pack assignment counts:
Argonian Male: 0 of 37 (0.00%)
Breton Male: 278 of 278 (100.00%)
etc...

6: Write the output .esp.

Which step is it hanging at? Also, are you just running with cacheing disabled to stress test?

Edit: Thinking about it a bit more, I can imagine it hanging during step 1 (when compiling the combination log it lists all records related to the combination; I can see it getting overwhelmed there) or during step 6 (unlikely, but maybe too many records trying to get written the output file). #1 can be tested by turning off the combination log in the TexMesh settings. I don't see any reason why the number of generated records would affect steps 2-5.

[ghost]

The last message is finished patching, nothing more beyond that. Now, after some more investigating, I think I might be having MO2 or Windows related issues again...

This time I've restarted Windows and left the patcher running overnight. In the morning, the last message was still "finished patching". I navigated through some menus and ignored the app for a moment. Later, I checked again, and somehow it got "unstuck", and processed everything pending, got all the remaining messages, without any input from me... really strange.
Maybe MO2 was having trouble letting SynthEBD write to disk? That's strange because it was succesfully writing verbose logs for various NPCs during patching...

I think a good idea would be to print a message for each of those steps, to give us an idea of where the patcher is. I've seen other users also getting confused by this delay and concluding that the patcher wasn't working, when in reality, it was just taking its sweet time 😄

Edit.: Oh and I'm running without cache just to test. With cacheing enabled, I haven't found any wrongly assigned records like other users reported, yet.

[Piranha91]

Added the requested logging in 0.9.4.5.

[ghost]

Thanks Piranha, but looks like I'm not getting the new logging:

Did I miss a toggle somewhere? Or I guess, it hanged again lol

Edit. Oh, just noticed the last line is actually from the new logging. So it hanged again. I'll rerun the patcher to be sure.

[ghost]

Okay, tried two big patcher runs, and can now confirm that patcher only hangs during the first step of writing combination log. Turning it off in the TexMesh settings skips the .txt writing and solves the problem 👍

[Piranha91]

Cool, I’ll try to take a look at some point and see what the combination log doesn’t like. Thanks for tracking it down.