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.

Sign up for GitHub

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

Jump to bottom

docker installed promcord process keeps restarting #151

Closed
dmamalis opened this issue Oct 22, 2021 · 14 comments
Closed

docker installed promcord process keeps restarting #151

dmamalis opened this issue Oct 22, 2021 · 14 comments

Comments

@dmamalis
Copy link

General Troubleshooting

Bug Report

promcord docker process keeps restarting. Not sure if this is a bug or a misconfiguration of the bot on our server.

18:47:31.632 [main] INFO  de.biosphere.promcord.Promcord - Starting promcord
18:47:31.702 [main] INFO  de.biosphere.promcord.Configuration - Configuration loaded!
18:47:44.083 [main] ERROR de.biosphere.promcord.Promcord - Encountered exception while initializing JDA!
18:47:44.102 [main] ERROR de.biosphere.promcord.Promcord - Encountered exception while initializing the bot!
java.lang.IllegalStateException: Could not acquire lock in a reasonable timeframe! (10 seconds)
        at net.dv8tion.jda.api.utils.MiscUtil.tryLock(MiscUtil.java:164)
        at net.dv8tion.jda.api.utils.MiscUtil.locked(MiscUtil.java:126)
        at net.dv8tion.jda.internal.requests.ratelimit.BotRateLimiter.stop(BotRateLimiter.java:169)
        at net.dv8tion.jda.internal.requests.Requester.stop(Requester.java:321)
        at net.dv8tion.jda.internal.JDAImpl.shutdownInternals(JDAImpl.java:701)
        at net.dv8tion.jda.internal.JDAImpl.shutdown(JDAImpl.java:682)
        at net.dv8tion.jda.internal.JDAImpl.shutdownNow(JDAImpl.java:671)
        at net.dv8tion.jda.internal.JDAImpl.verifyToken(JDAImpl.java:360)
        at net.dv8tion.jda.internal.JDAImpl.login(JDAImpl.java:281)
        at net.dv8tion.jda.internal.JDAImpl.login(JDAImpl.java:248)
        at net.dv8tion.jda.api.JDABuilder.build(JDABuilder.java:1929)
        at de.biosphere.promcord.Promcord.initializeJDA(Promcord.java:56)
        at de.biosphere.promcord.Promcord.<init>(Promcord.java:29)
        at de.biosphere.promcord.Promcord.main(Promcord.java:72)
18:47:46,779 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
18:47:46,785 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy]
18:47:46,793 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [jar:file:/promcord.jar!/logback.xml]
18:47:46,856 |-INFO in ch.qos.logback.core.joran.spi.ConfigurationWatchList@3d8314f0 - URL [jar:file:/promcord.jar!/logback.xml] is not of type file
18:47:47,227 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - debug attribute not set
18:47:47,248 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [net.dv8tion.jda] to ERROR
18:47:47,248 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
18:47:47,267 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [Console]
18:47:47,308 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
18:47:47,603 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [io.sentry.logback.SentryAppender]
18:47:47,777 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [Sentry]
18:47:47,807 |-WARN in io.sentry.logback.SentryAppender[Sentry] - Failed to init Sentry during appender initialization: DSN is required. Use empty string to disable SDK.
18:47:47,807 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to INFO
18:47:47,807 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [Console] to Logger[ROOT]
18:47:47,809 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [Sentry] to Logger[ROOT]
18:47:47,809 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
18:47:47,810 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@2df32bf7 - Registering current configuration as safe fallback point
@Edouard127
Copy link

Can you provide more informations ?
(docker-compose/docker-cli)

@dmamalis
Copy link
Author

Sure.
This is docker-compose 1.25.0.
I had a quick look at the code and followed the installation process once again. It looks as if this fails too early to be a bot configuration issue. I could use some more debug info on initializeJDA(). I will try to find some time this week to dive into this but honestly hoping that you will beat me to it :)

@nimarion
Copy link
Owner

Probably related to discord-jda/JDA#1700. How often does the error occur on your system?

