docker-minecraft-server icon indicating copy to clipboard operation
docker-minecraft-server copied to clipboard

Published 20 hours ago • verified publisher icon itzg

docker image pushed on 8/11 broke server

Open davidbhoward opened this issue 1 year ago • 4 comments

Describe the problem

I run several docker vanilla Java servers in my house, and when I tried to access them today, they weren't running. After a bit of digging, I found that a new image was pushed sometime on 8/11, which my automation picked up on 8/12 using Watchtower and deployed. I started seeing the error and didn't notice it until today.

Here is the log line where Watchtower updated the image, and it started to fail time="2024-08-12T02:00:09-07:00" level=debug msg=Comparing local="sha256:403ffaa737586d302e980d292ddf2837cc1ab2293ca005bc47b716f852960eed" remote="sha256:f9cc420f60eda63fbe5d7f5621ba3d4efa4a13ae64a6a93399c2865294cb0586"

I reverted to itzg/minecraft-server:latest@sha256:403ffaa737586d302e980d292ddf2837cc1ab2293ca005bc47b716f852960eed and everything is working again.

Container definition

  minecraft-java-survival:
    container_name: minecraft-java-survival
    image: itzg/minecraft-server
    user: 1000:1000
    environment:
      - SERVER_NAME=Cortana
      - INIT_MEMORY=12G
      - MAX_MEMORY=24G
      - UID=1000
      - GID=1000
      - EULA=TRUE
      - GAMEMODE=survival
      - DIFFICULTY=easy
      - MAX_THREADS=8
      - VIEW_DISTANCE=32
      - TICK_DISTANCE=4
      - DEFAULT_PLAYER_PERMISSION_LEVEL=member  # operator
      - OPS="xxx"
    volumes:
      - ./minecraft/java/survival/data:/data
    networks:
      macvlanmc:
        ipv4_address: 10.0.50.5
    ports:
      - "25565:25565"
    restart: unless-stopped

Container logs

2024-08-17 15:57:12.485	[init] Resolving type given VANILLA
2024-08-17 15:57:13.875	[init] Resolved version given LATEST into 1.21.1
2024-08-17 15:57:14.317	[mc-image-helper] 22:57:14.315 INFO  : Created/updated 1 property in /data/server.properties
2024-08-17 15:57:16.024	[mc-image-helper] 22:57:16.022 ERROR : 'manage-users' command failed. Version is 1.39.9
2024-08-17 15:57:16.024	me.itzg.helpers.http.FailedRequestException: HTTP request of https://playerdb.co/api/player/minecraft/%222533274792815295%2C2535422481116265%2C2535473455360206%22 failed with 500 Internal Server Error: Fetching object content
2024-08-17 15:57:16.024		at me.itzg.helpers.http.FetchBuilderBase.lambda$failedRequestMono$2(FetchBuilderBase.java:220)
2024-08-17 15:57:16.024		at reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:132)
2024-08-17 15:57:16.024		at reactor.core.publisher.FluxDefaultIfEmpty$DefaultIfEmptySubscriber.onNext(FluxDefaultIfEmpty.java:122)
2024-08-17 15:57:16.024		at reactor.core.publisher.FluxHandle$HandleSubscriber.onNext(FluxHandle.java:129)
2024-08-17 15:57:16.024		at reactor.core.publisher.FluxMap$MapConditionalSubscriber.onNext(FluxMap.java:224)
2024-08-17 15:57:16.024		at reactor.core.publisher.FluxDoFinally$DoFinallySubscriber.onNext(FluxDoFinally.java:113)
2024-08-17 15:57:16.024		at reactor.core.publisher.FluxHandleFuseable$HandleFuseableSubscriber.onNext(FluxHandleFuseable.java:194)
2024-08-17 15:57:16.024		at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.onNext(FluxContextWrite.java:107)
2024-08-17 15:57:16.024		at reactor.core.publisher.Operators$BaseFluxToMonoOperator.completePossiblyEmpty(Operators.java:2071)
2024-08-17 15:57:16.024		at reactor.core.publisher.MonoCollectList$MonoCollectListSubscriber.onComplete(MonoCollectList.java:118)
2024-08-17 15:57:16.024		at reactor.core.publisher.FluxPeek$PeekSubscriber.onComplete(FluxPeek.java:260)
2024-08-17 15:57:16.024		at reactor.core.publisher.FluxMap$MapSubscriber.onComplete(FluxMap.java:144)
2024-08-17 15:57:16.024		at reactor.netty.channel.FluxReceive.onInboundComplete(FluxReceive.java:415)
2024-08-17 15:57:16.024		at reactor.netty.channel.ChannelOperations.onInboundComplete(ChannelOperations.java:446)
2024-08-17 15:57:16.024		at reactor.netty.channel.ChannelOperations.terminate(ChannelOperations.java:500)
2024-08-17 15:57:16.024		at reactor.netty.http.client.HttpClientOperations.onInboundNext(HttpClientOperations.java:800)
2024-08-17 15:57:16.024		at reactor.netty.channel.ChannelOperationsHandler.channelRead(ChannelOperationsHandler.java:115)
2024-08-17 15:57:16.024		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444)
2024-08-17 15:57:16.024		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
2024-08-17 15:57:16.024		at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
2024-08-17 15:57:16.024		at io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:289)
2024-08-17 15:57:16.024		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442)
2024-08-17 15:57:16.024		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
2024-08-17 15:57:16.024		at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
2024-08-17 15:57:16.024		at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:436)
2024-08-17 15:57:16.024		at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:346)
2024-08-17 15:57:16.024		at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:318)
2024-08-17 15:57:16.024		at io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:251)
2024-08-17 15:57:16.024		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442)
2024-08-17 15:57:16.024		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
2024-08-17 15:57:16.024		at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
2024-08-17 15:57:16.024		at io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1473)
2024-08-17 15:57:16.024		at io.netty.handler.ssl.SslHandler.decodeJdkCompatible(SslHandler.java:1336)
2024-08-17 15:57:16.024		at io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1385)
2024-08-17 15:57:16.024		at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:530)
2024-08-17 15:57:16.024		at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:469)
2024-08-17 15:57:16.024		at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:290)
2024-08-17 15:57:16.024		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444)
2024-08-17 15:57:16.024		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
2024-08-17 15:57:16.024		at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
2024-08-17 15:57:16.024		at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1407)
2024-08-17 15:57:16.024		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:440)
2024-08-17 15:57:16.024		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
2024-08-17 15:57:16.024		at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:918)
2024-08-17 15:57:16.024		at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:799)
2024-08-17 15:57:16.024		at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:501)
2024-08-17 15:57:16.024		at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:399)
2024-08-17 15:57:16.024		at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:994)
2024-08-17 15:57:16.024		at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
2024-08-17 15:57:16.024		at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
2024-08-17 15:57:16.024		at java.base/java.lang.Thread.run(Unknown Source)
2024-08-17 15:57:16.024		Suppressed: java.lang.Exception: #block terminated with an error
2024-08-17 15:57:16.024			at reactor.core.publisher.BlockingSingleSubscriber.blockingGet(BlockingSingleSubscriber.java:103)
2024-08-17 15:57:16.024			at reactor.core.publisher.Mono.block(Mono.java:1712)
2024-08-17 15:57:16.024			at me.itzg.helpers.users.PlayerdbUserApi.resolveUser(PlayerdbUserApi.java:51)
2024-08-17 15:57:16.024			at me.itzg.helpers.users.ManageUsersCommand.lambda$resolveJavaUserId$1(ManageUsersCommand.java:254)
2024-08-17 15:57:16.024			at java.base/java.util.Optional.orElseGet(Unknown Source)
2024-08-17 15:57:16.024			at me.itzg.helpers.users.ManageUsersCommand.resolveJavaUserId(ManageUsersCommand.java:218)
2024-08-17 15:57:16.024			at me.itzg.helpers.users.ManageUsersCommand.reconcile(ManageUsersCommand.java:165)
2024-08-17 15:57:16.024			at me.itzg.helpers.users.ManageUsersCommand.processJavaUserIdList(ManageUsersCommand.java:138)
2024-08-17 15:57:16.024			at me.itzg.helpers.users.ManageUsersCommand.call(ManageUsersCommand.java:101)
2024-08-17 15:57:16.024			at me.itzg.helpers.users.ManageUsersCommand.call(ManageUsersCommand.java:35)
2024-08-17 15:57:16.024			at picocli.CommandLine.executeUserObject(CommandLine.java:2045)
2024-08-17 15:57:16.024			at picocli.CommandLine.access$1500(CommandLine.java:148)
2024-08-17 15:57:16.024			at picocli.CommandLine$RunLast.executeUserObjectOfLastSubcommandWithSameParent(CommandLine.java:2465)
2024-08-17 15:57:16.024			at picocli.CommandLine$RunLast.handle(CommandLine.java:2457)
2024-08-17 15:57:16.024			at picocli.CommandLine$RunLast.handle(CommandLine.java:2419)
2024-08-17 15:57:16.024			at picocli.CommandLine$AbstractParseResultHandler.execute(CommandLine.java:2277)
2024-08-17 15:57:16.024			at picocli.CommandLine$RunLast.execute(CommandLine.java:2421)
2024-08-17 15:57:16.024			at picocli.CommandLine.execute(CommandLine.java:2174)
2024-08-17 15:57:16.024			at me.itzg.helpers.McImageHelper.main(McImageHelper.java:159)

My hunch is this change broke it because I do have an OP list: https://github.com/itzg/docker-minecraft-server/commit/cea839aa67ba4c949ce4b44992da767ff103abbc

davidbhoward avatar Aug 17 '24 23:08 davidbhoward

Is your OPS actually an empty string?

I'm not sure where it got such a strange username in the lookup URL

https://playerdb.co/api/player/minecraft/%222533274792815295%2C2535422481116265%2C2535473455360206%22

You probably need to set EXISTING_OPS_FILE back to the old default value of "SKIP".

itzg avatar Aug 17 '24 23:08 itzg

Oh, I see you later changed your config snippet. Do you have a comma separated list of usernames or UUIDs for your OPS?

itzg avatar Aug 17 '24 23:08 itzg

Aha! When using environment list syntax, then do not include quotes, like

      - OPS="xxx"

It needs to be

      - OPS=user1,user2

Better yet, I highly recommend using object syntax since it is much more robust and leverages YAML features, such as:

    environment:
      SERVER_NAME: Cortana
      INIT_MEMORY: 12G
      MAX_MEMORY: 24G
      UID: 1000
      GID: 1000
      EULA: TRUE
      GAMEMODE: survival
      DIFFICULTY: easy
      MAX_THREADS: 8
      VIEW_DISTANCE: 32
      TICK_DISTANCE: 4
      DEFAULT_PLAYER_PERMISSION_LEVEL: member  # operator
      OPS: "xxx"

itzg avatar Aug 17 '24 23:08 itzg

Thanks for the info. I understand about using object syntax, and I have updated my syntax. However, that was not the cause here. The issue was with the player's UUID. It looks like our UUIDs have changed, and after digging up my UUID and updating it in the config, things are working again.

davidbhoward avatar Aug 18 '24 20:08 davidbhoward

This issue is stale because it has been open 30 days with no activity. Please add a comment describing the reason to keep this issue open.

github-actions[bot] avatar Sep 18 '24 02:09 github-actions[bot]