-
Notifications
You must be signed in to change notification settings - Fork 58
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Hang sometimes immediately after connecting #75
Comments
Last message before the hang is [server/mod.rs:192][DEBUG] Login, then missing state/models if applicable, likely unrelated. The server eventually times out the connection. Occurs with both release and debug builds. Attaching in lldb, here is a backtrace in release mode - deadlock?:
|
Another observation: when Steven is launched, if it connects to a server and hangs, it takes about 15 seconds before the client is kicked with disconnect.timeout, and the problem persists when reconnecting. What state is generated at startup that could cause this kind of issue? Taking a backtrace in debug mode shows it is in the hasher:
|
The timeout occurs because, as shown with added logging in src/server/mod.rs on_chunk_data(), loading chunks is slower in debug mode. The chunks stop loading as soon as the client is kicked. However, in release mode, the chunks load quickly enough, and the hang occurs later, but since the app is compiled in release mode, debugging symbols are limited (same pthread rwlock wait from steven`steven::main::hac396abb5a81b8e3 + 8880). |
diff --git a/src/server/mod.rs b/src/server/mod.rs
index 1a7cb20..d8764f3 100644
--- a/src/server/mod.rs
+++ b/src/server/mod.rs
@@ -77,6 +77,7 @@ pub struct Server {
sun_model: Option<sun::SunModel>,
target_info: target::Info,
+ loaded_chunks: usize,
}
pub struct PlayerInfo {
@@ -311,6 +312,7 @@ impl Server {
sun_model: None,
target_info: target::Info::new(),
+ loaded_chunks: 0,
}
}
@@ -1088,6 +1090,9 @@ impl Server {
}
fn on_chunk_data(&mut self, chunk_data: packet::play::clientbound::ChunkData) {
+ println!("on_chunk_data about to call self.world.load_chunk19 {}", self.loaded_chunks);
+ self.loaded_chunks += 1;
+ if self.loaded_chunks > 100 && self.loaded_chunks < 300 { return }
self.world.load_chunk19(
chunk_data.chunk_x,
chunk_data.chunk_z,
@@ -1095,7 +1100,9 @@ impl Server {
chunk_data.bitmask.0 as u16,
chunk_data.data.data
).unwrap();
+ println!("on_chunk_data about to update block entities");
for optional_block_entity in chunk_data.block_entities.data {
+ println!("optional_block_entity = {:?}", optional_block_entity);
if let Some(block_entity) = optional_block_entity {
let x = block_entity.1.get("x").unwrap().as_int().unwrap();
let y = block_entity.1.get("y").unwrap().as_int().unwrap();
@@ -1115,6 +1122,7 @@ impl Server {
});
}
}
+ println!("on_chunk_data returning");
}
fn on_chunk_data_no_entities(&mut self, chunk_data: packet::play::clientbound::ChunkData_NoEntities) {
diff --git a/src/world/mod.rs b/src/world/mod.rs
index 9900846..1e14dad 100644
--- a/src/world/mod.rs
+++ b/src/world/mod.rs
@@ -914,7 +914,9 @@ impl World {
chunk.calculate_heightmap();
}
+ println!("about to self.dirty_chunks_by_bitmask");
self.dirty_chunks_by_bitmask(x, z, mask);
+ println!("returned from self.dirty_chunks_by_bitmask");
Ok(())
}
Skipping loading some chunks to speed up game loading, attempting to reproduce in debug mode, but doesn't seem to stick. If this is a timing bug, may have to debug in release mode. |
With debug symbols in release mode, added in Cargo.toml: [profile.release]
debug = true backtrace shows it is in ticking resources. Is this because resources are ticked in the main loop, or an underlying concurrency issue or other bug in resource ticking?
|
let version = {
let mut res = game.resource_manager.write().unwrap();
res.tick(&mut resui, &mut ui_container, delta);
res.version()
}; resource_manager is an
It is indeed hanging on obtaining the mutable reference to the resource lock: --- a/Cargo.toml
+++ b/Cargo.toml
@@ -4,6 +4,9 @@ version = "0.0.1"
authors = [ "Thinkofdeath <thinkofdeath@spigotmc.org>" ]
edition = "2018"
+[profile.release]
+debug = true
+
[profile.dev]
# Steven runs horrendously slow with no optimizations, and often freezes.
# However, building with full -O3 optimizations takes too long for a debug build.
diff --git a/src/main.rs b/src/main.rs
index 22ba351..819c9ab 100644
--- a/src/main.rs
+++ b/src/main.rs
@@ -250,10 +250,14 @@ fn main() {
let (physical_width, physical_height) = window.get_inner_size().unwrap().to_physical(game.dpi_factor).into();
let version = {
+ println!("obtaining mutable reference to resource manager");
let mut res = game.resource_manager.write().unwrap();
+ println!("about to tick resource");
res.tick(&mut resui, &mut ui_container, delta);
+ println!("ticked resources, returning version");
res.version()
};
+ println!("version = {}", version);
let vsync_changed = *game.vars.get(settings::R_VSYNC);
if vsync != vsync_changed { output:
hangs there https://doc.rust-lang.org/std/sync/struct.RwLock.html#method.write
Who else already has the resource manager lock? game.resource_manager is cloned in connect_to(), cloned in main passed to render::Renderer::new, server::Server::dummy_server, Game initialization, and chunk_builder::ChunkBuilder::new. |
Where is resources::Manager used for write() besides in the main loop? I can only find for read():
except in main:
How can RwLock deadlock with only one write()? |
Occasionally, soon after connecting to a server, the game hangs. Sometimes the world is partially rendered:
other times, it is not. If this problem does not occur, the world loads quickly, and reliably and repeatedly when disconnecting and reconnecting.
This may have occurred since the first version of Steven I've tried (specifically, the first version I could run from the
updates1
branch Thinkofname/steven#75), but I've been working around it by relaunching until it doesn't hang. Sometimes this takes several attempts to get a non-hanging launch, very cumbersome. Other times it doesn't hang at all. Race condition?The text was updated successfully, but these errors were encountered: