Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

docker image pushed on 8/11 broke server #3045

Closed
davidbhoward opened this issue Aug 17, 2024 · 5 comments
Closed

docker image pushed on 8/11 broke server #3045

davidbhoward opened this issue Aug 17, 2024 · 5 comments
Labels
discussion status/stale No recently activity has been seen and will be closed soon.

Comments

@davidbhoward
Copy link

davidbhoward commented Aug 17, 2024

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: cea839a

@itzg
Copy link
Owner

itzg commented Aug 17, 2024

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
Copy link
Owner

itzg commented Aug 17, 2024

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

@itzg
Copy link
Owner

itzg commented Aug 17, 2024

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"

@davidbhoward
Copy link
Author

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.

Copy link

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 github-actions bot added the status/stale No recently activity has been seen and will be closed soon. label Sep 18, 2024
@github-actions github-actions bot closed this as not planned Won't fix, can't repro, duplicate, stale Sep 23, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
discussion status/stale No recently activity has been seen and will be closed soon.
Projects
None yet
Development

No branches or pull requests

2 participants