Can't backup Java ED

[dannythunder]

Describe the bug or issue being faced I can't get the backup working for my Java version. Bedrock works fine tho.

Configuration and Verbose Logs

DEBU[0000] Using /backups to match uid and gid          
DEBU[0000] Resolved UID=0 from match path               
DEBU[0000] Resolved GID=998 from match path             
[13:51:18.369][info    ] Initializing Bedrockifier Daemon
[13:51:18.394][info    ] Configuring Bedrockifier Daemon
[13:51:18.403][info    ] Loading Configuration From: /backups/config.yml
[13:51:18.420][info    ] Configuration Loaded, Running Service... (main.swift:83)
[13:51:18.443][info    ] Host PTY Handle Opened: /dev/pts/1 (6) (Terminal.swift:141)
[13:51:18.444][info    ] Child PTY Handle Opened: /dev/pts/1 (7) (Terminal.swift:162)
[13:51:18.445][debug   ] Process attached (Terminal.swift:81)
[13:51:18.445][info    ] Checking for servers that might not be cleaned up (BackupActor.swift:73)
[13:51:18.447][info    ] Backup Interval: 40.0 seconds (Service.swift:151)
[13:51:18.448][debug   ] [interval] Registered (ServiceTimer.swift:102)
[13:51:18.449][debug   ] [interval] Scheduled For Nov 2, 2023, 1:51:18 PM, Repeating 40.0 s (ServiceTimer.swift:81)
[13:51:18.449][info    ] Service Started Successfully. (Service.swift:101)
[13:51:18.450][info    ] minecraft-java is dirty, cleaning up (BackupActor.swift:77)
[13:51:18.450][debug   ] Starting Container Process (ContainerConnection.swift:69)
[13:51:18.450][debug   ] [interval] Event Fired. Valid Handler: true (ServiceTimer.swift:110)
[13:51:18.453][info    ] Resuming autosave on minecraft-java (BackupActor.swift:84)
[13:51:18.454][trace   ] Sending: save-on
 (Terminal.swift:181)
[13:51:18.456][debug   ] Expecting: ["Automatic saving is now enabled", "Saving is already turned on", "Got permission denied while trying to connect to the Docker daemon"] (Terminal.swift:227)
[13:51:18.458][trace   ] Data Received on file descriptor (6) (Terminal.swift:296)
[13:51:18.457][trace   ] Adding Expectation BB9A3F3D-240C-4CED-B587-4E61348D852D (Terminal.swift:265)
[13:51:18.459][debug   ] Timeout for Expectation is 60.0 s (Terminal.swift:271)
[13:51:18.459][info    ] Starting Full Backup (BackupActor.swift:159)
[13:51:18.459][debug   ] Starting Container Process (ContainerConnection.swift:69)
[13:51:18.460][error   ] The operation could not be completed. (NSCocoaErrorDomain error 3587.) (BackupActor.swift:182)
[13:51:18.460][error   ] Container minecraft-java failed to backup properly (BackupActor.swift:183)
[13:51:18.460][info    ] Performing Trim Jobs (BackupActor.swift:217)
[13:51:18.464][info    ] Full Backup Completed (BackupActor.swift:190)
[13:51:18.464][debug   ] Reseting Container Process (ContainerConnection.swift:90)
[13:51:18.464][error   ] The operation could not be completed. (PTYKit.PTYError error 4.) (BackupActor.swift:204)
[13:51:18.464][error   ] Full Backup Failed (BackupActor.swift:205)
[13:51:58.448][debug   ] [interval] Event Fired. Valid Handler: true (ServiceTimer.swift:110)
[13:51:58.448][info    ] Starting Full Backup (BackupActor.swift:159)
[13:51:58.449][debug   ] Starting Container Process (ContainerConnection.swift:69)
[13:51:58.449][error   ] The operation could not be completed. (NSCocoaErrorDomain error 3587.) (BackupActor.swift:182)
[13:51:58.449][error   ] Container minecraft-java failed to backup properly (BackupActor.swift:183)
[13:51:58.449][info    ] Performing Trim Jobs (BackupActor.swift:217)
[13:51:58.450][info    ] Full Backup Completed (BackupActor.swift:190)
[13:51:58.450][debug   ] Reseting Container Process (ContainerConnection.swift:90)
[13:51:58.450][error   ] The operation could not be completed. (PTYKit.PTYError error 4.) (BackupActor.swift:204)
[13:51:58.450][error   ] Full Backup Failed (BackupActor.swift:205)

