Refined Storage

Refined Storage

77M Downloads

[1.10.2] Large autocrafting orders cause MAJOR lag

hugeblank opened this issue ยท 57 comments

commented

Issue description:

So, I run a 1.10.2 server with a small amount of players online. We all started for the most part together, and as such, our bases are growing at the same speed. We got to the point where autocrafting was feasible, and immediately ran into issues.

What happens:

We wanted to compress a large LARGE amount of coal that we had collected, and noticed that the server lagged when crafting...HARD. Everyone slows down, and eventually stops moving, chat is slowed, and other common effects of the dreaded server lag.

What you expected to happen:

Not that ^ XD

Steps to reproduce:

  1. Run a server
  2. Create a RSS with an autocrafting setup
  3. Insert a large amount of items that can be crafted
  4. Craft them, and enjoy as your server lags to hell

Version (Make sure you are on the latest version before reporting):

  • Minecraft: 1.10.2
  • Forge: 2185
  • Refined Storage: 1.2.14

Does this issue occur on a server?
Yep.

commented

Could you profile the issue? More info about that: https://refinedstorage.raoulvdberge.com/wiki/profiling

commented

@hugeblank Please run a profiling session while the lag is happening, or I'll have to close this issue because we can't do much otherwise.

commented

@raoulvdberge Yeah I can do that. Give me a few days, other than weekends, I'm not typically free to work on the server.

commented

Please Please Please fix this we are having the same problem. here's what you're asking for
RefinedStorage.nps.zip

commented

at the very end of the sample we stopped it before I had time to turn off the sampler. tell me if you need or want a longer sample.

commented

@linktlh well thank you for doing my work for me! :P

commented

Naw I was just trying to help speed up the process cause I knew you were very busy. :)

commented

Also without you I wouldn't have found what was causing the major lag on my server a user linked this forum after a bit I read it then went around looking for massive amount of auto crafting and sure enough someone was making 5,000 supremium essence. As soon as we canseled it the lag was 100% gone

commented

yeah the essence are quite the task for RS, it is one of those things that are better done before entering RS. But I'll keep trying to improve :p

commented

I feel like I'm gonna have to ban auto crafters for
Here due to this >.> I REALLY don't want to do that...

commented

Yeah I can understand the pain of the decision, seeing as autocrafting is a key component to the mod, and also a desirable feature.

Maybe as a feature request, servers should be able to set a max amount of craftable items. (as a temporary fix to this issue)

commented

OO I like that idea like you can only craft
Custom auto crafting:

"arg1 amount of arg2",
ect

commented

That's not EXACTLY what I was saying, but it would be another cool idea.

My idea was that if someone wanted, let's say, 5 million course dirt to be crafted, it would check the server configs for a limit to the amount of crafting operations that it can do. If it exceeds that amount, then it notifies the player, and begins the operation with the max amount.

commented

#876 should also help with the lag

commented

Still lagging as hell after the #876 fix

Steps to reproduce:

  • Make a very basic RS system with a Controller, a Grid, a Pattern Grid, a Disk Drive, a disk of any size, a Crafter and a Crafting Monitor
  • Put a lot of Coal Blocks on it
  • Create a pattern for the Crafter that crafts Coal from Coal Blocks
  • Start an auto crafting process from your Grid to craft a lot of Coal

Version:

  • RS compiled from branch mc.1.10, commit 3be7adb
  • Forge 1.10.2-12.18.3.2221

VisualVM sampling while crafting coal with the Crafter reported this (33% used by that Controller):
javaw_2017-01-24_23-16-07

And at some point after I stopped the sampling above, it completely stalled and VisualVM sampling reported this (100% writing NBT data forever?):
javaw_2017-01-24_23-30-53

I had to kill the process because after a minute it was still stalled.

commented

@KaiKikuchi How much did you order? And by start an autocrafting process you mean manually or with some redstone activated crafter?

commented

I started the autocrafting process manually by specifying to craft 10000 coal after adding about 2000 coal blocks.

commented

I have no clue why you would be lagging, just did that exact task and my tps didn't dip at all. Running at 3.040 ms and my storage is a colossal chest. Do you have some hardware bottleneck?

commented

Did you try with oredict too @way2muchnoise ?

commented
commented

@KaiKikuchi in the screenshot you posted the main thread is sleeping 50% of the time. And your NBT write is 10ms 10s long. I really have no idea why your CPU would be at 100%.