@dmamalis
Copy link
Author

dmamalis commented Oct 23, 2021 •
edited
Loading

Probably related to DV8FromTheWorld/JDA#1700. How often does the error occur on your system?

Unfortunately constantly. I tried to install on 3 different linux boxes. Two with docker-compose 1.25.0 and one with docker compose 1.24.1

CONTAINER ID   IMAGE                 COMMAND                  CREATED        STATUS         PORTS                  NAMES
64fec1af2b4e   grafana/grafana       "/run.sh"                23 hours ago   Up 23 hours    0.0.0.0:80->3000/tcp   docker-promcord_grafana_1
4fbc5dbc6bd5   biospheere/promcord   "java -jar promcord.…"   23 hours ago   Up 7 seconds   8080/tcp               promcord
21a6db3bd91f   prom/prometheus       "/bin/prometheus --c…"   23 hours ago   Up 23 hours    9090/tcp               disport-prom

@nimarion
Copy link
Owner

Can you reproduce the issue on https://labs.play-with-docker.com/ ?

@Edouard127
Copy link

Edouard127 commented Oct 23, 2021 •
edited
Loading

Using 1.26.0 I can't reproduce the issue
image

@dmamalis
Copy link
Author

sorry lads. Same with 1.26.0 on all machines.
Same on labs (print from @nimarion lab

[node1] (local) root@192.168.0.18 ~/promcord
$ docker ps
CONTAINER ID   IMAGE                 COMMAND                  CREATED         STATUS         PORTS                  NAMES
f530a5b702b8   biospheere/promcord   "java -jar promcord.…"   3 minutes ago   Up 7 seconds   8080/tcp               promcord
bd9f8e935b7b   grafana/grafana       "/run.sh"                4 minutes ago   Up 4 minutes   0.0.0.0:80->3000/tcp   promcord_grafana_1
b9cc025a8ce4   prom/prometheus       "/bin/prometheus --c…"   4 minutes ago   Up 4 minutes   9090/tcp               disport-prom

I feel like I am not helping you much. The JDA issue seems a possible candidate however something is stopping you from reproducing. Are you sure this is not discord dev settings issue instead of a bug? I am completely out of my waters here.
:-)

@Edouard127
Copy link

@dmamalis Can you send the docker-compose.yaml here ?

@dmamalis
Copy link
Author

It's just a copy of the sample yml. Initially I had it configured on a different port, but that is not the issue. I also tried with the original ports.

version: '3'
services:
  promcord:
    image: "biospheere/promcord"
    restart: always
    env_file: .env
    container_name: "promcord"
    expose:
      - 8080
  prometheus:
    image: "prom/prometheus"
    restart: always
    container_name: "disport-prom"
    volumes:
      - './prometheus.yml:/etc/prometheus/prometheus.yml'
      - prometheus:/prometheus
    command:
      - '--config.file=/etc/prometheus/prometheus.yml'
      - '--storage.tsdb.path=/prometheus'
      - '--web.console.libraries=/usr/share/prometheus/console_libraries'
      - '--web.console.templates=/usr/share/prometheus/consoles'
      - '--storage.tsdb.retention.time=200h'
  grafana:
    image: "grafana/grafana"
    restart: always
    volumes:
      - grafana_data:/var/lib/grafana
      - ./provisioning:/etc/grafana/provisioning
    ports:
      - 80:3000
    depends_on:
      - prometheus
    links:
      - prometheus

volumes:
  prometheus:
  grafana_data:

@Edouard127
Copy link

When i tried to do the issue, i ran docker-compose up
Could you do the same and send full output

@dmamalis
Copy link
Author

dmamalis commented Oct 24, 2021 •
edited
Loading

I managed to debug this by using the Python Discord SDK to run a simple bot and check the bot settings. Turns out that this is most possibly a Bot Settings issues rather than the JDA bug. However, it only works on the docker-compose v1.26 machine although I still doubt this is a docker-compose version issue. In this case, docker-compose is pretty simple and straightforward. I really see no reason why this could be related. I will come back to that when I have some extra time to test.

