Combined trains break apart after server restarting

[BiDuang]

English is not my native language; please excuse typing errors.

Info

Please provide the following information:

• BkCommonLib Version (/train version): 1.20.2-v1 (build: 1464)
• TrainCarts Version (/train version): v1.20.2-v1 (build: 1634)
• Server Type and Version (/version): git-Paper-280 (MC: 1.20.2)

---

Bug

Description

Combination trains running on loop lines will malfunction after a server restart. For example, carts will disconnect from each other and became a new train.

Before restart:

After restart:

You can see that some train got new children.

Steps to reproduce

Just restart the server and do nothing.

[bergerkiller]

Where the trains revert, is that near to the spawn area of the server, and is the spawn kept loaded? Do the trains have keepchunksloaded on?

[BiDuang]

Where the trains revert, is that near to the spawn area of the server, and is the spawn kept loaded? Do the trains have keepchunksloaded on?

Some of them near the spawn area, but not very close(maybe about 100-200 blocks away?)

And yes, each train has enabled keepchunksloaded to ensure it can running on a circle line.

[bergerkiller]

And /train startuplog doesnt show any errors at startup when this happens? Its going to be difficult to figure out when/what causes it. Not easy to reproduce on my end anyways

[BiDuang]

And /train startuplog doesnt show any errors at startup when this happens? Its going to be difficult to figure out when/what causes it. Not easy to reproduce on my end anyways

Yes, nothing goes wrong in the log:

====================================================
Date: Friday, November 10, 2023 GMT+8
Server: git-Paper-280 (MC: 1.20.2) (JDK 17.0.6+9-LTS-190)
Relevant plugins:
  - BKCommonLib 1.20.2-v1 (build: 1634) (jar: BKCommonLib-1.20.2-v1-1634.jar)
  - Train_Carts 1.20.2-v1 (build: 1464) (jar: TrainCarts-1.20.2-v1-1464.jar)
====================================================

---- Plugin logs ----
[10:26:13] [INFO] [BKCommonLib] Loading server plugin BKCommonLib v1.20.2-v1
[10:26:23] [INFO] [Train_Carts] 0 detector rail regions loaded covering 0 blocks
[10:26:25] [INFO] [BKCommonLib] Enabling BKCommonLib v1.20.2-v1
[10:26:26] [INFO] [BKCommonLib] BKCommonLib is running on Paper (git-Paper-280) : v1_20_R2 (Minecraft 1.20.2)
[10:26:26] [INFO] [BKCommonLib.Network] Now using the ProtocolLib library to provide Packet Listener and Monitor support
[10:26:26] [INFO] [BKCommonLib] Supplier supplying suppliers for your lazy needs!
[10:26:26] [INFO] [BKCommonLib] BKCommonLib version 1.20.2-v1 (build: 1634) enabled! (0.871s)
[10:26:28] [INFO] [BKCommonLib] [RegionChangeTracker] Region block changes will be notified from WorldEdit (>= v7.0.0)
[10:26:29] [INFO] [BKCommonLib] ViaVersion detected, will use it to detect player game versions
[10:26:29] [INFO] [Train_Carts] Enabling Train_Carts v1.20.2-v1
[10:26:33] [INFO] [Train_Carts] [Resource Pack Models] Loading resource pack item model lists
[10:26:33] [INFO] [Train_Carts] SignLink detected, support for arrival signs added!
[10:26:34] [INFO] [Train_Carts] 12 Trains have been loaded in 1 world. (240 Minecarts)
[10:26:34] [INFO] [Train_Carts] Restoring trains and loading nearby chunks...
[10:26:43] [INFO] [Train_Carts] Train_Carts version 1.20.2-v1 (build: 1464) enabled! (13.178s)
[10:26:43] [INFO] [Train_Carts] SignLink detected, support for arrival signs added!

---- Miscellaneous server logs ----
[10:26:24] [INFO] [Minecraft] Server permissions file permissions.yml is empty, ignoring it
[10:26:44] [INFO] [Minecraft] [CoreProtect] 使用 SQLite 用于数据存储。
[10:26:44] [INFO] [Minecraft] --------------------
[10:26:44] [INFO] [Minecraft] [CoreProtect] 对 CoreProtect 感到满意吗？请加入我们的 Discord 频道！
[10:26:44] [INFO] [Minecraft] [CoreProtect] Discord: www.coreprotect.net/discord/
[10:26:44] [INFO] [Minecraft] --------------------
[...]
[10:26:44] [INFO] [Minecraft] [CoreProtect] 与 WorldEdit 的交互已成功初始化。
[10:26:45] [INFO] [Minecraft] Timings Reset

This issue occurs every time the server starts. I have updated all plugins and server core but the problem is not resolved.

[BiDuang]

I suspect this error occurs during the save or restore phase. Because if you don't reboot the server, then everything will be fine.

[bergerkiller]

Can you stop the server and upload the latest.log generated at that point? Its possible the server did not properly shut down (and save). So it should show the plugins disabling and worlds saving before the server shuts off.

[BiDuang]

Can you stop the server and upload the latest.log generated at that point? Its possible the server did not properly shut down (and save). So it should show the plugins disabling and worlds saving before the server shuts off.

Sure, there's the log:

[16:37:46 INFO]: There are 11 trains on this server (of which 8
[16:37:46 INFO]:  are moving)
[16:37:46 INFO]: There are 336 minecart entities
[16:37:46 INFO]: The following trains exist on this server:
[16:37:46 INFO]: L1-1 / L1-2 / L1-3 / L2-1 / L2-2 / L2-3 / L2-4 / L2-5
[16:37:46 INFO]: L2-6 / L2-7 / woolfact
[16:37:52 INFO]: Stopping the server
[16:37:52 INFO]: Stopping server
[16:37:52 INFO]: [AntiPopup] Disabling AntiPopup v7
[16:37:52 INFO]: [AntiPopup] Disabled PacketEvents.
[16:37:52 INFO]: [Chunky] Disabling Chunky v1.3.92
[16:37:52 INFO]: [CoreProtect] Disabling CoreProtect v22.2
[16:37:52 INFO]: [CoreProtect] 正在完成数据记录，请稍等...
[16:37:53 INFO]: [CoreProtect] 禁用 CoreProtect v22.2 成功！
[16:37:53 INFO]: [GravityControl] Disabling GravityControl v2.0.0
[16:37:53 INFO]: [Images] Disabling Images v2.3.1
[16:37:53 INFO]: [ResourcePack-Plugin] Disabling ResourcePack-Plugin v1.7.3
[16:37:53 INFO]: [ResourcePack-Plugin] ResourcePack-plugin has been disabled!
[16:37:53 INFO]: [SeeMore] Disabling SeeMore v1.0.2
[16:37:53 INFO]: [TabTPS] Disabling TabTPS v1.3.21
[16:37:53 INFO]: [Train_Carts] Disabling Train_Carts v1.20.2-v1
[16:37:54 INFO]: [Train_Carts] Train_Carts disabled!
[16:37:54 INFO]: [ViaBackwards] Disabling ViaBackwards v4.8.1
[16:37:54 INFO]: [BlueMap] Disabling BlueMap v3.17
[16:37:54 INFO]: [BlueMap] Stopping...
[16:37:54 INFO]: [BlueMap] Saved and stopped!
[16:37:54 INFO]: [WorldEdit] Disabling WorldEdit v7.2.17+6544-56d0383
[16:37:54 INFO]: [BKCommonLib] [RegionChangeTracker] Region block changes will no longer be notified from WorldEdit (>= v7.0.0)
[16:37:54 INFO]: Unregistering com.sk89q.worldedit.bukkit.BukkitServerInterface from WorldEdit
[16:37:54 INFO]: [SignLink] Disabling SignLink v1.20.2-v1
[16:37:54 INFO]: [SignLink] SignLink disabled!
[16:37:54 INFO]: [Vault] Disabling Vault v1.7.3-b131
[16:37:54 INFO]: [BKCommonLib] Disabling BKCommonLib v1.20.2-v1
[16:37:54 INFO]: [PlaceholderAPI] Disabling PlaceholderAPI v2.11.5
[16:37:54 INFO]: [LuckPerms] Disabling LuckPerms v5.4.82
[16:37:54 INFO]: [LuckPerms] Starting shutdown process...
[16:37:54 INFO]: [LuckPerms] Closing storage...
[16:37:54 INFO]: [LuckPerms] Goodbye!
[16:37:54 INFO]: [ProtocolLib] Disabling ProtocolLib v5.1.1-SNAPSHOT-673
[16:37:54 INFO]: [ViaVersion] Disabling ViaVersion v4.8.1
[16:37:54 INFO]: [ViaVersion] ViaVersion is disabling, if this is a reload and you experience issues consider rebooting.
[16:37:54 INFO]: Saving players
[16:37:54 INFO]: Saving worlds
[16:37:54 INFO]: Saving chunks for level 'ServerLevel[world]'/minecraft:overworld
[16:37:54 INFO]: [ChunkHolderManager] Waiting 60s for chunk system to halt for world 'world'
[16:37:54 INFO]: [ChunkHolderManager] Halted chunk system for world 'world'
[16:37:54 INFO]: [ChunkHolderManager] Saving all chunkholders for world 'world'
[16:37:55 INFO]: [ChunkHolderManager] Saved 330 block chunks, 774 entity chunks, 0 poi chunks in world 'world' in 0.62s
[16:37:55 INFO]: ThreadedAnvilChunkStorage (world): All chunks are saved
[16:37:55 INFO]: Saving chunks for level 'ServerLevel[world_nether]'/minecraft:the_nether
[16:37:55 INFO]: [ChunkHolderManager] Waiting 60s for chunk system to halt for world 'world_nether'
[16:37:55 INFO]: [ChunkHolderManager] Halted chunk system for world 'world_nether'
[16:37:55 INFO]: [ChunkHolderManager] Saving all chunkholders for world 'world_nether'
[16:37:55 INFO]: [ChunkHolderManager] Saved 400 block chunks, 160 entity chunks, 0 poi chunks in world 'world_nether' in 0.45s
[16:37:55 INFO]: ThreadedAnvilChunkStorage (DIM-1): All chunks are saved
[16:37:55 INFO]: Saving chunks for level 'ServerLevel[world_the_end]'/minecraft:the_end
[16:37:55 INFO]: [ChunkHolderManager] Waiting 60s for chunk system to halt for world 'world_the_end'
[16:37:55 INFO]: [ChunkHolderManager] Halted chunk system for world 'world_the_end'
[16:37:55 INFO]: [ChunkHolderManager] Saving all chunkholders for world 'world_the_end'
[16:37:55 INFO]: [ChunkHolderManager] Saved 1 block chunks, 5 entity chunks, 0 poi chunks in world 'world_the_end' in 0.02s
[16:37:55 INFO]: ThreadedAnvilChunkStorage (DIM1): All chunks are saved
[16:37:55 INFO]: ThreadedAnvilChunkStorage: All dimensions are saved
[16:37:55 INFO]: Flushing Chunk IO
[16:37:55 INFO]: Closing Thread Pool
2023-11-14 16:37:55,868 Log4j2-AsyncAppenderEventDispatcher-1-Async WARN Advanced terminal features are not available in this environment
[16:37:55 INFO]: Closing Server

Starting org.bukkit.craftbukkit.Main
System Info: Java 17 (Java HotSpot(TM) 64-Bit Server VM 17.0.6+9-LTS-190) Host: Windows 11 10.0 (amd64)
Loading libraries, please wait...
2023-11-14 16:38:56,772 ServerMain WARN Advanced terminal features are not available in this environment
[16:38:59 INFO]: Environment: Environment[accountsHost=https://api.mojang.com, sessionHost=https://sessionserver.mojang.com, servicesHost=https://api.minecraftservices.com, name=PROD]
[16:39:00 INFO]: Loaded 7 recipes
[16:39:00 INFO]: Starting minecraft server version 1.20.2
[16:39:00 INFO]: Loading properties
[16:39:00 INFO]: This server is running Paper version git-Paper-280 (MC: 1.20.2) (Implementing API version 1.20.2-R0.1-SNAPSHOT) (Git: 4675152)
[16:39:01 INFO]: Server Ping Player Sample Count: 12
[16:39:01 INFO]: Using 4 threads for Netty based IO
[16:39:01 WARN]: [!] The timings profiler has been enabled but has been scheduled for removal from Paper in the future.
    We recommend installing the spark profiler as a replacement: https://spark.lucko.me/
    For more information please visit: https://github.com/PaperMC/Paper/issues/8948
[16:39:01 INFO]: [ChunkTaskScheduler] Chunk system is using 1 I/O threads, 5 worker threads, and gen parallelism of 5 threads
[16:39:01 INFO]: Default game type: SURVIVAL
[16:39:01 INFO]: Generating keypair
[16:39:01 INFO]: Starting Minecraft server on *:25565
[16:39:01 INFO]: Using default channel type
[16:39:01 INFO]: Paper: Using Java compression from Velocity.
[16:39:01 INFO]: Paper: Using Java cipher from Velocity.
[16:39:01 INFO]: [SpigotLibraryLoader] [AntiPopup] Loading 1 libraries... please wait
[16:39:01 INFO]: [SpigotLibraryLoader] [AntiPopup] Loaded library D:\MCSManager\daemon\data\InstanceData\19474cdaca8245f4ae1764d280385f04\libraries\dev\dejvokep\boosted-yaml-spigot\1.3\boosted-yaml-spigot-1.3.jar
[16:39:01 INFO]: [ViaVersion] Loading server plugin ViaVersion v4.8.1
[16:39:01 INFO]: [ViaVersion] ViaVersion 4.8.1 is now loaded. Registering protocol transformers and injecting...
[16:39:01 INFO]: [ViaVersion] Loading block connection mappings ...
[16:39:01 INFO]: [ViaVersion] Using FastUtil Long2ObjectOpenHashMap for block connections
[16:39:02 INFO]: [ViaBackwards] Loading translations...
[16:39:02 INFO]: [ViaBackwards] Registering protocols...
[16:39:02 INFO]: [ProtocolLib] Loading server plugin ProtocolLib v5.1.1-SNAPSHOT-673
[16:39:03 INFO]: [LuckPerms] Loading server plugin LuckPerms v5.4.82
[16:39:04 INFO]: [PlaceholderAPI] Loading server plugin PlaceholderAPI v2.11.5
[16:39:04 INFO]: [BKCommonLib] Loading server plugin BKCommonLib v1.20.2-v1
[16:39:09 WARN]: [org.bukkit.craftbukkit.v1_20_R2.legacy.CraftLegacy] Initializing Legacy Material Support. Unless you have legacy plugins and/or data this is a bug!
[16:39:15 INFO]: [Vault] Loading server plugin Vault v1.7.3-b131
[16:39:15 INFO]: [SignLink] Loading server plugin SignLink v1.20.2-v1
[16:39:15 INFO]: [WorldEdit] Loading server plugin WorldEdit v7.2.17+6544-56d0383
[16:39:15 INFO]: Got request to register class com.sk89q.worldedit.bukkit.BukkitServerInterface with WorldEdit [com.sk89q.worldedit.extension.platform.PlatformManager@6b5fb7a4]
[16:39:15 INFO]: [BlueMap] Loading server plugin BlueMap v3.17
[16:39:15 INFO]: [ViaBackwards] Loading server plugin ViaBackwards v4.8.1
[16:39:15 INFO]: [Train_Carts] Loading server plugin Train_Carts v1.20.2-v1
[16:39:16 INFO]: [Train_Carts] 0 detector rail regions loaded covering 0 blocks
[16:39:16 INFO]: [TabTPS] Loading server plugin TabTPS v1.3.21
[16:39:16 INFO]: [SeeMore] Loading server plugin SeeMore v1.0.2
[16:39:16 INFO]: [ResourcePack-Plugin] Loading server plugin ResourcePack-Plugin v1.7.3
[16:39:16 INFO]: [Images] Loading server plugin Images v2.3.1
[16:39:16 INFO]: [GravityControl] Loading server plugin GravityControl v2.0.0
[16:39:16 INFO]: [CoreProtect] Loading server plugin CoreProtect v22.2
[16:39:16 INFO]: [Chunky] Loading server plugin Chunky v1.3.92
[16:39:16 INFO]: [AntiPopup] Loading server plugin AntiPopup v7
[16:39:16 INFO]: [AntiPopup] Loaded PacketEvents.
[16:39:16 INFO]: Server permissions file permissions.yml is empty, ignoring it
[16:39:16 INFO]: [ProtocolLib] Enabling ProtocolLib v5.1.1-SNAPSHOT-673
[16:39:16 INFO]: [LuckPerms] Enabling LuckPerms v5.4.82
[16:39:17 INFO]:         __    
[16:39:17 INFO]:   |    |__)   LuckPerms v5.4.82
[16:39:17 INFO]:   |___ |      Running on Bukkit - Paper
[16:39:17 INFO]: 
[16:39:17 INFO]: [LuckPerms] Loading configuration...
[16:39:17 INFO]: [LuckPerms] Loading storage provider... [H2]
[16:39:18 INFO]: [LuckPerms] Loading internal permission managers...
[16:39:18 INFO]: [LuckPerms] Performing initial data load...
[16:39:18 INFO]: [LuckPerms] Successfully enabled. (took 1652ms)
[16:39:18 INFO]: [BKCommonLib] Enabling BKCommonLib v1.20.2-v1
[16:39:18 INFO]: [BKCommonLib] BKCommonLib is running on Paper (git-Paper-280) : v1_20_R2 (Minecraft 1.20.2)
[16:39:18 INFO]: [BKCommonLib.Network] Now using the ProtocolLib library to provide Packet Listener and Monitor support
[16:39:19 INFO]: [BKCommonLib] Bringing home the bacon since 2011!
[16:39:19 INFO]: [BKCommonLib] BKCommonLib version 1.20.2-v1 (build: 1634) enabled! (1.154s)
[16:39:19 INFO]: [Vault] Enabling Vault v1.7.3-b131
[16:39:19 INFO]: [Vault] [Permission] SuperPermissions loaded as backup permission system.
[16:39:19 INFO]: [Vault] Enabled Version 1.7.3-b131
[16:39:19 INFO]: [LuckPerms] Registered Vault permission & chat hook.
[16:39:19 INFO]: [WorldEdit] Enabling WorldEdit v7.2.17+6544-56d0383
[16:39:19 INFO]: Registering commands with com.sk89q.worldedit.bukkit.BukkitServerInterface
[16:39:20 INFO]: WEPIF: Vault detected! Using Vault for permissions
[16:39:20 INFO]: Using com.sk89q.worldedit.bukkit.adapter.impl.v1_20_R2.PaperweightAdapter as the Bukkit adapter
[16:39:21 INFO]: [BKCommonLib] [RegionChangeTracker] Region block changes will be notified from WorldEdit (>= v7.0.0)
[16:39:21 INFO]: [ResourcePack-Plugin] Enabling ResourcePack-Plugin v1.7.3
[16:39:21 INFO]: [ResourcePack-Plugin]  ===============================================
[16:39:21 INFO]: [ResourcePack-Plugin]           ResourcePack-plugin launched!!
[16:39:21 INFO]: [ResourcePack-Plugin]              By CokeFenya And Fess_
[16:39:21 INFO]: [ResourcePack-Plugin]                   Version: 1.5
[16:39:21 INFO]: [ResourcePack-Plugin]              The plugin was created:
[16:39:21 INFO]: [ResourcePack-Plugin]            https://github.com/CokeFenya
[16:39:21 INFO]: [ResourcePack-Plugin]  ===============================================
[16:39:21 INFO]: Preparing level "world"
[16:39:22 INFO]: Preparing start region for dimension minecraft:overworld
[16:39:23 INFO]: Time elapsed: 528 ms
[16:39:23 INFO]: Preparing start region for dimension minecraft:the_nether
[16:39:23 INFO]: Time elapsed: 40 ms
[16:39:23 INFO]: Preparing start region for dimension minecraft:the_end
[16:39:23 INFO]: Time elapsed: 44 ms
[16:39:23 INFO]: [ViaVersion] Enabling ViaVersion v4.8.1
[16:39:23 INFO]: [ViaVersion] ViaVersion detected server version: 1.20.2 (764)
[16:39:23 INFO]: [BKCommonLib] ViaVersion detected, will use it to detect player game versions
[16:39:23 INFO]: [PlaceholderAPI] Enabling PlaceholderAPI v2.11.5
[16:39:23 INFO]: [PlaceholderAPI] Fetching available expansion information...
[16:39:23 INFO]: [SignLink] Enabling SignLink v1.20.2-v1
[16:39:24 INFO]: [PlaceholderAPI] Successfully registered internal expansion: signlink [1.20.2-v1]
[16:39:24 INFO]: [PlaceholderAPI] Successfully registered internal expansion: sl [1.20.2-v1]
[16:39:24 INFO]: [SignLink] SignLink version 1.20.2-v1 (build: 89) enabled! (0.115s)
[16:39:24 INFO]: [BlueMap] Enabling BlueMap v3.17
[16:39:24 INFO]: [BlueMap] Loading...
[16:39:24 INFO]: [ViaBackwards] Enabling ViaBackwards v4.8.1
[16:39:24 INFO]: [Train_Carts] Enabling Train_Carts v1.20.2-v1
[16:39:24 INFO]: [BlueMap] Loading resources...
[16:39:25 INFO]: [BlueMap] Loading textures...
[16:39:28 INFO]: [Train_Carts] [Resource Pack Models] Loading resource pack item model lists
[16:39:28 INFO]: [Train_Carts] SignLink detected, support for arrival signs added!
[16:39:28 INFO]: [BlueMap] Baking resources...
[16:39:29 INFO]: [BlueMap] Resources loaded.
[16:39:29 INFO]: [BlueMap] Loading world '832ed081-eb04-48a9-b773-3f364ee97064' (D:\MCSManager\daemon\data\InstanceData\19474cdaca8245f4ae1764d280385f04\world)...
[16:39:29 INFO]: [BlueMap] Initializing Storage: 'file' (Type: FILE)
[16:39:29 INFO]: [BlueMap] Loading map 'world'...
[16:39:29 INFO]: [Train_Carts] 11 Trains have been loaded in 1 world. (241 Minecarts)
[16:39:29 INFO]: [Train_Carts] Restoring trains and loading nearby chunks...
[16:39:30 INFO]: [BlueMap] Loading world 'cd544f83-1e1f-444d-84d1-24d47dc3ca5c' (D:\MCSManager\daemon\data\InstanceData\19474cdaca8245f4ae1764d280385f04\world_the_end\DIM1)...
[16:39:30 INFO]: [BlueMap] Loading map 'world_the_end'...
[16:39:32 INFO]: [BlueMap] Loading world '053b4f49-7909-4462-959e-f81d87c42b35' (D:\MCSManager\daemon\data\InstanceData\19474cdaca8245f4ae1764d280385f04\world_nether\DIM-1)...
[16:39:32 INFO]: [BlueMap] Loading map 'world_nether'...
[16:39:33 INFO]: [BlueMap] WebServer bound to all network interfaces on port 8100
[16:39:33 INFO]: [BlueMap] WebServer started.
[16:39:33 INFO]: [BlueMap] Loaded!
[16:39:39 INFO]: [Train_Carts] Train_Carts version 1.20.2-v1 (build: 1464) enabled! (15.132s)
[16:39:39 INFO]: [Train_Carts] SignLink detected, support for arrival signs added!
[16:39:39 INFO]: [TabTPS] Enabling TabTPS v1.3.21
[16:39:39 INFO]: [TabTPS] Successfully registered Mojang Brigadier support for commands.
[16:39:39 INFO]: [TabTPS] Successfully registered asynchronous command completion listener.
[16:39:39 INFO]: [SeeMore] Enabling SeeMore v1.0.2
[16:39:39 INFO]: [Images] Enabling Images v2.3.1
[16:39:39 INFO]: [Images] ProtocolLib detected. Enabling generic packet handling...
[16:39:39 INFO]: [GravityControl] Enabling GravityControl v2.0.0
[16:39:40 INFO]: [CoreProtect] Enabling CoreProtect v22.2
[16:39:40 INFO]: [CoreProtect] CoreProtect 已成功启用！ 
[16:39:40 INFO]: [CoreProtect] 使用 SQLite 用于数据存储。
[16:39:40 INFO]: --------------------
[16:39:40 INFO]: [CoreProtect] 对 CoreProtect 感到满意吗？请加入我们的 Discord 频道！
[16:39:40 INFO]: [CoreProtect] Discord: www.coreprotect.net/discord/
[16:39:40 INFO]: --------------------
[16:39:40 INFO]: [Chunky] Enabling Chunky v1.3.92
[16:39:40 INFO]: [AntiPopup] Enabling AntiPopup v7
[16:39:40 INFO]: [AntiPopup] Config enabled.
[16:39:40 INFO]: [AntiPopup] Initiated PacketEvents.
[16:39:40 INFO]: [AntiPopup] Hooked on 1.20.2
[16:39:40 INFO]: [AntiPopup] Commands registered.
[16:39:40 INFO]: [AntiPopup] Logger filter enabled.
[16:39:40 INFO]: [PlaceholderAPI] Placeholder expansion registration initializing...
[16:39:40 INFO]: JMX monitoring enabled
[16:39:40 INFO]: Running delayed init tasks
[16:39:40 INFO]: [CoreProtect] 与 WorldEdit 的交互已成功初始化。
[16:39:40 INFO]: [ViaVersion] Finished mapping loading, shutting down loader executor!
[16:39:40 INFO]: [Vault] Checking for Updates ... 
[16:39:41 INFO]: [Vault] No new version available
[16:39:41 INFO]: [PlaceholderAPI] Successfully registered external expansion: player [2.0.5]
[16:39:41 INFO]: [PlaceholderAPI] Successfully registered external expansion: servertime [3.2]
[16:39:41 INFO]: 2 placeholder hook(s) registered! 1 placeholder hook(s) have an update available.
[16:39:41 INFO]: Done (40.684s)! For help, type "help"
[16:39:41 INFO]: Timings Reset
[16:39:47 WARN]: Can't keep up! Is the server overloaded? Running 5030ms or 100 ticks behind
[16:39:48 INFO]: [Images] Loaded 18 images...
[16:40:13 INFO]: There are 13 trains on this server (of which 8
[16:40:13 INFO]:  are moving)
[16:40:13 INFO]: There are 333 minecart entities
[16:40:13 INFO]: The following trains exist on this server:
[16:40:13 INFO]: L1-1 / L1-2 / L1-3 / L2-1 / L2-2 / L2-3 / L2-4 / L2-5
[16:40:13 INFO]: L2-6 / L2-7 / L2-7~c / L2-7~d / woolfact

I cannot find anything wrong in there, have you got any idea?

[bergerkiller]

The only thing I find strange is that the bluemap plugin is kicked into action while traincarts is loading trains/chunks. Its a far-off guess, but can you see what happens if you restart without bluemap running? If the same problem still occurs?

If it does its an annoying bug to track down, Ill have to send some custom builds that adds some debugging information

[BiDuang]

The only thing I find strange is that the bluemap plugin is kicked into action while traincarts is loading trains/chunks. Its a far-off guess, but can you see what happens if you restart without bluemap running? If the same problem still occurs?

If it does its an annoying bug to track down, Ill have to send some custom builds that adds some debugging information

Okay, I will try it. Thanks a lot!

[BiDuang]

The only thing I find strange is that the bluemap plugin is kicked into action while traincarts is loading trains/chunks. Its a far-off guess, but can you see what happens if you restart without bluemap running? If the same problem still occurs?

If it does its an annoying bug to track down, Ill have to send some custom builds that adds some debugging information

I disabled the Bluemap, but it didn't work. The train was still torn apart.

[bergerkiller]

Went over the track walking code again, so I need to narrow down what to look for. Do you know precisely where trains disconnect? If not, I can send a test build that logs the coordinates carts have when they disconnect.

If you do, does this happen while the cart is on a curved piece of vanilla track?

[bergerkiller]

Ive added a debug mode to hopefully more easily identify why trains split. Update to this build: https://ci.mg-dev.eu/job/TrainCarts/1481/

Boot server with it once, stop again. Then edit config.yml and set logTrainSplitting: true. It will then log all the splits that occur shortly after the server restart, and at normal runtime. Where, why and what cart(s)

[BiDuang]

Cool, it catched!

[16:49:23 INFO]: 2 placeholder hook(s) registered! 1 placeholder hook(s) have an update available.
[16:49:23 WARN]: [Train_Carts] Train 'L1-1' split apart because: Next cart is derailed
[16:49:23 WARN]: [Train_Carts] Search start: {rail={RailTypePowered{powered=true} -203/53/35}, pos={-202.0/53.0625/35.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:23 WARN]: [Train_Carts] Search end: {rail={NONE -204/53/36}, pos={-203.6567/53.0625/36.1567}, mot={-0.7071/0.0/0.7071}, f=SOUTH}
[16:49:23 WARN]: [Train_Carts] Cart that could not be reached: cart #14 of 24 at x=-203.65665663044663 y=53.0625 z=36.15665663044661
[16:49:23 WARN]: [Train_Carts] Train 'L1-1' split apart because: Next cart is derailed
[16:49:23 WARN]: [Train_Carts] Search start: {rail={RailTypePowered{powered=true} -203/53/35}, pos={-202.0/53.0625/35.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:23 WARN]: [Train_Carts] Search end: {rail={NONE -204/53/36}, pos={-203.6567/53.0625/36.1567}, mot={-0.6991/0.0/-0.715}, f=NORTH}
[16:49:23 WARN]: [Train_Carts] Cart that could not be reached: cart #14 of 24 at x=-203.65665663044663 y=53.0625 z=36.15665663044661
[16:49:23 INFO]: [ViaVersion] Finished mapping loading, shutting down loader executor!
[16:49:23 WARN]: [Train_Carts] Train 'L1-1' split apart because: Next cart is derailed
[16:49:23 WARN]: [Train_Carts] Search start: {rail={RailTypePowered{powered=true} -203/53/35}, pos={-202.0/53.0625/35.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:23 WARN]: [Train_Carts] Search end: {rail={NONE -204/53/36}, pos={-203.9196/53.0622/36.3563}, mot={-0.6991/0.0/-0.715}, f=NORTH}
[16:49:23 WARN]: [Train_Carts] Cart that could not be reached: cart #14 of 24 at x=-203.91958714110055 y=53.06223877590793 z=36.356287503865886
[16:49:23 INFO]: [Vault] Checking for Updates ... 
[16:49:23 WARN]: [Train_Carts] Train 'L1-1' split apart because: Next cart is derailed
[16:49:23 WARN]: [Train_Carts] Search start: {rail={RailTypePowered{powered=true} -203/53/35}, pos={-202.0/53.0625/35.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:23 WARN]: [Train_Carts] Search end: {rail={NONE -204/53/36}, pos={-203.9196/53.0622/36.3563}, mot={-0.668/1.0E-4/-0.7441}, f=NORTH}
[16:49:23 WARN]: [Train_Carts] Cart that could not be reached: cart #14 of 24 at x=-203.91958714110055 y=53.06223877590793 z=36.356287503865886
[16:49:23 WARN]: [Train_Carts] Train 'L1-1' split apart because: Next cart is derailed
[16:49:23 WARN]: [Train_Carts] Search start: {rail={RailTypePowered{powered=true} -203/53/35}, pos={-202.0/53.0625/35.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:23 WARN]: [Train_Carts] Search end: {rail={NONE -204/53/36}, pos={-203.9196/53.0622/36.3563}, mot={-0.668/1.0E-4/-0.7441}, f=NORTH}
[16:49:23 WARN]: [Train_Carts] Cart that could not be reached: cart #14 of 24 at x=-203.91958714110055 y=53.06223877590793 z=36.356287503865886
[16:49:23 WARN]: [Train_Carts] Train 'L1-1' split apart because: Next cart is derailed
[16:49:23 WARN]: [Train_Carts] Search start: {rail={RailTypePowered{powered=true} -204/53/35}, pos={-203.0/53.0625/35.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:23 WARN]: [Train_Carts] Search end: {rail={NONE -205/53/36}, pos={-204.1825/53.0617/36.547}, mot={-0.668/1.0E-4/-0.7441}, f=NORTH}
[16:49:23 WARN]: [Train_Carts] Cart that could not be reached: cart #14 of 24 at x=-204.18251968302818 y=53.06171802088557 z=36.54698984905209
[16:49:23 WARN]: [Train_Carts] Train 'L1-1' split apart because: Next cart is derailed
[16:49:23 WARN]: [Train_Carts] Search start: {rail={RailTypePowered{powered=true} -204/53/35}, pos={-203.0/53.0625/35.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:23 WARN]: [Train_Carts] Search end: {rail={NONE -205/53/36}, pos={-204.1825/53.0617/36.547}, mot={-0.6417/3.0E-4/-0.767}, f=NORTH}
[16:49:23 WARN]: [Train_Carts] Cart that could not be reached: cart #14 of 24 at x=-204.18251968302818 y=53.06171802088557 z=36.54698984905209
[16:49:23 WARN]: [Train_Carts] Train 'L1-1' split apart because: Next cart is derailed
[16:49:23 WARN]: [Train_Carts] Search start: {rail={RailTypePowered{powered=true} -204/53/35}, pos={-203.0/53.0625/35.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:23 WARN]: [Train_Carts] Search end: {rail={NONE -205/53/36}, pos={-204.1825/53.0617/36.547}, mot={-0.6417/3.0E-4/-0.767}, f=NORTH}
[16:49:23 WARN]: [Train_Carts] Cart that could not be reached: cart #14 of 24 at x=-204.18251968302818 y=53.06171802088557 z=36.54698984905209
[16:49:23 WARN]: [Train_Carts] Train 'L1-1' split apart because: Next cart is derailed
[16:49:23 WARN]: [Train_Carts] Search start: {rail={RailTypePowered{powered=true} -204/53/35}, pos={-203.0/53.0625/35.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:23 WARN]: [Train_Carts] Search end: {rail={NONE -205/53/36}, pos={-204.4453/53.0609/36.7268}, mot={-0.6417/3.0E-4/-0.767}, f=NORTH}
[16:49:23 WARN]: [Train_Carts] Cart that could not be reached: cart #14 of 24 at x=-204.44533336233116 y=53.06094427654565 z=36.72678569364815
[16:49:24 INFO]: [Vault] No new version available
[16:49:24 INFO]: Done (39.035s)! For help, type "help"
[16:49:24 INFO]: Timings Reset
[16:49:24 WARN]: [Train_Carts] Train 'L1-1' split apart because: Next cart is derailed
[16:49:24 WARN]: [Train_Carts] Search start: {rail={RailTypePowered{powered=true} -204/53/35}, pos={-203.0/53.0625/35.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:24 WARN]: [Train_Carts] Search end: {rail={NONE -205/53/36}, pos={-204.4453/53.0609/36.7268}, mot={-0.6197/5.0E-4/-0.7848}, f=NORTH}
[16:49:24 WARN]: [Train_Carts] Cart that could not be reached: cart #14 of 24 at x=-204.44533336233116 y=53.06094427654565 z=36.72678569364815
[16:49:24 WARN]: [Train_Carts] Train 'L1-1' split apart because: Next cart is derailed
[16:49:24 WARN]: [Train_Carts] Search start: {rail={RailTypePowered{powered=true} -204/53/35}, pos={-203.0/53.0625/35.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:24 WARN]: [Train_Carts] Search end: {rail={NONE -205/53/36}, pos={-204.4453/53.0609/36.7268}, mot={-0.6197/5.0E-4/-0.7848}, f=NORTH}
[16:49:24 WARN]: [Train_Carts] Cart that could not be reached: cart #14 of 24 at x=-204.44533336233116 y=53.06094427654565 z=36.72678569364815
[16:49:24 WARN]: [Train_Carts] Train 'L1-1' split apart because: Next cart is derailed
[16:49:24 WARN]: [Train_Carts] Search start: {rail={RailTypePowered{powered=true} -204/53/35}, pos={-203.0/53.0625/35.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:24 WARN]: [Train_Carts] Search end: {rail={NONE -205/53/36}, pos={-204.7084/53.0599/36.8945}, mot={-0.6197/5.0E-4/-0.7848}, f=NORTH}
[16:49:24 WARN]: [Train_Carts] Cart that could not be reached: cart #14 of 24 at x=-204.70838465243475 y=53.05992799653855 z=36.89453332264862
[16:49:24 WARN]: [Train_Carts] Train 'L1-1' split apart because: Next cart is derailed
[16:49:24 WARN]: [Train_Carts] Search start: {rail={RailTypePowered{powered=true} -204/53/35}, pos={-203.0/53.0625/35.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:24 WARN]: [Train_Carts] Search end: {rail={NONE -205/53/36}, pos={-204.7084/53.0599/36.8945}, mot={-0.6015/9.0E-4/-0.7988}, f=NORTH}
[16:49:24 WARN]: [Train_Carts] Cart that could not be reached: cart #14 of 24 at x=-204.70838465243475 y=53.05992799653855 z=36.89453332264862
[16:49:24 WARN]: [Train_Carts] Train 'L1-1' split apart because: Next cart is derailed
[16:49:24 WARN]: [Train_Carts] Search start: {rail={RailTypePowered{powered=true} -204/53/35}, pos={-203.0/53.0625/35.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:24 WARN]: [Train_Carts] Search end: {rail={NONE -205/53/36}, pos={-204.7084/53.0599/36.8945}, mot={-0.6015/9.0E-4/-0.7988}, f=NORTH}
[16:49:24 WARN]: [Train_Carts] Cart that could not be reached: cart #14 of 24 at x=-204.70838465243475 y=53.05992799653855 z=36.89453332264862
[16:49:24 WARN]: [Train_Carts] Train 'L1-1' split apart because: Next cart is derailed
[16:49:24 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -205/53/35}, pos={-204.0/53.0625/35.5}, mot={-0.7071/0.0/-0.7071}, f=NORTH}
[16:49:24 WARN]: [Train_Carts] Search end: {rail={NONE -205/53/37}, pos={-204.9722/53.0587/37.0498}, mot={-0.6015/9.0E-4/-0.7988}, f=NORTH}
[16:49:24 WARN]: [Train_Carts] Cart that could not be reached: cart #14 of 24 at x=-204.9721673871252 y=53.058681956363635 z=37.04980968820402
[16:49:24 WARN]: [Train_Carts] Train 'L1-1' split apart because: Next cart is derailed
[16:49:24 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -205/53/35}, pos={-204.0/53.0625/35.5}, mot={-0.7071/0.0/-0.7071}, f=NORTH}
[16:49:24 WARN]: [Train_Carts] Search end: {rail={NONE -205/53/37}, pos={-204.9722/53.0587/37.0498}, mot={-0.5866/0.0012/-0.8098}, f=NORTH}
[16:49:24 WARN]: [Train_Carts] Cart that could not be reached: cart #14 of 24 at x=-204.9721673871252 y=53.058681956363635 z=37.04980968820402
[16:49:24 WARN]: [Train_Carts] Train 'L1-1' split apart because: Next cart is derailed
[16:49:24 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -205/53/35}, pos={-204.0/53.0625/35.5}, mot={-0.7071/0.0/-0.7071}, f=NORTH}
[16:49:24 WARN]: [Train_Carts] Search end: {rail={NONE -205/53/37}, pos={-204.9722/53.0587/37.0498}, mot={-0.5866/0.0012/-0.8098}, f=NORTH}
[16:49:24 WARN]: [Train_Carts] Cart that could not be reached: cart #14 of 24 at x=-204.9721673871252 y=53.058681956363635 z=37.04980968820402
[16:49:24 WARN]: [Train_Carts] Train 'L1-1' split apart because: Next cart is derailed
[16:49:24 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -205/53/35}, pos={-204.0/53.0625/35.5}, mot={-0.7071/0.0/-0.7071}, f=NORTH}
[16:49:24 WARN]: [Train_Carts] Search end: {rail={NONE -206/53/37}, pos={-205.2333/53.0572/37.1842}, mot={-0.5866/0.0012/-0.8098}, f=NORTH}
[16:49:24 WARN]: [Train_Carts] Cart that could not be reached: cart #14 of 24 at x=-205.23325795523226 y=53.05723617547564 z=37.18421121634505
[16:49:24 WARN]: [Train_Carts] Train 'L1-1' split apart because: Next cart is derailed
[16:49:24 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -205/53/35}, pos={-204.0/53.0625/35.5}, mot={-0.7071/0.0/-0.7071}, f=NORTH}
[16:49:24 WARN]: [Train_Carts] Search end: {rail={NONE -206/53/37}, pos={-205.2333/53.0572/37.1842}, mot={-0.5562/0.0016/-0.8311}, f=NORTH}
[16:49:24 WARN]: [Train_Carts] Cart that could not be reached: cart #14 of 24 at x=-205.23325795523226 y=53.05723617547564 z=37.18421121634505
[16:49:24 WARN]: [Train_Carts] Train 'L1-1' split apart because: Next cart is derailed
[16:49:24 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -205/53/35}, pos={-204.0/53.0625/35.5}, mot={-0.7071/0.0/-0.7071}, f=NORTH}
[16:49:24 WARN]: [Train_Carts] Search end: {rail={NONE -206/53/37}, pos={-205.2333/53.0572/37.1842}, mot={-0.5562/0.0016/-0.8311}, f=NORTH}
[16:49:24 WARN]: [Train_Carts] Cart that could not be reached: cart #14 of 24 at x=-205.23325795523226 y=53.05723617547564 z=37.18421121634505
[16:49:24 WARN]: [Train_Carts] Train 'L1-1' split apart because: Next cart is derailed
[16:49:24 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -205/53/34}, pos={-204.5/53.0625/35.0}, mot={-0.7071/0.0/-0.7071}, f=NORTH}
[16:49:24 WARN]: [Train_Carts] Search end: {rail={NONE -206/53/37}, pos={-205.4916/53.0556/37.2927}, mot={-0.5562/0.0016/-0.8311}, f=NORTH}
[16:49:24 WARN]: [Train_Carts] Cart that could not be reached: cart #14 of 24 at x=-205.49163055110333 y=53.05561270693594 z=37.292706976306725
[16:49:24 WARN]: [Train_Carts] Train 'L1-1~a' split apart because: Next cart is derailed
[16:49:24 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -205/53/34}, pos={-204.5/53.0625/35.0}, mot={-0.7071/0.0/-0.7071}, f=NORTH}
[16:49:24 WARN]: [Train_Carts] Search end: {rail={NONE -206/53/37}, pos={-205.4916/53.0556/37.2927}, mot={-0.3748/-0.0023/0.9271}, f=SOUTH}
[16:49:24 WARN]: [Train_Carts] Cart that could not be reached: cart #1 of 11 at x=-205.49163055110333 y=53.05561270693594 z=37.292706976306725
[16:49:25 WARN]: [Train_Carts] Train 'L1-1~a' split apart because: Next cart is derailed
[16:49:25 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -205/53/34}, pos={-204.5/53.0625/35.0}, mot={-0.7071/0.0/-0.7071}, f=NORTH}
[16:49:25 WARN]: [Train_Carts] Search end: {rail={NONE -206/53/37}, pos={-205.4916/53.0556/37.2927}, mot={-0.3428/-0.0027/0.9394}, f=SOUTH}
[16:49:25 WARN]: [Train_Carts] Cart that could not be reached: cart #1 of 11 at x=-205.49163055110333 y=53.05561270693594 z=37.292706976306725
[16:49:25 WARN]: [Train_Carts] Train 'L1-1~a' split apart because: Next cart is derailed
[16:49:25 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -205/53/34}, pos={-204.5/53.0625/35.0}, mot={-0.7071/0.0/-0.7071}, f=NORTH}
[16:49:25 WARN]: [Train_Carts] Search end: {rail={NONE -206/53/37}, pos={-205.4916/53.0556/37.2927}, mot={-0.3428/-0.0027/0.9394}, f=SOUTH}
[16:49:25 WARN]: [Train_Carts] Cart that could not be reached: cart #1 of 11 at x=-205.49163055110333 y=53.05561270693594 z=37.292706976306725
[16:49:25 WARN]: [Train_Carts] Train 'L1-1~a' split apart because: Next cart is derailed
[16:49:25 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -205/53/34}, pos={-204.5/53.0625/35.0}, mot={-0.7071/0.0/-0.7071}, f=NORTH}
[16:49:25 WARN]: [Train_Carts] Search end: {rail={NONE -206/53/37}, pos={-205.6755/53.0527/37.4121}, mot={-0.3428/-0.0027/0.9394}, f=SOUTH}
[16:49:25 WARN]: [Train_Carts] Cart that could not be reached: cart #1 of 11 at x=-205.67551907028096 y=53.05266560209267 z=37.41207232763191
[16:49:25 WARN]: [Train_Carts] Train 'L1-1~a' split apart because: Next cart is derailed
[16:49:25 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -205/53/34}, pos={-204.5/53.0625/35.0}, mot={-0.7071/0.0/-0.7071}, f=NORTH}
[16:49:25 WARN]: [Train_Carts] Search end: {rail={NONE -206/53/37}, pos={-205.6755/53.0527/37.4121}, mot={-0.2933/-0.0034/0.956}, f=SOUTH}
[16:49:25 WARN]: [Train_Carts] Cart that could not be reached: cart #1 of 11 at x=-205.67551907028096 y=53.05266560209267 z=37.41207232763191
[16:49:25 WARN]: [Train_Carts] Train 'L1-1~a' split apart because: Next cart is derailed
[16:49:25 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -205/53/34}, pos={-204.5/53.0625/35.0}, mot={-0.7071/0.0/-0.7071}, f=NORTH}
[16:49:25 WARN]: [Train_Carts] Search end: {rail={NONE -206/53/37}, pos={-205.6755/53.0527/37.4121}, mot={-0.2933/-0.0034/0.956}, f=SOUTH}
[16:49:25 WARN]: [Train_Carts] Cart that could not be reached: cart #1 of 11 at x=-205.67551907028096 y=53.05266560209267 z=37.41207232763191
[16:49:25 WARN]: [Train_Carts] Train 'L1-1~a' split apart because: Next cart is derailed
[16:49:25 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -206/53/34}, pos={-205.0/53.0625/34.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:25 WARN]: [Train_Carts] Search end: {rail={NONE -206/53/37}, pos={-205.8557/53.0487/37.5}, mot={-0.2933/-0.0034/0.956}, f=SOUTH}
[16:49:25 WARN]: [Train_Carts] Cart that could not be reached: cart #1 of 11 at x=-205.85565600263556 y=53.04869715777535 z=37.49997985067477
[16:49:25 WARN]: [Train_Carts] Train 'L1-1~a' split apart because: Next cart is derailed
[16:49:25 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -206/53/34}, pos={-205.0/53.0625/34.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:25 WARN]: [Train_Carts] Search end: {rail={NONE -206/53/37}, pos={-205.8557/53.0487/37.5}, mot={-0.2522/-0.0045/0.9677}, f=SOUTH}
[16:49:25 WARN]: [Train_Carts] Cart that could not be reached: cart #1 of 11 at x=-205.85565600263556 y=53.04869715777535 z=37.49997985067477
[16:49:25 WARN]: [Train_Carts] Train 'L1-1~a' split apart because: Next cart is derailed
[16:49:25 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -206/53/34}, pos={-205.0/53.0625/34.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:25 WARN]: [Train_Carts] Search end: {rail={NONE -206/53/37}, pos={-205.8557/53.0487/37.5}, mot={-0.2522/-0.0045/0.9677}, f=SOUTH}
[16:49:25 WARN]: [Train_Carts] Cart that could not be reached: cart #1 of 11 at x=-205.85565600263556 y=53.04869715777535 z=37.49997985067477
[16:49:25 WARN]: [Train_Carts] Train 'L1-1~a' split apart because: Next cart is derailed
[16:49:25 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -206/53/34}, pos={-205.0/53.0625/34.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:25 WARN]: [Train_Carts] Search end: {rail={NONE -207/53/37}, pos={-206.0357/53.0438/37.5641}, mot={-0.2522/-0.0045/0.9677}, f=SOUTH}
[16:49:25 WARN]: [Train_Carts] Cart that could not be reached: cart #1 of 11 at x=-206.0357413788915 y=53.04376507727941 z=37.5641404873241
[16:49:25 WARN]: [Train_Carts] Train 'L1-1~a' split apart because: Next cart is derailed
[16:49:25 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -206/53/34}, pos={-205.0/53.0625/34.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:25 WARN]: [Train_Carts] Search end: {rail={NONE -207/53/37}, pos={-206.0357/53.0438/37.5641}, mot={-0.2067/-0.006/0.9784}, f=SOUTH}
[16:49:25 WARN]: [Train_Carts] Cart that could not be reached: cart #1 of 11 at x=-206.0357413788915 y=53.04376507727941 z=37.5641404873241
[16:49:25 WARN]: [Train_Carts] Train 'L1-1~a' split apart because: Next cart is derailed
[16:49:25 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -206/53/34}, pos={-205.0/53.0625/34.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:25 WARN]: [Train_Carts] Search end: {rail={NONE -207/53/37}, pos={-206.2225/53.0379/37.6235}, mot={-0.2067/-0.006/0.9784}, f=SOUTH}
[16:49:25 WARN]: [Train_Carts] Cart that could not be reached: cart #1 of 11 at x=-206.22253023917267 y=53.03791993801431 z=37.623459793667756
[16:49:25 WARN]: [Train_Carts] Train 'L1-1~a' split apart because: Next cart is derailed
[16:49:25 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -206/53/34}, pos={-205.0/53.0625/34.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:25 WARN]: [Train_Carts] Search end: {rail={NONE -207/53/37}, pos={-206.2225/53.0379/37.6235}, mot={-0.1641/-0.0078/0.9864}, f=SOUTH}
[16:49:25 WARN]: [Train_Carts] Cart that could not be reached: cart #1 of 11 at x=-206.22253023917267 y=53.03791993801431 z=37.623459793667756
[16:49:25 WARN]: [Train_Carts] Train 'L1-1~a' split apart because: Next cart is derailed
[16:49:25 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -206/53/34}, pos={-205.0/53.0625/34.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:25 WARN]: [Train_Carts] Search end: {rail={NONE -207/53/37}, pos={-206.2225/53.0379/37.6235}, mot={-0.1641/-0.0078/0.9864}, f=SOUTH}
[16:49:25 WARN]: [Train_Carts] Cart that could not be reached: cart #1 of 11 at x=-206.22253023917267 y=53.03791993801431 z=37.623459793667756
[16:49:25 WARN]: [Train_Carts] Train 'L1-1~a' split apart because: Next cart is derailed
[16:49:25 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -207/53/34}, pos={-206.0/53.0625/34.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:25 WARN]: [Train_Carts] Search end: {rail={NONE -207/53/37}, pos={-206.4158/53.0312/37.678}, mot={-0.1641/-0.0078/0.9864}, f=SOUTH}
[16:49:25 WARN]: [Train_Carts] Cart that could not be reached: cart #1 of 11 at x=-206.415772454419 y=53.031201196083316 z=37.67802242265507
[16:49:25 WARN]: [Train_Carts] Train 'L1-1~a' split apart because: Next cart is derailed
[16:49:25 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -207/53/34}, pos={-206.0/53.0625/34.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:25 WARN]: [Train_Carts] Search end: {rail={NONE -207/53/37}, pos={-206.4158/53.0312/37.678}, mot={-0.1244/-0.0098/0.9922}, f=SOUTH}
[16:49:25 WARN]: [Train_Carts] Cart that could not be reached: cart #1 of 11 at x=-206.415772454419 y=53.031201196083316 z=37.67802242265507
[16:49:25 WARN]: [Train_Carts] Train 'L1-1~a' split apart because: Next cart is derailed
[16:49:25 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -207/53/34}, pos={-206.0/53.0625/34.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:25 WARN]: [Train_Carts] Search end: {rail={NONE -207/53/37}, pos={-206.4158/53.0312/37.678}, mot={-0.1244/-0.0098/0.9922}, f=SOUTH}
[16:49:25 WARN]: [Train_Carts] Cart that could not be reached: cart #1 of 11 at x=-206.415772454419 y=53.031201196083316 z=37.67802242265507
[16:49:25 WARN]: [Train_Carts] Train 'L1-1~a' split apart because: Next cart is derailed
[16:49:25 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -207/53/34}, pos={-206.0/53.0625/34.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:25 WARN]: [Train_Carts] Search end: {rail={NONE -207/53/37}, pos={-206.6152/53.0236/37.728}, mot={-0.1244/-0.0098/0.9922}, f=SOUTH}
[16:49:25 WARN]: [Train_Carts] Cart that could not be reached: cart #1 of 11 at x=-206.61523586055242 y=53.02364436274294 z=37.72796883281758
[16:49:25 WARN]: [Train_Carts] Train 'L1-1~a' split apart because: Next cart is derailed
[16:49:25 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -207/53/34}, pos={-206.0/53.0625/34.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:25 WARN]: [Train_Carts] Search end: {rail={NONE -207/53/37}, pos={-206.6152/53.0236/37.728}, mot={-0.0877/-0.012/0.9961}, f=SOUTH}
[16:49:25 WARN]: [Train_Carts] Cart that could not be reached: cart #1 of 11 at x=-206.61523586055242 y=53.02364436274294 z=37.72796883281758
[16:49:25 WARN]: [Train_Carts] Train 'L1-1~a' split apart because: Next cart is derailed
[16:49:25 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -207/53/34}, pos={-206.0/53.0625/34.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:25 WARN]: [Train_Carts] Search end: {rail={NONE -207/53/37}, pos={-206.6152/53.0236/37.728}, mot={-0.0877/-0.012/0.9961}, f=SOUTH}
[16:49:25 WARN]: [Train_Carts] Cart that could not be reached: cart #1 of 11 at x=-206.61523586055242 y=53.02364436274294 z=37.72796883281758
[16:49:25 WARN]: [Train_Carts] Train 'L1-1~a' split apart because: Next cart is derailed
[16:49:25 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -207/53/34}, pos={-206.0/53.0625/34.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:25 WARN]: [Train_Carts] Search end: {rail={NONE -207/53/37}, pos={-206.8207/53.0153/37.7735}, mot={-0.0877/-0.012/0.9961}, f=SOUTH}
[16:49:25 WARN]: [Train_Carts] Cart that could not be reached: cart #1 of 11 at x=-206.82069075084243 y=53.015281562259474 z=37.77348306988827
[16:49:25 WARN]: [Train_Carts] Train 'L1-1~a' split apart because: Next cart is derailed
[16:49:25 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -207/53/34}, pos={-206.0/53.0625/34.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:25 WARN]: [Train_Carts] Search end: {rail={NONE -207/53/37}, pos={-206.8207/53.0153/37.7735}, mot={-0.0537/-0.0144/0.9985}, f=SOUTH}
[16:49:25 WARN]: [Train_Carts] Cart that could not be reached: cart #1 of 11 at x=-206.82069075084243 y=53.015281562259474 z=37.77348306988827
[16:49:25 WARN]: [Train_Carts] Train 'L1-1~a' split apart because: Next cart is derailed
[16:49:25 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -207/53/34}, pos={-206.0/53.0625/34.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:25 WARN]: [Train_Carts] Search end: {rail={NONE -207/53/37}, pos={-206.8207/53.0153/37.7735}, mot={-0.0537/-0.0144/0.9985}, f=SOUTH}
[16:49:25 WARN]: [Train_Carts] Cart that could not be reached: cart #1 of 11 at x=-206.82069075084243 y=53.015281562259474 z=37.77348306988827
[16:49:25 WARN]: [Train_Carts] Train 'L1-1~a' split apart because: Next cart is derailed
[16:49:25 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -207/53/34}, pos={-206.0/53.0625/34.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:25 WARN]: [Train_Carts] Search end: {rail={NONE -208/53/37}, pos={-207.0319/53.0061/37.8148}, mot={-0.0537/-0.0144/0.9985}, f=SOUTH}
[16:49:25 WARN]: [Train_Carts] Cart that could not be reached: cart #1 of 11 at x=-207.0319013054925 y=53.006141989328256 z=37.81478185623314
[16:49:26 WARN]: [Train_Carts] Train 'L1-1~a' split apart because: Next cart is derailed
[16:49:26 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -207/53/34}, pos={-206.0/53.0625/34.5}, mot={-1.0/0.0/0.0}, f=WEST}
[16:49:26 WARN]: [Train_Carts] Search end: {rail={NONE -208/53/37}, pos={-207.0319/53.0061/37.8148}, mot={-0.0225/-0.017/0.9996}, f=SOUTH}
[16:49:26 WARN]: [Train_Carts] Cart that could not be reached: cart #1 of 11 at x=-207.0319013054925 y=53.006141989328256 z=37.81478185623314
[16:49:26 WARN]: [Train_Carts] Train 'L1-1~a' split apart because: Next cart is derailed
[16:49:26 WARN]: [Train_Carts] Search start: {rail={RailTypeRegular -208/53/34}, pos={-207.0/53.0625/34.5}, mot={-0.7071/0.0/-0.7071}, f=NORTH}
[16:49:26 WARN]: [Train_Carts] Search end: {rail={NONE -208/52/37}, pos={-207.2486/52.9962/37.8521}, mot={-0.0225/-0.017/0.9996}, f=SOUTH}
[16:49:26 WARN]: [Train_Carts] Cart that could not be reached: cart #1 of 11 at x=-207.24863542394922 y=52.99624838562205 z=37.85210501815752
[16:49:29 WARN]: Can't keep up! Is the server overloaded? Running 5353ms or 107 ticks behind
[16:49:34 INFO]: [Images] Loaded 18 images...
[16:49:46 INFO]: There are 12 trains on this server (of which 8
[16:49:46 INFO]:  are moving)
[16:49:46 INFO]: There are 334 minecart entities
[16:49:46 INFO]: The following trains exist on this server:
[16:49:46 INFO]: L1-1 / L1-1~b / L1-2 / L1-3 / L2-1 / L2-2 / L2-3
[16:49:46 INFO]: L2-4 / L2-5 / L2-6 / L2-7 / woolfact