Additional context I've tried a bunch of ways to get it working. I've check all the permissions for (running at root while learning about running a server so....)

Compose (removed some settings and such)

version: "3.3"

services:
  minecraft-java:
    restart: always
    container_name: minecraft-java
    image: itzg/minecraft-server
    ports:
      - 25565:25565
    environment:
      TZ: "Europe/Stockholm"
      stdin_open: true
      tty: true

    volumes:
      - ./minecraft-data:/data
      - ./saves-to-import:/worlds:ro

  bds-backup:
    image: kaiede/minecraft-bedrock-backup
    container_name: minecraft_backup-java
    restart: always
    depends_on:
      - "minecraft-java"
    environment:
      TZ: "Europe/Stockholm"
    tty: true
    volumes:
      - /var/run/docker.sock:/var/run/docker.sock
      - /opt/java/backups:/backups
      - /data/compose/16/minecraft-data:/server

- /opt/java/backups:/backups
- /data/compose/16/minecraft-data:/server

Both maps as the should inside the backup-container.

Administrating every container via Portainer (docker-compose).

[Kaiede]

So this the first time I’ve seen this specific error in any project I’ve worked on. (NSCocoaErrorDomain error 3587.)

This error is NSExecutableLoadError which means the executable used to connect to the container didn’t load and execute properly from within the container. But if nothing changed in the container, this shouldn’t happen. The only thing I can think of is that the download of the image to this specific server either got corrupted or there’s something else about the hardware configuration that’s the issue.

Can you try removing and redownloading the backup container image?

A couple quick questions in case the above doesn’t work:

• What’s different between the bedrock and java environments? What hardware is used, etc.
• What does the config yaml look like for the backup tool?

[dannythunder]

Running on VPS and Portainer. So it's the same image used in both (just separate docker-compose splited between bedrock and java).

(don't mind indentation here, it is correct. Markdown won't indentate my java-config correct. Validates here) Java´s config.yml:

containers:
  java:
    - name: minecraft-java
      worlds:
        - "/server/world"
schedule:
  interval: 40s <--- 40s just so that i could check the error doing some tests outside container
trim:
  trimDays: 2
  keepDays: 21
  minKeep: 5
loggingLevel: trace

Badrock´s config.yml:

containers:
  bedrock:
    - name: minecraft-bedrock
      worlds:
        - "/server/worlds/Bedrock level"
schedule:
  onLastLogout: true
trim:
  trimDays: 2
  keepDays: 21
  minKeep: 5

This is the VPS i use as server

Host folder for java:

root@vps-server:/opt/backups/backups# ls -lr /data/compose/16/minecraft-data/world/
stats
session.lock
region
poi
playerdata
level.dat_old
level.dat
entities
DIM1
DIM-1
datapacks
data
advancements

Inside the java backup-container:

root@vps-server:/opt/java/backups# docker exec -it minecraft-backups bash
root@27f0e87a97d9:/# ls -1r /server/java/world/
stats
session.lock
region
poi
playerdata
level.dat_old
level.dat
entities
DIM1
DIM-1
datapacks
data
advancements

I alos tried the :test tag. No go.

For now I manually do cp (dunno if that works) and snaphot the vps.

btw. Is this a wrapper over some python (think a read it somewhere)? I 've not checked the source code (and my Swift knowledge is pretty slim)

EDIT: Moved everything regarding backup to a singel docker-compose. the bds mount is created using docker volume create. It works with the server-container. Backups with Bedrocks works as before.

docker-compose.yml

version: "3.3"

services:
  bds-backup:
    image: kaiede/minecraft-bedrock-backup
    container_name: minecraft-backups
    restart: always
    environment:
      TZ: "Europe/Stockholm"
    tty: true
    volumes:
      # För att kunna ansluta till docker
      - /var/run/docker.sock:/var/run/docker.sock
      # Vart backup lagras på server-disk
      - /opt/backups/backups:/backups

      # Varje servers katalog för data
      - /data/compose/16/minecraft-data:/server/java
      - bds:/server/bedrock
volumes:
  bds:
    external: true

config.yml

