Confirmed by Firedale and Nathan Wostrel on the weekly TFC Tuesday server. ( pakratt0013/honneyplay/nihontiger/firedale2002/bananapopsikul/nathanwostrel/seriouscreeper/lyeoj/xekedeath )

Steps to reproduce:

• Setup a multi-player TFC server.
• Create a forge
• Heat Ingots (easiest to reproduce with wrought iron ingots)
• Attempt to weld on a correct tier anvil (E.G. any Bronze / Wrought Iron); Both ingots in the anvil, Can Weld, With Flux, Hammer in hand, shift + right click.

A desync may result in a fake double-ingot in the offhand, or visually inside the anvil's exterior view. However this does not sync to other players, nor is it the true state when the anvil UI is opened.

We confirmed that at least Wrought Iron Ingots and Bronze Ingots are currently affected by this issue.

Prior to us updating TFC on December 6th, on November 29th, welding worked fine for the Bronze ingots.

The only changes made to the server between November 29th and December 6th was to update TFC from 2.2.1 to 2.2.2 .

Cannot reproduce. Welding is working fine for me with the provided setup. Would need more circumstantial information because "It stopped working randomly" doesn't really indicate anything. The update of 2.2.1 -> 2.2.2 in question does not have any changes that would affect Anvil behavior.

A reboot on the TFC Tuesday server also appears to have worked around the issue.

It's inconsistent, but has been observed two times in the wild. Since rebooting makes the issue go away it would be helpful if welding attempts printed a debug message to the server / client consoles.

This afternoon I've yet to reproduce it with 8x server reloads. Just MC, Forge, TFC 2.2.2, Patchouli (71.1) and Chisels and Bits 1.2.116.

This weekend I also saw this issue ONCE on a multiplayer server. It was intermittently reproducible while I was shuffling mods around on a local test server and client. Due to it not consistently reproducing I gave up after falsely thinking it was one mod or another only to find that it wasn't that mod when I tried to double-check the results. I had assumed it was some oddity in the TFC modpack I was using (with an updated TFC 2.2.2) that I'd look into later this week after that updated again.

Need a good way to collect data the next time it happens to happen, without reloading the server.

https://clips.twitch.tv/AbstemiousJazzySowPastaThat-S8LvZpFV46Sg0eDS

We still need a command or method to collect some sort of useful data, live, on a server which is exhibiting the issue.

If you can reproduce it, upload the server and client logs. As I was not able to. "some sort of useful data" -> yes, log files.

Unfortunately, the issue does not show up in the server logs, which is probably why mjevans is asking for more debugging options for it.
It would be sometime after the final horse moving wrongly issue ([10Jan2023 19:37:28.622]) and before Pakratt left the game ([10Jan2023 20:01:04.850]), as it occurred after we were back in town and no longer using the horses. In the log, there's nothing mentioned whatsoever outside of the regular backup.

Client: Client - latest.log
Server: latest.log

The Client log is from myself, and I experienced the issue during that time, in addition to another player on the server.

I'm not looking for the error to manifest itself in the log - I'm looking to see if you have any recipe loading errors (which you do), and verifying our server/client recipe manager sync is correct hasn't been invalidated.