[bergerkiller]

Interesting, its derailed. Means for some reason it cannot detect any rails at the position of the cart. Can you check for some of the positions listed, whether its above or inside a rails block?

For example: x=-205.67551907028096 y=53.05266560209267 z=37.41207232763191

If thats above rails then theres a bug at startup reading block data for some reason

[BiDuang]

The block at -205, 53, 37 is a stone, it doesn't make sense.🤔

[bergerkiller]

Hmmm....its possible that the cart continues moving a short time at startup until all chunks have loaded that the train needs. Is there a linear path from that exact position at a 45 or 90 degree angle to another rail block? Trains move at a 45 degree angle in curves

For example:

[bergerkiller]

Ill probably send a test build later today (in 5 hours or so) that logs all the positions of minecarts when they are first loaded in, and their position every tick until the train loads in, to see if such a drift is occurring.

[BiDuang]

Okay, thanks for your work!

[bergerkiller]

This build logs the position of all minecarts that are unloaded (pending loading) and when the minecart loads in and is converted to a traincarts minecart. plugin.zip

You can send the startup log up to and including all split logs, might be pretty spammy

[BiDuang]

I think upload a file can make you read easier?

debug.log

[bergerkiller]

As I cant see the blocks involved, is there a rails at?: x=-217.5 y=60.0625 z=-160.92279605257855 For some reason the coordinates have changed, and later on the position is at: x=-216.81599095859067 y=60.0625 z=-160.68400904140933