containers:
  java:
    - name: minecraft-java
      worlds:
        - "/server/java/world"
  bedrock:
    - name: minecraft-bedrock
      worlds:
        - "/server/bedrock/worlds/Bedrock level"
schedule:
  #onLastLogout: true
  interval: 40s
trim:
  trimDays: 2
  keepDays: 21
  minKeep: 5
loggingLevel: trace

New log:

[14:19:17.460][trace   ] Data Received on file descriptor (6) (Terminal.swift:296)
[14:19:17.461][trace   ] Processing 1 Expects (Terminal.swift:311)
[14:19:17.461][debug   ] Content Read: [2023-11-03 14:19:17:622 INFO] Changes to the world are resumed.

 (Terminal.swift:236)
[14:19:17.461][trace   ] Removing Expectation 8E7E51E4-F86E-4192-A1B7-0C5632D38A3D (Terminal.swift:252)
[14:19:17.461][debug   ] Match Found: [2023-11-03 14:19:17:622 INFO] Changes to the world are resumed.

 (Terminal.swift:238)
[14:19:17.462][debug   ] Releasing save hold on minecraft-bedrock (ContainerConnection.swift:320)
[14:19:17.462][debug   ] Terminating Docker Process (ContainerConnection.swift:79)
[14:19:17.467][trace   ] Process terminated (Process.swift:41)
[14:19:17.467][debug   ] Calling process detach handlers (Terminal.swift:94)
[14:19:17.468][debug   ] Process detached (Terminal.swift:99)
[14:19:17.468][debug   ] Starting Container Process (ContainerConnection.swift:69)
[14:19:17.468][error   ] The operation could not be completed. (NSCocoaErrorDomain error 3587.) (BackupActor.swift:182)
[14:19:17.468][error   ] Container minecraft-java failed to backup properly (BackupActor.swift:183)
[14:19:17.468][info    ] Performing Trim Jobs (BackupActor.swift:217)
[14:19:17.482][debug   ] Processing: Bedrock level (Backup.swift:93)
[14:19:17.489][info    ] Full Backup Completed (BackupActor.swift:190)
[14:19:17.489][debug   ] Reseting Container Process (ContainerConnection.swift:90)
[14:19:17.489][debug   ] Process attached (Terminal.swift:81)
[14:19:17.489][debug   ] Reseting Container Process (ContainerConnection.swift:90)
[14:19:17.489][error   ] The operation could not be completed. (PTYKit.PTYError error 4.) (BackupActor.swift:204)
[14:19:17.489][error   ] Full Backup Failed (BackupActor.swift:205)
[14:19:57.173][debug   ] [interval] Event Fired. Valid Handler: true (ServiceTimer.swift:110)
[14:19:57.174][info    ] Starting Full Backup (BackupActor.swift:159)
[14:19:57.174][debug   ] Starting Container Process (ContainerConnection.swift:69)
[14:19:57.175][debug   ] Taking save hold on minecraft-bedrock (ContainerConnection.swift:312)
[14:19:57.177][trace   ] Sending: save hold
 (Terminal.swift:181)
[14:19:57.177][debug   ] Expecting: ["Saving", "The command is already running", "Got permission denied while trying to connect to the Docker daemon"] (Terminal.swift:227)
[14:19:57.177][trace   ] Adding Expectation 52C7D1E0-9140-4ED1-AD7E-304EDFE38255 (Terminal.swift:265)
[14:19:57.178][debug   ] Timeout for Expectation is 10.0 s (Terminal.swift:271)
[14:19:57.243][trace   ] Data Received on file descriptor (6) (Terminal.swift:296)
[14:19:57.244][trace   ] Processing 1 Expects (Terminal.swift:311)
[14:19:57.244][debug   ] Content Read: save hold

 (Terminal.swift:236)
[14:19:57.245][trace   ] Content Has No Matches (Terminal.swift:241)
[14:19:57.264][trace   ] Data Received on file descriptor (6) (Terminal.swift:296)
[14:19:57.264][trace   ] Processing 1 Expects (Terminal.swift:311)
[14:19:57.265][debug   ] Content Read: [2023-11-03 14:19:57:425 INFO] Saving...

 (Terminal.swift:236)
