itzg / docker-mc-backup

Provides a side-car container to backup itzg/minecraft-server world data
https://hub.docker.com/r/itzg/mc-backup
MIT License
315 stars 52 forks source link

Error Querying the server #88

Open AndrewTevebaugh opened 2 years ago

AndrewTevebaugh commented 2 years ago

Hello, I just tried to get this container back up and running after not running it for a few months and I noticed that the backup worked successfully the first time around, but after that it would not connect to the minecraft server container.

As you can see it generates the first backup successfully on startup, but after that it cannot seem to connect to the server.


2022-05-10T00:54:26-0400 INFO waiting initial delay of 2m...
2022-05-10T00:56:26-0400 INFO waiting for rcon readiness...
2022-05-10T00:56:26-0400 INFO Command executed successfully rcon-cli save-on
2022-05-10T00:56:26-0400 INFO Command executed successfully rcon-cli save-off
2022-05-10T00:56:27-0400 INFO Command executed successfully rcon-cli save-all flush
2022-05-10T00:56:27-0400 INFO Command executed successfully sync
2022-05-10T00:56:27-0400 INFO Backing up content in /data
2022-05-10T00:56:28-0400 INFO using parent snapshot 2848ceb8
2022-05-10T00:56:28-0400 INFO
2022-05-10T00:56:28-0400 INFO Files:           0 new,  1329 changed,  3173 unmodified
2022-05-10T00:56:28-0400 INFO Dirs:            0 new,   146 changed,   576 unmodified
2022-05-10T00:56:28-0400 INFO Added to the repo: 22.716 MiB
2022-05-10T00:56:28-0400 INFO
2022-05-10T00:56:28-0400 INFO processed 4502 files, 16.455 GiB in 0:00
2022-05-10T00:56:28-0400 INFO snapshot 15cbc603 saved
2022-05-10T00:56:28-0400 INFO Command executed successfully rcon-cli save-on
2022-05-10T00:56:29-0400 ERROR Error querying the server, waiting 5m...
2022-05-10T01:01:29-0400 ERROR Error querying the server, waiting 5m...```
itzg commented 2 years ago

Can you set DEBUG to "true" and then provide that output?

AndrewTevebaugh commented 2 years ago

I'm not really sure what part of this is important so I apologize for the length.

+ : /data
+ : /backups
+ : world
+ : 2m
+ : 4h
+ : true
+ : 5m
+ : restic
+ : gzip
+ : '-3 --long=25 --single-thread'
+ : 7
+ : '--keep-hourly 1 --keep-daily 7 --keep-weekly 5 --keep-monthly 12 --keep-yearly 75'
+ : 25565
+ : localhost
+ : 25576
+ : ********
+ : 5
+ : 10s
+ : '*.jar,cache,logs'
+ : false
+ : mc_backups
+ : /config
+ : false
+ : America/New_York
+ export TZ
+ export RCON_HOST
+ export RCON_PORT
+ export RCON_PASSWORD
+ export XDG_CONFIG_HOME
+ '[' -n '' ']'
+ '[' '!' -d /data ']'
+ is_function restic
+ '[' 1 -ne 1 ']'
+ name=restic
++ type -t restic
+ '[' function == function ']'
+ readarray -td, excludes_patterns
++ printf %s '*.jar,cache,logs'
+ excludes=()
+ for pattern in "${excludes_patterns[@]}"
+ excludes+=(--exclude "${pattern}")
+ for pattern in "${excludes_patterns[@]}"
+ excludes+=(--exclude "${pattern}")
+ for pattern in "${excludes_patterns[@]}"
+ excludes+=(--exclude "${pattern}")
+ restic init
+ call_if_function_exists init
+ '[' 1 -lt 1 ']'
+ function_name=init
+ is_function init
+ '[' 1 -ne 1 ']'
+ name=init
++ type -t init
+ '[' function == function ']'
+ init
+ '[' -z password ']'
+ '[' -z /backups ']'
++ command restic snapshots
+ output=
+ log INFO 'Repository already initialized'
+ '[' 2 -lt 1 ']'
+ local level=INFO
+ shift
+ valid_levels=('INFO' 'WARN' 'ERROR' 'INTERNALERROR')
+ local valid_levels
+ is_elem_in_array INFO INFO WARN ERROR INTERNALERROR
+ '[' 5 -lt 2 ']'
+ local element=INFO
+ shift
+ local e
+ for e in "$@"
+ '[' INFO == INFO ']'
+ return 0
+ '[' 1 -ge 1 ']'
+ cat -
+ awk -v level=INFO '{ printf("%s %s %s\n", strftime("%FT%T%z"), level, $0); fflush(); }'
2022-05-10T18:41:04-0400 INFO Repository already initialized
+ '[' INFO == INTERNALERROR ']'
+ _check
++ command restic check
+ output='using temporary cache in /tmp/restic-check-cache-992440541
create exclusive lock for repository
load indexes
check all packs
check snapshots, trees and blobs
[0:00] 100.00%  3 / 3 snapshots

no errors were found'
+ read -ra restic_tags
+ restic_tags+=("${BACKUP_NAME}")
+ readonly restic_tags
+ restic_tags_arguments=()
+ local tag
+ for tag in "${restic_tags[@]}"
+ restic_tags_arguments+=(--tag "$tag")
+ for tag in "${restic_tags[@]}"
+ restic_tags_arguments+=(--tag "$tag")
+ readonly restic_tags_arguments
++ IFS=,
++ echo mc_backups,world
+ restic_tags_filter=mc_backups,world
+ readonly restic_tags_filter
+ is_one_shot
+ [[ FALSE = TRUE ]]
+ return 1
+ log INFO 'waiting initial delay of 2m...'
+ '[' 2 -lt 1 ']'
+ local level=INFO
+ shift
+ valid_levels=('INFO' 'WARN' 'ERROR' 'INTERNALERROR')
+ local valid_levels
+ is_elem_in_array INFO INFO WARN ERROR INTERNALERROR
+ '[' 5 -lt 2 ']'
+ local element=INFO
+ shift
+ local e
+ for e in "$@"
+ '[' INFO == INFO ']'
+ return 0
+ '[' 1 -ge 1 ']'
+ cat -
+ awk -v level=INFO '{ printf("%s %s %s\n", strftime("%FT%T%z"), level, $0); fflush(); }'
2022-05-10T18:41:05-0400 INFO waiting initial delay of 2m...
+ '[' INFO == INTERNALERROR ']'
+ sleep 2m
+ log INFO 'waiting for rcon readiness...'
+ '[' 2 -lt 1 ']'
+ local level=INFO
+ shift
+ valid_levels=('INFO' 'WARN' 'ERROR' 'INTERNALERROR')
+ local valid_levels
+ is_elem_in_array INFO INFO WARN ERROR INTERNALERROR
+ '[' 5 -lt 2 ']'
+ local element=INFO
+ shift
+ local e
+ for e in "$@"
+ '[' INFO == INFO ']'
+ return 0
+ '[' 1 -ge 1 ']'
+ cat -
+ awk -v level=INFO '{ printf("%s %s %s\n", strftime("%FT%T%z"), level, $0); fflush(); }'
2022-05-10T18:43:05-0400 INFO waiting for rcon readiness...
+ '[' INFO == INTERNALERROR ']'
+ retry 5 10s rcon-cli save-on
+ '[' 4 -lt 3 ']'
+ local retries=5
+ local interval=10s
+ readonly retries interval
+ shift 2
+ ((  retries < 0  ))
+ local retries_msg=5
+ local i=-1
+ ((  retries >= ++i  ))
++ timeout --signal=SIGINT --kill-after=30s 5m rcon-cli save-on
++ tr '\n' '\t'
+ output='Saving is already turned on   '
+ log INFO 'Command executed successfully rcon-cli save-on'
+ '[' 2 -lt 1 ']'
+ local level=INFO
+ shift
+ valid_levels=('INFO' 'WARN' 'ERROR' 'INTERNALERROR')
+ local valid_levels
+ is_elem_in_array INFO INFO WARN ERROR INTERNALERROR
+ '[' 5 -lt 2 ']'
+ local element=INFO
+ shift
+ local e
+ for e in "$@"
+ '[' INFO == INFO ']'
+ return 0
+ '[' 1 -ge 1 ']'
+ cat -
+ awk -v level=INFO '{ printf("%s %s %s\n", strftime("%FT%T%z"), level, $0); fflush(); }'
2022-05-10T18:43:05-0400 INFO Command executed successfully rcon-cli save-on
+ '[' INFO == INTERNALERROR ']'
+ return 0
+ true
+ retry 5 10s rcon-cli save-off
+ '[' 4 -lt 3 ']'
+ local retries=5
+ local interval=10s
+ readonly retries interval
+ shift 2
+ ((  retries < 0  ))
+ local retries_msg=5
+ local i=-1
+ ((  retries >= ++i  ))
++ timeout --signal=SIGINT --kill-after=30s 5m rcon-cli save-off
++ tr '\n' '\t'
+ output='Turned off world auto-saving  '
+ log INFO 'Command executed successfully rcon-cli save-off'
+ '[' 2 -lt 1 ']'
+ local level=INFO
+ shift
+ valid_levels=('INFO' 'WARN' 'ERROR' 'INTERNALERROR')
+ local valid_levels
+ is_elem_in_array INFO INFO WARN ERROR INTERNALERROR
+ '[' 5 -lt 2 ']'
+ local element=INFO
+ shift
+ local e
+ for e in "$@"
+ '[' INFO == INFO ']'
+ return 0
+ '[' 1 -ge 1 ']'
+ cat -
+ awk -v level=INFO '{ printf("%s %s %s\n", strftime("%FT%T%z"), level, $0); fflush(); }'
2022-05-10T18:43:05-0400 INFO Command executed successfully rcon-cli save-off
+ '[' INFO == INTERNALERROR ']'
+ return 0
+ trap 'retry 5 5s rcon-cli save-on' EXIT
+ retry 5 10s rcon-cli save-all flush
+ '[' 5 -lt 3 ']'
+ local retries=5
+ local interval=10s
+ readonly retries interval
+ shift 2
+ ((  retries < 0  ))
+ local retries_msg=5
+ local i=-1
+ ((  retries >= ++i  ))
++ timeout --signal=SIGINT --kill-after=30s 5m rcon-cli save-all flush
++ tr '\n' '\t'
+ output='Saving...Flushing all saves...Flushing completedSaved the world   '
+ log INFO 'Command executed successfully rcon-cli save-all flush'
+ '[' 2 -lt 1 ']'
+ local level=INFO
+ shift
+ valid_levels=('INFO' 'WARN' 'ERROR' 'INTERNALERROR')
+ local valid_levels
+ is_elem_in_array INFO INFO WARN ERROR INTERNALERROR
+ '[' 5 -lt 2 ']'
+ local element=INFO
+ shift
+ local e
+ for e in "$@"
+ '[' INFO == INFO ']'
+ return 0
+ '[' 1 -ge 1 ']'
+ cat -
+ awk -v level=INFO '{ printf("%s %s %s\n", strftime("%FT%T%z"), level, $0); fflush(); }'
2022-05-10T18:43:05-0400 INFO Command executed successfully rcon-cli save-all flush
+ '[' INFO == INTERNALERROR ']'
+ return 0
+ retry 5 10s sync
+ '[' 3 -lt 3 ']'
+ local retries=5
+ local interval=10s
+ readonly retries interval
+ shift 2
+ ((  retries < 0  ))
+ local retries_msg=5
+ local i=-1
+ ((  retries >= ++i  ))
++ timeout --signal=SIGINT --kill-after=30s 5m sync
++ tr '\n' '\t'
+ output=
+ log INFO 'Command executed successfully sync'
+ '[' 2 -lt 1 ']'
+ local level=INFO
+ shift
+ valid_levels=('INFO' 'WARN' 'ERROR' 'INTERNALERROR')
+ local valid_levels
+ is_elem_in_array INFO INFO WARN ERROR INTERNALERROR
+ '[' 5 -lt 2 ']'
+ local element=INFO
+ shift
+ local e
+ for e in "$@"
+ '[' INFO == INFO ']'
+ return 0
+ '[' 1 -ge 1 ']'
+ cat -
+ awk -v level=INFO '{ printf("%s %s %s\n", strftime("%FT%T%z"), level, $0); fflush(); }'
2022-05-10T18:43:05-0400 INFO Command executed successfully sync
+ '[' INFO == INTERNALERROR ']'
+ return 0
+ restic backup
+ call_if_function_exists backup
+ '[' 1 -lt 1 ']'
+ function_name=backup
+ is_function backup
+ '[' 1 -ne 1 ']'
+ name=backup
++ type -t backup
+ '[' function == function ']'
+ backup
+ log INFO 'Backing up content in /data'
+ '[' 2 -lt 1 ']'
+ local level=INFO
+ shift
+ valid_levels=('INFO' 'WARN' 'ERROR' 'INTERNALERROR')
+ local valid_levels
+ is_elem_in_array INFO INFO WARN ERROR INTERNALERROR
+ '[' 5 -lt 2 ']'
+ local element=INFO
+ shift
+ local e
+ for e in "$@"
+ '[' INFO == INFO ']'
+ return 0
+ '[' 1 -ge 1 ']'
+ cat -
+ awk -v level=INFO '{ printf("%s %s %s\n", strftime("%FT%T%z"), level, $0); fflush(); }'
2022-05-10T18:43:05-0400 INFO Backing up content in /data
+ '[' INFO == INTERNALERROR ']'
+ command restic backup --tag mc_backups --tag world --exclude '*.jar' --exclude cache --exclude logs /data
+ log INFO
+ '[' 1 -lt 1 ']'
+ local level=INFO
+ shift
+ valid_levels=('INFO' 'WARN' 'ERROR' 'INTERNALERROR')
+ local valid_levels
+ is_elem_in_array INFO INFO WARN ERROR INTERNALERROR
+ '[' 5 -lt 2 ']'
+ local element=INFO
+ shift
+ local e
+ for e in "$@"
+ '[' INFO == INFO ']'
+ return 0
+ '[' 0 -ge 1 ']'
+ cat -
+ awk -v level=INFO '{ printf("%s %s %s\n", strftime("%FT%T%z"), level, $0); fflush(); }'
2022-05-10T18:43:06-0400 INFO using parent snapshot 15cbc603
2022-05-10T18:43:06-0400 INFO
2022-05-10T18:43:06-0400 INFO Files:           0 new,    61 changed,  4441 unmodified
2022-05-10T18:43:06-0400 INFO Dirs:            0 new,    19 changed,   703 unmodified
2022-05-10T18:43:06-0400 INFO Added to the repo: 12.885 MiB
2022-05-10T18:43:06-0400 INFO
2022-05-10T18:43:06-0400 INFO processed 4502 files, 16.455 GiB in 0:00
2022-05-10T18:43:06-0400 INFO snapshot 629d2338 saved
+ '[' INFO == INTERNALERROR ']'
+ retry 5 10s rcon-cli save-on
+ '[' 4 -lt 3 ']'
+ local retries=5
+ local interval=10s
+ readonly retries interval
+ shift 2
+ ((  retries < 0  ))
+ local retries_msg=5
+ local i=-1
+ ((  retries >= ++i  ))
++ timeout --signal=SIGINT --kill-after=30s 5m rcon-cli save-on
++ tr '\n' '\t'
+ output='Turned on world auto-saving   '
+ log INFO 'Command executed successfully rcon-cli save-on'
+ '[' 2 -lt 1 ']'
+ local level=INFO
+ shift
+ valid_levels=('INFO' 'WARN' 'ERROR' 'INTERNALERROR')
+ local valid_levels
+ is_elem_in_array INFO INFO WARN ERROR INTERNALERROR
+ '[' 5 -lt 2 ']'
+ local element=INFO
+ shift
+ local e
+ for e in "$@"
+ '[' INFO == INFO ']'
+ return 0
+ '[' 1 -ge 1 ']'
+ cat -
+ awk -v level=INFO '{ printf("%s %s %s\n", strftime("%FT%T%z"), level, $0); fflush(); }'
2022-05-10T18:43:06-0400 INFO Command executed successfully rcon-cli save-on
+ '[' INFO == INTERNALERROR ']'
+ return 0
+ trap EXIT
+ ((  PRUNE_BACKUPS_DAYS > 0  ))
+ restic prune
+ call_if_function_exists prune
+ '[' 1 -lt 1 ']'
+ function_name=prune
+ is_function prune
+ '[' 1 -ne 1 ']'
+ name=prune
++ type -t prune
+ '[' function == function ']'
+ prune
+ _delete_old_backups --dry-run
+ + command grep restic '^remove [[:digit:]]* snapshots:$'forget
--tag mc_backups,world --keep-hourly 1 --keep-daily 7 --keep-weekly 5 --keep-monthly 12 --keep-yearly 75 --dry-run
+ log INFO 'Pruning snapshots using --keep-hourly 1 --keep-daily 7 --keep-weekly 5 --keep-monthly 12 --keep-yearly 75'
+ '[' 2 -lt 1 ']'
+ local level=INFO
+ shift
+ valid_levels=('INFO' 'WARN' 'ERROR' 'INTERNALERROR')
+ local valid_levels
+ is_elem_in_array INFO INFO WARN ERROR INTERNALERROR
+ '[' 5 -lt 2 ']'
+ local element=INFO
+ shift
+ local e
+ for e in "$@"
+ '[' INFO == INFO ']'
+ return 0
+ '[' 1 -ge 1 ']'
+ cat -
+ awk -v level=INFO '{ printf("%s %s %s\n", strftime("%FT%T%z"), level, $0); fflush(); }'
2022-05-10T18:43:07-0400 INFO Pruning snapshots using --keep-hourly 1 --keep-daily 7 --keep-weekly 5 --keep-monthly 12 --keep-yearly 75
+ '[' INFO == INTERNALERROR ']'
+ _delete_old_backups --prune
+ log INFO
+ command restic forget --tag mc_backups,world --keep-hourly 1 --keep-daily 7 --keep-weekly 5 --keep-monthly 12 --keep-yearly 75 --prune
+ '[' 1 -lt 1 ']'
+ local level=INFO
+ shift
+ valid_levels=('INFO' 'WARN' 'ERROR' 'INTERNALERROR')
+ local valid_levels
+ is_elem_in_array INFO INFO WARN ERROR INTERNALERROR
+ '[' 5 -lt 2 ']'
+ local element=INFO
+ shift
+ local e
+ for e in "$@"
+ '[' INFO == INFO ']'
+ return 0
+ '[' 0 -ge 1 ']'
+ cat -
+ awk -v level=INFO '{ printf("%s %s %s\n", strftime("%FT%T%z"), level, $0); fflush(); }'
2022-05-10T18:43:08-0400 INFO Applying Policy: keep 1 hourly, 7 daily, 5 weekly, 12 monthly, 75 yearly snapshots
2022-05-10T18:43:08-0400 INFO keep 3 snapshots:
2022-05-10T18:43:08-0400 INFO ID        Time                 Host          Tags              Reasons           Paths
2022-05-10T18:43:08-0400 INFO --------------------------------------------------------------------------------------
2022-05-10T18:43:08-0400 INFO 5e564cf3  2022-01-30 22:53:28  32db350235ab  mc_backups,world  daily snapshot    /data
2022-05-10T18:43:08-0400 INFO                                                                weekly snapshot
2022-05-10T18:43:08-0400 INFO                                                                monthly snapshot
2022-05-10T18:43:08-0400 INFO 2848ceb8  2022-03-15 00:17:51  32db350235ab  mc_backups,world  daily snapshot    /data
2022-05-10T18:43:08-0400 INFO                                                                weekly snapshot
2022-05-10T18:43:08-0400 INFO                                                                monthly snapshot
2022-05-10T18:43:08-0400 INFO 629d2338  2022-05-10 18:43:05  32db350235ab  mc_backups,world  hourly snapshot   /data
2022-05-10T18:43:08-0400 INFO                                                                daily snapshot
2022-05-10T18:43:08-0400 INFO                                                                weekly snapshot
2022-05-10T18:43:08-0400 INFO                                                                monthly snapshot
2022-05-10T18:43:08-0400 INFO                                                                yearly snapshot
2022-05-10T18:43:08-0400 INFO --------------------------------------------------------------------------------------
2022-05-10T18:43:08-0400 INFO 3 snapshots
2022-05-10T18:43:08-0400 INFO
2022-05-10T18:43:08-0400 INFO remove 1 snapshots:
2022-05-10T18:43:08-0400 INFO ID        Time                 Host          Tags              Paths
2022-05-10T18:43:08-0400 INFO --------------------------------------------------------------------
2022-05-10T18:43:08-0400 INFO 15cbc603  2022-05-10 00:56:27  32db350235ab  mc_backups,world  /data
2022-05-10T18:43:08-0400 INFO --------------------------------------------------------------------
2022-05-10T18:43:08-0400 INFO 1 snapshots
2022-05-10T18:43:08-0400 INFO
2022-05-10T18:43:08-0400 INFO [0:00] 100.00%  1 / 1 files deleted
2022-05-10T18:43:08-0400 INFO
2022-05-10T18:43:08-0400 INFO 1 snapshots have been removed, running prune
2022-05-10T18:43:08-0400 INFO loading indexes...
2022-05-10T18:43:08-0400 INFO loading all snapshots...
2022-05-10T18:43:08-0400 INFO finding data that is still in use for 3 snapshots
2022-05-10T18:43:08-0400 INFO [0:00] 100.00%  3 / 3 snapshots
2022-05-10T18:43:08-0400 INFO
2022-05-10T18:43:08-0400 INFO searching used packs...
2022-05-10T18:43:08-0400 INFO collecting packs for deletion and repacking
2022-05-10T18:43:08-0400 INFO [0:00] 100.00%  2619 / 2619 packs processed
2022-05-10T18:43:08-0400 INFO
2022-05-10T18:43:08-0400 INFO
2022-05-10T18:43:08-0400 INFO to repack:          146 blobs / 862.878 KiB
2022-05-10T18:43:08-0400 INFO this removes         20 blobs / 251.843 KiB
2022-05-10T18:43:08-0400 INFO to delete:            8 blobs / 4.387 MiB
2022-05-10T18:43:08-0400 INFO total prune:         28 blobs / 4.633 MiB
2022-05-10T18:43:08-0400 INFO remaining:        15991 blobs / 12.517 GiB
2022-05-10T18:43:08-0400 INFO unused size after prune: 8.257 MiB (0.06% of remaining size)
2022-05-10T18:43:08-0400 INFO
2022-05-10T18:43:08-0400 INFO repacking packs
2022-05-10T18:43:08-0400 INFO [0:00] 100.00%  2 / 2 packs repacked
2022-05-10T18:43:08-0400 INFO
2022-05-10T18:43:08-0400 INFO rebuilding index
2022-05-10T18:43:08-0400 INFO [0:00] 100.00%  2618 / 2618 packs processed
2022-05-10T18:43:08-0400 INFO
2022-05-10T18:43:08-0400 INFO deleting obsolete index files
2022-05-10T18:43:08-0400 INFO [0:00] 100.00%  4 / 4 files deleted
2022-05-10T18:43:08-0400 INFO
2022-05-10T18:43:08-0400 INFO removing 3 old packs
2022-05-10T18:43:08-0400 INFO [0:00] 100.00%  3 / 3 files deleted
2022-05-10T18:43:08-0400 INFO
2022-05-10T18:43:08-0400 INFO done
+ '[' INFO == INTERNALERROR ']'
+ _check
+ log INFO
+ '[' 1 -lt 1 ']'
+ local level=INFO
+ shift
+ valid_levels=('INFO' 'WARN' 'ERROR' 'INTERNALERROR')
++ command restic check
+ local valid_levels
+ is_elem_in_array INFO INFO WARN ERROR INTERNALERROR
+ '[' 5 -lt 2 ']'
+ local element=INFO
+ shift
+ local e
+ for e in "$@"
+ '[' INFO == INFO ']'
+ return 0
+ '[' 0 -ge 1 ']'
+ cat -
+ awk -v level=INFO '{ printf("%s %s %s\n", strftime("%FT%T%z"), level, $0); fflush(); }'
+ output='using temporary cache in /tmp/restic-check-cache-479990148
create exclusive lock for repository
load indexes
check all packs
check snapshots, trees and blobs
[0:00] 100.00%  3 / 3 snapshots

no errors were found'
+ '[' INFO == INTERNALERROR ']'
+ is_one_shot
+ [[ FALSE = TRUE ]]
+ return 1
+ [[ TRUE = TRUE ]]
+ true
++ mc-monitor status --host localhost --port 25565 --show-player-count
+ PLAYERS_ONLINE='failed to ping localhost:25565 : could not connect to Minecraft server: dial tcp 127.0.0.1:25565: connect: connection refused'
+ log ERROR 'Error querying the server, waiting 5m...'
+ '[' 2 -lt 1 ']'
+ local level=ERROR
+ shift
+ valid_levels=('INFO' 'WARN' 'ERROR' 'INTERNALERROR')
+ local valid_levels
+ is_elem_in_array ERROR INFO WARN ERROR INTERNALERROR
+ '[' 5 -lt 2 ']'
+ local element=ERROR
+ shift
+ local e
+ for e in "$@"
+ '[' ERROR == INFO ']'
+ for e in "$@"
+ '[' ERROR == WARN ']'
+ for e in "$@"
+ '[' ERROR == ERROR ']'
+ return 0
+ '[' 1 -ge 1 ']'
+ cat -
+ awk -v level=ERROR '{ printf("%s %s %s\n", strftime("%FT%T%z"), level, $0); fflush(); }'
2022-05-10T18:43:09-0400 ERROR Error querying the server, waiting 5m...
+ '[' ERROR == INTERNALERROR ']'
+ sleep 5m
itzg commented 2 years ago

Thanks, yes, expected a lot of output. FYI here's the bit I was looking for

mc-monitor status --host localhost --port 25565 --show-player-count
+ PLAYERS_ONLINE='failed to ping localhost:25565 : could not connect to Minecraft server: dial tcp 127.0.0.1:25565: connect: connection refused'

Can you double check the Minecraft server itself isn't outputting errors or anything around the time of that?

AndrewTevebaugh commented 2 years ago

No errors from the server itself, however I did notice that the blurb you pointed out is trying to access port 25565. This is the backup for my 2nd minecraft server I am running. My first server uses the port 25565 and my second server uses port 25566. I tried to set the RCON port for the second server to 25576 instead of the default 25575 (from what I understand). However I just checked and the port of the docker container for the second server is 25565/tcp, 25575/tcp, 0.0.0.0:25566->25566/tcp, :::25566->25566/tcp For the first server it is this: 0.0.0.0:24454->24454/udp, :::24454->24454/udp, 0.0.0.0:25565->25565/tcp, :::25565->25565/tcp, 25575/tcp Note: the extra port on the first server is for a voice chat plugin

itzg commented 2 years ago

Can you provide the container configs for that backup container and it's corresponding server? Going over loopback, the container port mappings won't be utilized, so was wanting to cross check the internal ports configured.

AndrewTevebaugh commented 2 years ago

This is the contents of my docker-compose file:


services:
  ProjectOzone:
    hostname: ProjectOzone
    image: itzg/minecraft-server:${IMAGE_TAG:-java8}
    ports:
      - 25566:25566
    environment:
      MEMORY: 6G
      EULA: "TRUE"
      TYPE: FORGE
      VERSION: 1.12.2
      MOTD: Project Ozone
      ENABLE_RCON: "true"
      RCON_PORT: 25576
      RCON_PASSWORD: "password"
      SERVER_PORT: 25566
      TZ: "America/New_York"
    tty: true
    stdin_open: true
    restart: unless-stopped
    volumes:
      - ./ProjectOzone:/data
  ProjectOzoneBackups:
    image: itzg/mc-backup
    environment:
      RCON_PORT: 25576
      RCON_PASSWORD: "password"
      BACKUP_INTERVAL: "4h"
      TZ: "America/New_York"
      PAUSE_IF_NO_PLAYERS: true
      BACKUP_METHOD: restic
      RESTIC_PASSWORD: password
      RESTIC_REPOSITORY: /backups
      PRUNE_RESTIC_RETENTION: "--keep-hourly 1 --keep-daily 7 --keep-weekly 5 --keep-monthly 12 --keep-yearly 75"
      DEBUG: TRUE
    volumes:
      - ./ProjectOzone:/data:ro
      - ./ProjectOzone-Backups:/backups
    network_mode: "service:ProjectOzone"
    restart: unless-stopped
itzg commented 2 years ago

Ah, you're missing SERVER_PORT on the backup service.

Better yet, I really recommend you don't change the SERVER_PORT and RCON_PORT values since the port mappings can adjust for host side port conflicts.

AndrewTevebaugh commented 2 years ago

so what would that look like? Would I just remove all of the SERVER_PORT and RCON_PORT from both containers and change the port mapping to 25566:25565?

EDIT: I tried that and it didn't work.

itzg commented 2 years ago

Can you clarify in what way it didn't work?

Instead, you can go back to your previous but add the missing SERVER_PORT to your backup service.

AndrewTevebaugh commented 2 years ago

I tried doing what you recommended by removing the SERVER_PORT and RCON_PORT values and adjust the port mappings. Like So:

services:
  ProjectOzone:
    hostname: ProjectOzone
    image: itzg/minecraft-server:${IMAGE_TAG:-java8}
    ports:
      - 25566:25565
    environment:
      MEMORY: 6G
      EULA: "TRUE"
      TYPE: FORGE
      VERSION: 1.12.2
      MOTD: Project Ozone
      ENABLE_RCON: "true"
      RCON_PASSWORD: "password"
      TZ: "America/New_York"
    tty: true
    stdin_open: true
    restart: unless-stopped
    volumes:
      - ./ProjectOzone:/data
  ProjectOzoneBackups:
    image: itzg/mc-backup
    environment:
      RCON_PASSWORD: "password"
      BACKUP_INTERVAL: "4h"
      TZ: "America/New_York"
      PAUSE_IF_NO_PLAYERS: true
      BACKUP_METHOD: restic
      RESTIC_PASSWORD: password
      RESTIC_REPOSITORY: /backups
      PRUNE_RESTIC_RETENTION: "--keep-hourly 1 --keep-daily 7 --keep-weekly 5 --keep-monthly 12 --keep-yearly 75"
      DEBUG: TRUE
    volumes:
      - ./ProjectOzone:/data:ro
      - ./ProjectOzone-Backups:/backups
    network_mode: "service:ProjectOzone"
    restart: unless-stopped

I was able to get everything functioning by adding SERVER_PORT to the backup service, however I would like to understand why the other attempt to fix the issue did not work.

itzg commented 2 years ago

I just realized why the first suggestion didn't work. By default it won't update the server.properties file. Adding OVERRIDE_SERVER_PROPERTIES: "true" will get it working I think.

EndlessUndo commented 2 years ago

I just realized why the first suggestion didn't work. By default it won't update the server.properties file. Adding OVERRIDE_SERVER_PROPERTIES: "true" will get it working I think.

Thank you itzg! This solved a similar issue for me.