[BiDuang]

As I cant see the blocks involved, is there a rails at?: x=-217.5 y=60.0625 z=-160.92279605257855 For some reason the coordinates have changed, and later on the position is at: x=-216.81599095859067 y=60.0625 z=-160.68400904140933

Oh, that's a rail:

[bergerkiller]

Its kinda difficult to calculate all of this, so its easier if you check. Can you /tp to exactly x=-216.8159 z=-160.684 and look all the way down? Where is this at? I think the initial spawn coordinate is indeed on the rails still, im uncertain about the second after it split off

[BiDuang]

Here it is:

[bergerkiller]

That does not seem like youre looking all the way down. Pitch angle is only 68 / 90. I need to know exactly where it is at so pixels line up with the coordinates.

[BiDuang]

Okay :

[bergerkiller]

Not the right coordinates exactly. Use /tp @p -216.8159 ~ -160.684

[BiDuang]

[bergerkiller]

It seems some miscalculation happened somewhere in the physics to cause it to move there, because that movement change makes no sense. It was on that straight piece of track, and not much later its off the rails. I'll need to add some more logging to debug this

[BiDuang]

Sure, happy to help.

[bergerkiller]

plugin.zip Lot more spammy this time, hopefully it identifies where the position of carts suddenly changes

[BiDuang]