[14:19:57.266][trace   ] Removing Expectation 52C7D1E0-9140-4ED1-AD7E-304EDFE38255 (Terminal.swift:252)
[14:19:57.266][debug   ] Match Found: [2023-11-03 14:19:57:425 INFO] Saving...

 (Terminal.swift:238)
[14:19:57.267][trace   ] Sending: save query
 (Terminal.swift:181)
[14:19:57.267][debug   ] Expecting: ["Files are now ready to be copied", "Got permission denied while trying to connect to the Docker daemon"] (Terminal.swift:227)
[14:19:57.267][trace   ] Adding Expectation 1BC4218C-3F85-4BAF-9CB6-F3CFA4860DA5 (Terminal.swift:265)
[14:19:57.268][debug   ] Timeout for Expectation is 10.0 s (Terminal.swift:271)
[14:19:57.268][trace   ] Data Received on file descriptor (6) (Terminal.swift:296)
[14:19:57.269][trace   ] Processing 1 Expects (Terminal.swift:311)
[14:19:57.269][debug   ] Content Read: save query

 (Terminal.swift:236)
[14:19:57.269][trace   ] Content Has No Matches (Terminal.swift:241)
[14:19:57.315][trace   ] Data Received on file descriptor (6) (Terminal.swift:296)
[14:19:57.316][trace   ] Processing 1 Expects (Terminal.swift:311)
[14:19:57.316][debug   ] Content Read: [2023-11-03 14:19:57:477 INFO] Data saved. Files are now ready to be copied.

Bedrock level/db/000006.log:32962, Bedrock level/db/CURRENT:16, Bedrock level/db/000005.ldb:453, Bedrock level/db/MANIFEST-000004:101, Bedrock level/level.dat:2741, Bedrock level/level.dat_old:2741, Bedrock level/levelname.txt:13

 (Terminal.swift:236)
[14:19:57.317][trace   ] Removing Expectation 1BC4218C-3F85-4BAF-9CB6-F3CFA4860DA5 (Terminal.swift:252)
[14:19:57.317][debug   ] Match Found: [2023-11-03 14:19:57:477 INFO] Data saved. Files are now ready to be copied.

Bedrock level/db/000006.log:32962, Bedrock level/db/CURRENT:16, Bedrock level/db/000005.ldb:453, Bedrock level/db/MANIFEST-000004:101, Bedrock level/level.dat:2741, Bedrock level/level.dat_old:2741, Bedrock level/levelname.txt:13

 (Terminal.swift:238)
[14:19:57.317][info    ] Starting Backup of worlds for: minecraft-bedrock (ContainerConnection.swift:124)
[14:19:57.317][info    ] Backing Up: Bedrock level (ContainerConnection.swift:130)
[14:19:57.323][info    ] Backed up as: Bedrock level.20231103-141957.mcworld (ContainerConnection.swift:132)
[14:19:57.324][info    ] Backups for minecraft-bedrock finished successfully... (ContainerConnection.swift:158)
[14:19:57.324][trace   ] Sending: save resume
 (Terminal.swift:181)
[14:19:57.324][debug   ] Expecting: ["Changes to the level are resumed", "Changes to the world are resumed", "A previous save has not been completed", "Got permission denied while trying to connect to the Docker daemon"] (Terminal.swift:227)
[14:19:57.324][trace   ] Adding Expectation E2CECC16-5F4A-4F91-8801-A1505C28F71F (Terminal.swift:265)
[14:19:57.325][debug   ] Timeout for Expectation is 60.0 s (Terminal.swift:271)
[14:19:57.326][trace   ] Data Received on file descriptor (6) (Terminal.swift:296)
[14:19:57.326][trace   ] Processing 1 Expects (Terminal.swift:311)
[14:19:57.326][debug   ] Content Read: save resume

 (Terminal.swift:236)
[14:19:57.326][trace   ] Content Has No Matches (Terminal.swift:241)
[14:19:57.360][trace   ] Data Received on file descriptor (6) (Terminal.swift:296)
[14:19:57.361][trace   ] Processing 1 Expects (Terminal.swift:311)
[14:19:57.361][debug   ] Content Read: [2023-11-03 14:19:57:522 INFO] Changes to the world are resumed.

 (Terminal.swift:236)