Firedale is exactly correct. There was no useful data the time I looked (haven't bothered looking the times since, just rebooted my own server, like 3 times before one finally let me weld). In the TFC Tuesday case Firedale's replying about and that the clip is from they didn't even bother restarting since it was nearly the end of their session.

Some command (or just additional checks that print data to the logs) that forces the production of additional data that you would find useful, ideally including a check over any assumptions that might exist is required for end users to provide any further useful data.

What I would find useful, is a reproduction case I can actually use. If you think you know better, then fix it yourself.

It's like it's some sort of weird race condition, but there's no place to start. As proven by just rebooting the server until it works it's like rolling the dice. Sometimes it works, sometimes it doesn't. If there were a 100% reproducible situation we'd have already reported that.

Upon starting the server today, the issue reappeared.
Restarting the server twice fixed the issue. Here is the beginning of the server log of the server when things ARE working.

latest.log

Perhaps having it available to see if there's anything that might be different between this one and the previous one supplied might be helpful.

@alcatrazEscapee
tfc.20230128-063342.redacted.debug.txt.gz

I've tried to redact all of the IP addresses (some version numbers seem to have matched the regexp), usernames, user-uuids, machine identifying information, and various tokens that stood out in the log file. I really don't think there's anything useful in it, but mostly that's because of the noise floor being around 75% of a megabyte, with nothing at all near the context of the event.

Upload the full server log, please, not just the snippet that you think is useful or not.

That's a lot of areas to review for a lot of different possible PII to redact. What are you looking for or what areas of context?

Tried again with 2.2.6

This server has some mods loaded, but the streamer clips are from a server with, as far as I know, only TFC.

debug.log end

[28Jan2023 06:35:44.934] [Server thread/DEBUG] [io.netty.util.internal.ThreadLocalRandom/]: -Dio.netty.initialSeedUniquifier: REDACTED
[28Jan2023 06:37:50.079] [Server thread/INFO] [net.minecraft.server.dedicated.DedicatedServer/]: PLAYERNAME has made the advancement [A Better Fuel]
[28Jan2023 06:38:34.055] [Server thread/INFO] [net.minecraft.server.dedicated.DedicatedServer/]: [PLAYERNAME: Gave 1 [Wrought Iron Anvil] to PLAYERNAME]
[28Jan2023 06:39:06.491] [Server thread/INFO] [net.minecraft.server.dedicated.DedicatedServer/]: [PLAYERNAME: Gave 1 [Flux] to PLAYERNAME]
[28Jan2023 06:39:07.530] [Server thread/INFO] [net.minecraft.server.dedicated.DedicatedServer/]: [PLAYERNAME: Gave 1 [Flux] to PLAYERNAME]
[28Jan2023 06:39:07.967] [Server thread/DEBUG] [mezz.jei.common.platform.Services/]: Loaded mezz.jei.forge.platform.ForgePlatformHelper@6a71dd23 for service interface mezz.jei.common.platform.IPlatformHelper
[28Jan2023 06:39:08.738] [Server thread/INFO] [net.minecraft.server.dedicated.DedicatedServer/]: [PLAYERNAME: Gave 64 [Flux] to PLAYERNAME]
[28Jan2023 06:39:45.291] [Server thread/DEBUG] [net.minecraftforge.common.ForgeHooks/WP]: Gathering id map for writing to world save world-test
[28Jan2023 06:39:45.309] [Server thread/DEBUG] [net.minecraftforge.common.ForgeHooks/WP]: ID Map collection complete world-test
[28Jan2023 06:40:32.470] [Server thread/INFO] [net.minecraft.server.network.ServerGamePacketListenerImpl/]: PLAYERNAME lost connection: Disconnected
[28Jan2023 06:40:32.470] [Server thread/INFO] [net.minecraft.server.dedicated.DedicatedServer/]: PLAYERNAME left the game

I don't know if it's not seeing the right click, or if something is wrong, but the ingots were Can Weld, there was flux, and in this test case I was trying to weld the ingots in a same tier anvil with a same tier hammer in my hand and the anvil.

An event on any weld fail during an attempted weld should print something to the logs so that I and other users can collect data to help debug what's going wrong.

heres a log of what happened, just thought you guys could disect it, good lick
2023-01-25-4.log.gz

Just had issue again with 2.2.6 update.
latest.log
debug.log

After about 6 restarts (not exaggerating), it finally worked, here's are the logs of a working session.
latest.log
debug.log

During the restarts, I even removed the data pack we put in to make TFC recipes for C&B stuff and it still didn't work after that.

And, after shutting down the server to get those last logs... the next start of the server is back to broken:
latest.log
debug.log

Every reproduction case so far has had at least chisel + bits. A user in our discord reported that removing it fixed it for them (in a situation where it was consistently broken). No idea if it's specific to the mod or just having other mods installed but the lack of reproducibility does beg the question.

It's very difficult to tell, because it doesn't break on every startup, and there can be runs of continuous breaks that look like it's reproducible, and then it suddenly works. I imagine the inverse is also readily possible, many startups where it works and then suddenly it doesn't. I don't even happen to try to weld every time I have a TFC session, so there are gaps in observation in at least my case. This is also extremely possible for others as well.

Hopefully it's understandable that many of us who add C&B do so for the same reasons TFC 1.7.x had a microblock mode. Which is now covered by C&B as not-duplicated effort. I also can't readily imagine where an obvious conflict between the two mods exists. I'd more strongly suspect CarryOn in my case (which was initially an issue for my game friends and self; we rebound it's sneak shared keybind to other keys; I chose Tab).

Even if there is a conflict, the solution isn't to say 'doesn't work with C&B' the solution is to narrow down where the conflict is happening, and which mods have an issue that's exposed by their co-existence in a pack / an instance.

Every weld attempt should print something to the debug log. Success or reason for rejection / failure. This would help cover if the event fires at all (if it doesn't the sneek hammer handler or whatever is where to start looking) or if it does might give a hint about what else is going wrong. The other failure cases could also print as chat events... E.G. "Weld: Missing Flux" "Weld: Item(s) Not Hot Enough (not Can Weld)" "Weld: Unknown recipe"

(Weld: Insufficient Anvil Tier".) I also agree with the streamer(s) I watch. Welding is just smashing two chunks of metal together in a flattening way. We're allowed to use any tier of hammer, so any tier of anvil should also work, since it's just two flat surfaces pounding two sides of the items being joined.

ALRIGHT buckle up kids. I was finally able to reproduce this, in a situation where I could attach a remote debugger. So, where to start:

First off, this is not exclusive to welding. Nor is it an issue with welding recipes. Based on the observed behavior it was clearly a server-client disagreement - the server thought the weld was not performed, the client did. What is more interesting, is the server didn't think the client performed anything, as long as the player was holding shift. So for example, we have this behavior which happens completely unrelated to welding itself:

So, actually being able to debug this, I was able to peruse through the stack traces and various event handlers, and discover that in these situations, on the server, Block#use is not called... at all. Introduce this bit of TFC code:

Minecraft does not call Block#use when shift is held, unless we explicitly allow it - either through an item (which we can't in this case), or through this event. And this works - it works perfectly well in TFC. So why did this break?

Introduce the culprit: Chisels and Bits

    event.setUseBlock(mapResult(result.getNextState()));

Source

They do a thing here, which, basically throws out any prior mod result, in favor of doing some chiseling nonsense. Which means the anvil doesn't ever receive an event, because chisels + bits just sets the default to DEFAULT, instead of the ALLOW which we replaced.

Why is this random? Because Forge, in their infinite wisdom, decided that mod loading should be parallel and mod load order completely unspecified. So as we both register an event handler, the question is simple one of "which mod registers their event handler first". If it's TFC, our fix for anvil-shift-click interactions gets tossed by C&B.

In short, C&B does a bad, stupid thing here (they should not be overwriting the result when their own chisel handling returns Default), as it just brazenly overwrites actual specific cases where other mods need this behavior.