debug.log

[bergerkiller]

So its part of the physics routine unfortunately, which is a whole lot of code to cover. Ill take out a few likely places and add some logging for it, will be tricky

[bergerkiller]

plugin.zip

After you send the logging, Ill pick out a single train that had issues, and list a series of coordinates. Youll have to see like previously if they are still above rails or not. So /tp @p x y z to those coordinates, and look all the way down, and verify whether or not its still above the rails or not.

[bergerkiller]

Ive managed to reproduce the problem by creating a jagged track far away from spawn and having a train go around in circles on it.

[bergerkiller]

I think I may have found the problem. https://ci.mg-dev.eu/job/TrainCarts/1484/

[BiDuang]

I think I may have found the problem. https://ci.mg-dev.eu/job/TrainCarts/1484/

I've tested it several times and it seems pretty good so far.

[BiDuang]

Well, looks like it shows again...

[bergerkiller]

You're running with latest dev snapshot from jenkins of traincarts? There have been a lot of changes

[BiDuang]

No, I'm running with the latest Release version

[bergerkiller]

Then id start with testing out https://ci.mg-dev.eu/view/all/job/TrainCarts/1542/

It has important changes when it comes to persistence, such as saving and restoring launch actions, active signs and more. Too many changes to really compare it with last release as all of that is basically a rewrite.

Let me know if it still happens, then I can look more deeply into it with the current codebase

[BiDuang]

Okay, thank you. I'll try this new build.