[14:19:57.361][trace   ] Removing Expectation E2CECC16-5F4A-4F91-8801-A1505C28F71F (Terminal.swift:252)
[14:19:57.361][debug   ] Match Found: [2023-11-03 14:19:57:522 INFO] Changes to the world are resumed.

 (Terminal.swift:238)
[14:19:57.362][debug   ] Releasing save hold on minecraft-bedrock (ContainerConnection.swift:320)
[14:19:57.362][debug   ] Terminating Docker Process (ContainerConnection.swift:79)
[14:19:57.368][trace   ] Process terminated (Process.swift:41)
[14:19:57.369][debug   ] Calling process detach handlers (Terminal.swift:94)
[14:19:57.369][debug   ] Process detached (Terminal.swift:99)
[14:19:57.369][debug   ] Starting Container Process (ContainerConnection.swift:69)
[14:19:57.369][error   ] The operation could not be completed. (NSCocoaErrorDomain error 3587.) (BackupActor.swift:182)
[14:19:57.369][error   ] Container minecraft-java failed to backup properly (BackupActor.swift:183)
[14:19:57.369][info    ] Performing Trim Jobs (BackupActor.swift:217)
[14:19:57.376][debug   ] Processing: Bedrock level (Backup.swift:93)
[14:19:57.382][info    ] Full Backup Completed (BackupActor.swift:190)
[14:19:57.383][debug   ] Reseting Container Process (ContainerConnection.swift:90)
[14:19:57.383][debug   ] Process attached (Terminal.swift:81)
[14:19:57.383][debug   ] Reseting Container Process (ContainerConnection.swift:90)
[14:19:57.383][error   ] The operation could not be completed. (PTYKit.PTYError error 4.) (BackupActor.swift:204)
[14:19:57.383][error   ] Full Backup Failed (BackupActor.swift:205)

[Kaiede]

I alos tried the :test tag. No go.

Unfortunately, that's not too surprising as there's not a whole lot in the test tag that isn't in latest. Just some support for calling into rcon-cli in the container rather than attaching to the server's in/out directly.

This is the VPS i use as server

I assume this is just an x86 server? Do you have any details on what the host environment looks like? What architecture, etc?

I did just push a new test tag though, which is a fresh build using the latest toolchain. Might be worth trying?

[Kaiede]

FYI: There's been chatter on the itgz's minecraft-bedrock-server issue list because tools like mine don't work well with non-docker container hosts, and so I've been looking at adding support for using rcon as the way to connect to the container rather than interacting with docker. It may help in this case once it's ready, but it will only be useful for Java in the short term (Bedrock has no rcon and someone would need to wrap the console into something that looks like rcon).

https://github.com/Kaiede/Bedrockifier/issues/72

[Kaiede]

Two updates here:

1) rcon support is in the test-amd64 tag, but not yet test (ARM64 is always a little flaky due to QEMU and so tags sometimes take a couple tries to get fully updated). If you are using interval backups for Java, this might unblock you? Worth trying.

2) ssh support is something I'm working on with itzg which might also help here, but it will take a bit more time as everything gets pushed to the various containers.

[Kaiede]

One more update:

While working on SSH support, I was able to reproduce this. It looks like it is specific to interval backups. If I use onLastLogout, it creates and holds open the processes once.

It's very weird. I don't normally host both Bedrock and Java on the same VM so I missed it.

[Kaiede]

Okay, I think I know what's going on:

• If something causes the backup to be interrupted, such as say, hitting the timeouts (which is very rare on bedrock), or auto pause halts the server (a Java-only thing in itzg's container), then the connection never gets torn down when one of these errors occurs. But the only way you'll see the pattern is by looking at the log as a whole, the clippings provided earlier in this bug weren't enough to see the pattern as it happens over multiple intervals/attempts.
• So long as this connection is open, then the terminal used for that server can't be used again until the connection is properly torn down, which is triggering this error. It's weird because this error talks about the executable, but it's really about the input/output of the terminal for the process.

So, I've got a fix which should at least stop the backup from getting stuck like this, but I don't have a full fix without knowing what was the original failure.

[Kaiede]

Fix should be in the test tag. It doesn't guarantee every backup will succeed, but maybe give it a try and see how much it helps?

If you are still having issues, I'd be curious in more complete Minecraft + Backup logs to see if we can track down the original failure point.

[Kaiede]

It's been over a month at this point, if there's still an issue to investigate, feel free to reopen with new details.