EDIT: Seems like a comma is used to define decimals so your NBT write is 10s long. That seems like a lot, but that could be something related to your drive speed or what ever is holding back your CPU.

commented

It looks like you're unfamiliar with VisualVM. You don't have to see the ms, because that's based on the entire profile time (27391 ms on the first screenshot, 9960 ms on the second screenshot) so it's not tick based. By doing some math, you can get an average per tick. The average per tick for my test Controller/Crafter, based on data you see on the first screenshot, is 16.85 ms. This is just an average, in fact it comes with lag spikes every X ticks. Probably this happens because the crafter isn't crafting 9 coal every tick, but every 5-10 ticks.

The average TPS per second is not below 20 with just 1 controller (in fact, I haven't said my CPU is at 100%), but you can add 4 or more controllers doing the same thing and, based on my tests, the TPS will drop below 20.

About the second screenshot (stall while writing NBT data), it's probably another bug.

PS: I'm a developer too, and I'm using a computer with quite good performances.
Also I don't have time to waste by reporting fake profiles. Just saying.

EDIT: I used the same world and setup that I had before the fix, so I tried to make a new minecraft world and try the Coal Blocks to Coal pattern again. This time I didn't get any particular issue. Maybe the older version did something bad to the controller.

PS: I'm using a SSD and an i7 as CPU. Nothing else showed on the Task Manager, or I would have noticed it. Also such issue would affect anything, not just this mod while a crafter is doing stuff.

commented

@KaiKikuchi it is not that I'm unfamiliar with it is just that you are posting screenshots and no other information. I can't reproduce your bug in my dev, so there isn't much I can do about it. If you could just post the nps then I could see it in perspective to other things, instead of blindly guessing at a screenshot.

commented

@Ryahn In all of those the biggest offender is Chunk.checkLight which is likely cause by something redrawing the chunk every tick. Are you using any other mods that interact during the autocrafting (I saw some routerreborn stuff in the log)? If yes, could you try without them?

commented

@misterfixit the issue in your case seems to be a slow interaction with the SagMill from eio, when RS tries to insert items it takes a very long time checking if the input is valid. I advice using some buffer chest for but I'll contact the eio devs about this.

commented

TPS per second is redundant as TPS is an acronym for Ticks Per Second
Might want to fix that :P

EDIT: or maybe I'm reading wrong?

commented

https://www.amazon.com/clouddrive/share/QRWQTcr1GHER8z65lm80nouAoCZk81tYfKq6NeyWlsr?ref_=cd_ph_share_link_copy

This is while testing three RS systems crafting 1000 items

  1. was crafting 1000 pistons
  2. was crafting 1000 solar panels from existing materials- aka only crafting patterns
  3. was crafting 1000 solar panels using raw materials and a combo of of processing and crafting patterns.
    The systems were in 3 different parts of the world
commented

Just found out that Forge's SidedInvWrapper is bypassing our "reject fast" code, so we run the full validity check for nothing (but CPU load). The slot is full, there is no need to do any more testing on the input item...

MinecraftForge/MinecraftForge#3658

commented

@HenryLoenwind Is that the sound of a patch coming soon? :D

commented

A patch for Ender IO, yes. We don't need to use the Forge wrapper class, we can supply our own handler with all the optimizations we want. It's in testing right now.

tbh, it is nice that Forge provides wrappers, but any serious item-heavy mod should roll its own handlers.

commented

I have a TPS of 1.112 with 898ms per tick when I craft 20 draconic solar panels. But I can craft 100000 levers, thats the same. :-(

Also A LOT of lag is caused by TileExporter even when it is idling.

commented

been having the same issue on a server and after doing some testing i found that speed upgrades make things alot worse, i had 2 crafters with 4 speed upgrades each (none in the others) and when i took those out autocrafting big orders was having a much smaller tps impact

this even heapens if non of the recipes used in the autocrafting are in the crafter with speed upgrades or not

commented

As far as Ender IO in involved, the latest version should work better. But I'd recommend to wait for build 170, I missed some special cases of machines allowing input slots to be output.

Update: Build 170 is available.

commented

Having the same issue, any update on this?

commented

Same issue. When set to auto-compress items, even if there are no base items to compress, it causes massive lag on the server.

commented

We are working on it.

commented

https://gyazo.com/1caaaf0b9fb9ec73a0d26e4aa9d7c85f
Here is another VisualVM subtree that might help fixing some issues. Running latest Refined Storage on SF3 modpack.

commented

yeah, getOreIDs() is slow. I recently replaced that call in Ender IO with a cached list (SleepyTrousers/EnderIO-1.5-1.12@b33d3fe ), feel free to copy this for RS (CC0).

commented

Any progres on this @raoulvdberge ?

commented

I'm not working on this, @way2muchnoise is. And he is currently recovering from an operation.

commented

Thanks for the update @raoulvdberge

commented

oh darn, I hope you have a quick and easy recovery @way2muchnoise

commented

Take care @way2muchnoise
Hope you get better soon.

In the meanwhile, is there anything you could possibly do? @raoulvdberge this issue is really big and causes a lot of servers to straight out ban the mod.

commented

I said I didn't work on the autocrafting code, stop pushing. Simple solution: stop starting large orders.

commented

Is this still an issue in 1.12.2? If yes, can anyone send some profiling reports my way?

(I know lots of people have posted reports here already - but those were for 1.10.2. I'm interested in NPS files on 1.12 - Thanks)

commented

How DO I post a NPS file? I'm currently having this issue with the DW20 pack on 1.12

commented

https://refinedstorage.raoulvdberge.com/wiki/profiling

You can include the NPS file as a zip through Github uploading.

commented

Ok. I'll do it later this afternoon and upload. Also, The system can't craft Flux capactitors from thermal expansion. It says the lower tiers are missing, even though the system knows how to craft them

commented

That is a separate issue! Please make a new issue for that.

commented

I know you want input contrary to the response I'm providing, but I figure a response is better than none at all: I (so far) haven't had any problems with the 1.12.2 version of RS. However this is the kind of issue I wouldn't instantly stamp off as resolved and close. If you're not totally sure that this should be resolved I'd keep it open until you're certain beyond reasonable doubt. (But I assume that's what you're going to do anyways making a large section of this message pretty much moot...)

commented

2018-01-11_16 19 38
We have exact this Problem with ATM 3 Modpack, updated to the latest RS.
If we start autocrafting 40k iron the forge tps goes up to
about 80ms (normal is about 22ms). On the Server side it skips
ticks (can't keep up! Did the system time change,...). If we stop the autocrafting task it goes back to normal. We also used mekanism furnace same problem.
Find attached the NPS File and the Screenshot of our construction.
Thank you very much

rs.zip

commented

@raoulvdberge Just profiled the very same issue with autocrafting 60k Glass through a Thermal expansion redstone furnace. I have 4 Speed upgrades inside the crafter and a rather fast signalum furnace as you can see in the screenshot.
image
Metainfo:
Modpack: Modern skyblock 2 2.8.1.1 expert mode
version: refinedstorage-1.5.31.jar
rs12.zip

commented

So, I thought I'd provide some input from using this in Modern Skyblock 2 Expert Mode as well.
I have a setup with a lot of craftables. RefinedStorage's controller block seems to be ticking the most out of everything on my server, and I'm thinking it's related to crafting in some way. I'm getting a profile for you set up as I write this.

I'm using RebornStorage to give me a lot of pattern space, and my crafting stuff is mostly in CompactMachines, but the CMs are rather new for me and was lagging before I implemented them. It doesn't specifically happen when I cause a pattern to build.

samples.zip

It seems that something is causing the storage networks to keep rebuilding:

Obviously, by the looks of it, RebornStorage is constantly causing the network to rebuild. @derdotte, are you also using the RebornStorage multiblock crafter?

EDIT: I removed the RebornStorage multiblock crafter and moved them all to individual Crafters. The server is much more stable now. I'll get a profile still just to see if anything has changed here.

EDIT2: Moved to crafters, and it still shows up in the profile but it's not anywhere nearly as bad as it was:

For some reason it still thinks a crafter is just being connected, even though it has constant power and never disconnects.

samples2.zip

commented

@Paril yes, i was using the rebornstorage multiblock crafter, although it was not specifically tasked to craft my 60k glass, as that is a processing pattern which the multiblock is unable to do. So that entirely falls out of the calculation.

commented

In 1.6, crafting tasks that take more than 5 seconds to calculate will not be executed anymore.

commented

Just want to add a "me too" to this thread. I am willing to run profiling/testing/etc if you need/want it.