If I can be of any help here, a bit more informative debugging could be useful. Also, for people who have no experience with custom discord bots, the bot settings are not quite self explanatory. Not really your fault, but it might help avoiding issues like this one.

You can consider this closed as a non-issue.

@mazzma12
Copy link

mazzma12 commented Feb 9, 2022 •
edited
Loading

same here with docker-compose 1.29.2

10:37:28,235 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
10:37:28,237 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy]
10:37:28,238 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [jar:file:/promcord.jar!/logback.xml]
10:37:28,257 |-INFO in ch.qos.logback.core.joran.spi.ConfigurationWatchList@3d8314f0 - URL [jar:file:/promcord.jar!/logback.xml] is not of type file
10:37:28,353 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - debug attribute not set
10:37:28,357 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [net.dv8tion.jda] to ERROR
10:37:28,358 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
10:37:28,362 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [Console]
10:37:28,371 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] pr

10:37:28,461 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [io.sentry.logback.SentryAppender]
10:37:28,547 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [Sentry]
10:37:28,563 |-WARN in io.sentry.logback.SentryAppender[Sentry] - Failed to init Sentry during appender initialization: DSN is required. Use empty string to disable SDK.
10:37:28,563 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to INFO
10:37:28,563 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [Console] to Logger[ROOT]
10:37:28,563 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [Sentry] to Logger[ROOT]
10:37:28,563 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
10:37:28,564 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@2df32bf7 - Registering current configuration as safe fallback point

@Edouard127 Edouard127 mentioned this issue Feb 9, 2022
Closed
@DMTryptamines
Copy link

I'm also getting this issue, any fix coming?

09:12:22.452 [main] INFO  de.biosphere.promcord.Promcord - Starting promcord
09:12:22.497 [main] INFO  de.biosphere.promcord.Configuration - Configuration loaded!
09:12:33.883 [main] ERROR de.biosphere.promcord.Promcord - Encountered exception while initializing JDA!
09:12:33.890 [main] ERROR de.biosphere.promcord.Promcord - Encountered exception while initializing the bot!
java.lang.IllegalStateException: Could not acquire lock in a reasonable timeframe! (10 seconds)
        at net.dv8tion.jda.api.utils.MiscUtil.tryLock(MiscUtil.java:164)
        at net.dv8tion.jda.api.utils.MiscUtil.locked(MiscUtil.java:126)
        at net.dv8tion.jda.internal.requests.ratelimit.BotRateLimiter.stop(BotRateLimiter.java:169)
        at net.dv8tion.jda.internal.requests.Requester.stop(Requester.java:321)
        at net.dv8tion.jda.internal.JDAImpl.shutdownInternals(JDAImpl.java:701)
        at net.dv8tion.jda.internal.JDAImpl.shutdown(JDAImpl.java:682)
        at net.dv8tion.jda.internal.JDAImpl.shutdownNow(JDAImpl.java:671)
        at net.dv8tion.jda.internal.JDAImpl.verifyToken(JDAImpl.java:360)
        at net.dv8tion.jda.internal.JDAImpl.login(JDAImpl.java:281)
        at net.dv8tion.jda.internal.JDAImpl.login(JDAImpl.java:248)
        at net.dv8tion.jda.api.JDABuilder.build(JDABuilder.java:1929)
        at de.biosphere.promcord.Promcord.initializeJDA(Promcord.java:56)
        at de.biosphere.promcord.Promcord.<init>(Promcord.java:29)
        at de.biosphere.promcord.Promcord.main(Promcord.java:72)

@DMTryptamines
Copy link

Right after porting the above I figured out the issue. I had to set these settings and the block of text went away, still get the Could NOT find resource [logback-test.xml] and Could NOT find resource [logback.groovy] errors though. You may only have to set on I'm not sure.

intents

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
5 participants
@dmamalis @mazzma12 @nimarion @Edouard127 @DMTryptamines