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

Could not open file "postmaster.pid": Permission denied; continuing anyway #107

Open
Hisayoo opened this issue Nov 27, 2024 · 5 comments
Open

Comments

@Hisayoo
Copy link

Hisayoo commented Nov 27, 2024

Everytime guacmole starts when the server boots or after some time of not using guacamole I can't access the web gui. All I get is ERROR please contact an administrator. These are the logs but I looked inside the container and all the permissions belong to root. I am also running the compose as root.
postgres_guacamole_compose logs:

2024-11-27 00:16:43.781 UTC [1] LOG:  received fast shutdown request
2024-11-27 00:16:43.781 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied
2024-11-27 00:16:43.781 UTC [1] LOG:  aborting any active transactions
2024-11-27 00:16:43.807 UTC [1] LOG:  background worker "logical replication launcher" (PID 27) exited with exit code 1
2024-11-27 00:16:43.814 UTC [22] LOG:  shutting down
2024-11-27 00:16:43.815 UTC [22] PANIC:  could not open file "/var/lib/postgresql/data/guacamole/global/pg_control": Permission denied
2024-11-27 00:16:43.825 UTC [1] LOG:  checkpointer process (PID 22) was terminated by signal 6: Aborted
2024-11-27 00:16:43.825 UTC [1] LOG:  terminating any other active server processes
2024-11-27 00:16:43.825 UTC [1] LOG:  abnormal database system shutdown
2024-11-27 00:16:43.834 UTC [1] LOG:  database system is shut down
PostgreSQL Database directory appears to contain a database; Skipping initialization
2024-11-27 05:32:55.702 UTC [1] LOG:  starting PostgreSQL 15.2 on x86_64-pc-linux-musl, compiled by gcc (Alpine 12.2.1_git20220924-r4) 12.2.1 20220924, 64-bit
2024-11-27 05:32:55.702 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2024-11-27 05:32:55.702 UTC [1] LOG:  listening on IPv6 address "::", port 5432
2024-11-27 05:32:55.718 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2024-11-27 05:32:55.739 UTC [25] LOG:  database system was interrupted; last known up at 2024-11-26 05:32:57 UTC
2024-11-27 05:32:59.019 UTC [25] LOG:  database system was not properly shut down; automatic recovery in progress
2024-11-27 05:32:59.032 UTC [25] LOG:  redo starts at 0/1AF49E8
2024-11-27 05:32:59.032 UTC [25] LOG:  invalid record length at 0/1AF4A20: wanted 24, got 0
2024-11-27 05:32:59.032 UTC [25] LOG:  redo done at 0/1AF49E8 system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s
2024-11-27 05:32:59.060 UTC [23] LOG:  checkpoint starting: end-of-recovery immediate wait
2024-11-27 05:32:59.135 UTC [23] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.022 s, sync=0.008 s, total=0.081 s; sync files=2, longest=0.005 s, average=0.004 s; distance=0 kB, estimate=0 kB
2024-11-27 05:32:59.159 UTC [1] LOG:  database system is ready to accept connections
2024-11-27 05:33:59.227 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 05:34:59.241 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 05:35:59.301 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 05:36:59.351 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 05:37:59.411 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 05:38:59.443 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 05:39:59.503 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 05:40:59.563 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 05:41:59.600 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 05:42:59.660 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 05:43:59.719 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 05:44:59.779 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 05:45:59.816 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 05:46:59.851 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 05:47:59.896 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 05:48:59.949 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 05:50:00.008 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 05:51:00.067 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 05:52:00.127 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 05:53:00.184 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 05:54:00.243 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 05:55:00.303 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 05:56:00.363 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 05:57:00.423 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 05:58:00.483 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 05:59:00.543 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 06:00:00.603 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 06:01:00.663 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 06:02:00.723 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 06:03:00.779 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 06:04:00.839 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 06:05:00.899 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 06:06:00.959 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 06:07:01.017 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 06:08:01.075 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 06:09:01.135 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 06:10:01.195 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 06:11:01.255 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 06:12:01.315 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 06:13:01.375 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 06:14:01.396 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 06:15:01.455 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 06:16:01.515 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 06:17:01.575 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 06:18:01.631 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 06:19:01.654 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 06:20:01.714 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 06:21:01.771 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied; continuing anyway
2024-11-27 06:21:07.197 UTC [1] LOG:  received fast shutdown request
2024-11-27 06:21:07.197 UTC [1] LOG:  could not open file "postmaster.pid": Permission denied
2024-11-27 06:21:07.197 UTC [1] LOG:  aborting any active transactions
2024-11-27 06:21:07.199 UTC [1] LOG:  background worker "logical replication launcher" (PID 28) exited with exit code 1
2024-11-27 06:21:07.199 UTC [23] LOG:  shutting down
2024-11-27 06:21:07.199 UTC [23] PANIC:  could not open file "/var/lib/postgresql/data/guacamole/global/pg_control": Permission denied
2024-11-27 06:21:07.200 UTC [1] LOG:  checkpointer process (PID 23) was terminated by signal 6: Aborted
2024-11-27 06:21:07.200 UTC [1] LOG:  terminating any other active server processes
2024-11-27 06:21:07.200 UTC [1] LOG:  abnormal database system shutdown
2024-11-27 06:21:07.204 UTC [1] LOG:  database system is shut down
PostgreSQL Database directory appears to contain a database; Skipping initialization
2024-11-27 06:21:07.716 UTC [1] LOG:  starting PostgreSQL 15.2 on x86_64-pc-linux-musl, compiled by gcc (Alpine 12.2.1_git20220924-r4) 12.2.1 20220924, 64-bit
2024-11-27 06:21:07.716 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2024-11-27 06:21:07.716 UTC [1] LOG:  listening on IPv6 address "::", port 5432
2024-11-27 06:21:07.718 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2024-11-27 06:21:07.722 UTC [25] LOG:  database system was interrupted; last known up at 2024-11-27 05:32:59 UTC
2024-11-27 06:21:07.913 UTC [25] LOG:  database system was not properly shut down; automatic recovery in progress
2024-11-27 06:21:07.915 UTC [25] LOG:  redo starts at 0/1AF4A98
2024-11-27 06:21:07.915 UTC [25] LOG:  invalid record length at 0/1AF4AD0: wanted 24, got 0
2024-11-27 06:21:07.915 UTC [25] LOG:  redo done at 0/1AF4A98 system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s
2024-11-27 06:21:07.918 UTC [23] LOG:  checkpoint starting: end-of-recovery immediate wait
2024-11-27 06:21:07.928 UTC [23] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.004 s, sync=0.001 s, total=0.012 s; sync files=2, longest=0.001 s, average=0.001 s; distance=0 kB, estimate=0 kB
2024-11-27 06:21:07.932 UTC [1] LOG:  database system is ready to accept connections
2024-11-27 07:01:08.699 UTC [23] LOG:  checkpoint starting: time
2024-11-27 07:01:10.513 UTC [23] LOG:  checkpoint complete: wrote 19 buffers (0.1%); 0 WAL file(s) added, 0 removed, 0 recycled; write=1.805 s, sync=0.004 s, total=1.815 s; sync files=19, longest=0.001 s, average=0.001 s; distance=30 kB, estimate=30 kB

guacd_compose logs:

guacd[1]: INFO:	Guacamole proxy daemon (guacd) version 1.5.5 started
guacd[1]: INFO:	Listening on host 0.0.0.0, port 4822
guacd[1]: INFO:	Guacamole proxy daemon (guacd) version 1.5.5 started
guacd[1]: INFO:	Listening on host 0.0.0.0, port 4822
guacd[1]: INFO:	Creating new client for protocol "rdp"
guacd[1]: INFO:	Connection ID is "$cdb3da82-76bd-4f41-9059-c4dcca91d6d9"
guacd[8]: INFO:	No security mode specified. Defaulting to security mode negotiation with server.
guacd[8]: INFO:	Resize method: none
guacd[8]: INFO:	No clipboard line-ending normalization specified. Defaulting to preserving the format of all line endings.
guacd[8]: INFO:	User "@93cc976a-0c56-4b4f-9bcf-916194021e3b" joined connection "$cdb3da82-76bd-4f41-9059-c4dcca91d6d9" (1 users now present)
guacd[8]: INFO:	Loading keymap "base"
guacd[8]: INFO:	Loading keymap "en-us-qwerty"
guacd[8]: INFO:	Connected to RDPDR 1.13 as client 0x0003
guacd[8]: INFO:	Connected to RDPDR 1.13 as client 0x0002
guacd[8]: INFO:	RDPDR user logged on

guacamole_compose logs:

27-Nov-2024 08:35:39.109 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources
27-Nov-2024 08:35:39.109 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dorg.apache.catalina.security.SecurityListener.UMASK=0027
27-Nov-2024 08:35:39.109 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dignore.endorsed.dirs=
27-Nov-2024 08:35:39.109 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.base=/home/guacamole/tomcat
27-Nov-2024 08:35:39.109 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=/usr/local/tomcat
27-Nov-2024 08:35:39.110 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=/home/guacamole/tomcat/temp
27-Nov-2024 08:35:39.110 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent Loaded Apache Tomcat Native library [1.2.39] using APR version [1.7.0].
27-Nov-2024 08:35:39.110 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true], UDS [{4}].
27-Nov-2024 08:35:39.110 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR/OpenSSL configuration: useAprConnector [false], useOpenSSL [true]
27-Nov-2024 08:35:39.114 INFO [main] org.apache.catalina.core.AprLifecycleListener.initializeSSL OpenSSL successfully initialized [OpenSSL 3.0.2 15 Mar 2022]
27-Nov-2024 08:35:39.197 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8080"]
27-Nov-2024 08:35:39.214 INFO [main] org.apache.catalina.startup.Catalina.load Initialization processed in 519 ms
27-Nov-2024 08:35:39.238 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina]
27-Nov-2024 08:35:39.238 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet engine: [Apache Tomcat/8.5.100]
27-Nov-2024 08:35:39.250 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployWAR Deploying web application archive [/home/guacamole/tomcat/webapps/guacamole.war]
27-Nov-2024 08:35:40.782 INFO [localhost-startStop-1] org.apache.jasper.servlet.TldScanner.scanJars At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
08:35:41.345 [localhost-startStop-1] INFO  o.a.g.environment.LocalEnvironment - GUACAMOLE_HOME is "/home/guacamole/.guacamole".
08:35:41.452 [localhost-startStop-1] INFO  o.a.g.GuacamoleServletContextListener - Read configuration parameters from "/home/guacamole/.guacamole/guacamole.properties".
08:35:41.455 [localhost-startStop-1] INFO  o.a.g.rest.auth.HashTokenSessionMap - Sessions will expire after 60 minutes of inactivity.
08:35:42.658 [localhost-startStop-1] INFO  o.a.g.extension.ExtensionModule - Extension "PostgreSQL Authentication" (postgresql) loaded.
08:35:42.769 [localhost-startStop-1] INFO  o.a.g.t.w.WebSocketTunnelModule - Loading JSR-356 WebSocket support...
27-Nov-2024 08:35:43.604 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployWAR Deployment of web application archive [/home/guacamole/tomcat/webapps/guacamole.war] has finished in [4,353] ms
27-Nov-2024 08:35:43.606 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
27-Nov-2024 08:35:43.617 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 4402 ms
11:52:17.327 [http-nio-8080-exec-2] WARN  o.a.g.e.AuthenticationProviderFacade - The "postgresql" authentication provider has encountered an internal error which will halt the authentication process. If this is unexpected or you are the developer of this authentication provider, you may wish to enable debug-level logging. If this is expected and you wish to ignore such failures in the future, please set "skip-if-unavailable: postgresql" within your guacamole.properties.
11:52:17.330 [http-nio-8080-exec-2] ERROR o.a.g.rest.RESTExceptionMapper - Unexpected internal error: 
### Error querying database.  Cause: org.postgresql.util.PSQLException: FATAL: could not open file "global/pg_filenode.map": Permission denied
### The error may exist in org/apache/guacamole/auth/jdbc/user/UserMapper.xml
### The error may involve org.apache.guacamole.auth.jdbc.user.UserMapper.selectOne
### The error occurred while executing a query
### Cause: org.postgresql.util.PSQLException: FATAL: could not open file "global/pg_filenode.map": Permission denied
11:52:19.420 [http-nio-8080-exec-9] WARN  o.a.g.e.AuthenticationProviderFacade - The "postgresql" authentication provider has encountered an internal error which will halt the authentication process. If this is unexpected or you are the developer of this authentication provider, you may wish to enable debug-level logging. If this is expected and you wish to ignore such failures in the future, please set "skip-if-unavailable: postgresql" within your guacamole.properties.
11:52:19.420 [http-nio-8080-exec-9] ERROR o.a.g.rest.RESTExceptionMapper - Unexpected internal error: 
### Error querying database.  Cause: org.postgresql.util.PSQLException: FATAL: could not open file "global/pg_filenode.map": Permission denied
### The error may exist in org/apache/guacamole/auth/jdbc/user/UserMapper.xml
### The error may involve org.apache.guacamole.auth.jdbc.user.UserMapper.selectOne
### The error occurred while executing a query
### Cause: org.postgresql.util.PSQLException: FATAL: could not open file "global/pg_filenode.map": Permission denied
11:52:23.044 [http-nio-8080-exec-4] WARN  o.a.g.e.AuthenticationProviderFacade - The "postgresql" authentication provider has encountered an internal error which will halt the authentication process. If this is unexpected or you are the developer of this authentication provider, you may wish to enable debug-level logging. If this is expected and you wish to ignore such failures in the future, please set "skip-if-unavailable: postgresql" within your guacamole.properties.
11:52:23.044 [http-nio-8080-exec-4] ERROR o.a.g.rest.RESTExceptionMapper - Unexpected internal error: 
### Error querying database.  Cause: org.postgresql.util.PSQLException: FATAL: could not open file "global/pg_filenode.map": Permission denied
### The error may exist in org/apache/guacamole/auth/jdbc/user/UserMapper.xml
### The error may involve org.apache.guacamole.auth.jdbc.user.UserMapper.selectOne
### The error occurred while executing a query
### Cause: org.postgresql.util.PSQLException: FATAL: could not open file "global/pg_filenode.map": Permission denied
11:52:23.830 [http-nio-8080-exec-10] WARN  o.a.g.e.AuthenticationProviderFacade - The "postgresql" authentication provider has encountered an internal error which will halt the authentication process. If this is unexpected or you are the developer of this authentication provider, you may wish to enable debug-level logging. If this is expected and you wish to ignore such failures in the future, please set "skip-if-unavailable: postgresql" within your guacamole.properties.
11:52:23.830 [http-nio-8080-exec-10] ERROR o.a.g.rest.RESTExceptionMapper - Unexpected internal error: 
### Error querying database.  Cause: org.postgresql.util.PSQLException: FATAL: could not open file "global/pg_filenode.map": Permission denied
### The error may exist in org/apache/guacamole/auth/jdbc/user/UserMapper.xml
### The error may involve org.apache.guacamole.auth.jdbc.user.UserMapper.selectOne
### The error occurred while executing a query
### Cause: org.postgresql.util.PSQLException: FATAL: could not open file "global/pg_filenode.map": Permission denied
27-Nov-2024 11:53:11.431 INFO [Thread-2] org.apache.coyote.AbstractProtocol.pause Pausing ProtocolHandler ["http-nio-8080"]
27-Nov-2024 11:53:11.432 INFO [Thread-2] org.apache.catalina.core.StandardService.stopInternal Stopping service [Catalina]
27-Nov-2024 11:53:11.451 INFO [Thread-2] org.apache.coyote.AbstractProtocol.stop Stopping ProtocolHandler ["http-nio-8080"]
27-Nov-2024 11:53:11.454 INFO [Thread-2] org.apache.coyote.AbstractProtocol.destroy Destroying ProtocolHandler ["http-nio-8080"]
WARNING: POSTGRES_HOSTNAME detected, please use POSTGRESQL_HOSTNAME for further deployments.
WARNING: POSTGRES_DATABASE detected, please use POSTGRESQL_DATABASE for further deployments.
WARNING: POSTGRES_USER detected, please use POSTGRESQL_USER for further deployments.
WARNING: POSTGRES_PASSWORD detected, please use POSTGRESQL_PASSWORD for further deployments.
27-Nov-2024 11:53:12.615 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version name:   Apache Tomcat/8.5.100
27-Nov-2024 11:53:12.616 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server built:          Mar 19 2024 13:54:42 UTC
27-Nov-2024 11:53:12.617 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version number: 8.5.100.0
27-Nov-2024 11:53:12.617 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name:               Linux
27-Nov-2024 11:53:12.617 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version:            6.2.16-20-pve
27-Nov-2024 11:53:12.617 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture:          amd64
27-Nov-2024 11:53:12.617 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Java Home:             /opt/java/openjdk/jre
27-Nov-2024 11:53:12.617 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Version:           1.8.0_402-b06
27-Nov-2024 11:53:12.617 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Vendor:            Temurin
27-Nov-2024 11:53:12.617 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_BASE:         /home/guacamole/tomcat
27-Nov-2024 11:53:12.617 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_HOME:         /usr/local/tomcat
27-Nov-2024 11:53:12.617 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.config.file=/home/guacamole/tomcat/conf/logging.properties
27-Nov-2024 11:53:12.617 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
27-Nov-2024 11:53:12.617 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
27-Nov-2024 11:53:12.617 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources
27-Nov-2024 11:53:12.617 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dorg.apache.catalina.security.SecurityListener.UMASK=0027
27-Nov-2024 11:53:12.618 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dignore.endorsed.dirs=
27-Nov-2024 11:53:12.618 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.base=/home/guacamole/tomcat
27-Nov-2024 11:53:12.618 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=/usr/local/tomcat
27-Nov-2024 11:53:12.618 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=/home/guacamole/tomcat/temp
27-Nov-2024 11:53:12.618 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent Loaded Apache Tomcat Native library [1.2.39] using APR version [1.7.0].
27-Nov-2024 11:53:12.618 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true], UDS [{4}].
27-Nov-2024 11:53:12.618 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR/OpenSSL configuration: useAprConnector [false], useOpenSSL [true]
27-Nov-2024 11:53:12.621 INFO [main] org.apache.catalina.core.AprLifecycleListener.initializeSSL OpenSSL successfully initialized [OpenSSL 3.0.2 15 Mar 2022]
27-Nov-2024 11:53:12.682 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8080"]
27-Nov-2024 11:53:12.697 INFO [main] org.apache.catalina.startup.Catalina.load Initialization processed in 421 ms
27-Nov-2024 11:53:12.714 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina]
27-Nov-2024 11:53:12.714 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet engine: [Apache Tomcat/8.5.100]
27-Nov-2024 11:53:12.724 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployWAR Deploying web application archive [/home/guacamole/tomcat/webapps/guacamole.war]
27-Nov-2024 11:53:13.737 INFO [localhost-startStop-1] org.apache.jasper.servlet.TldScanner.scanJars At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
11:53:14.057 [localhost-startStop-1] INFO  o.a.g.environment.LocalEnvironment - GUACAMOLE_HOME is "/home/guacamole/.guacamole".
11:53:14.125 [localhost-startStop-1] INFO  o.a.g.GuacamoleServletContextListener - Read configuration parameters from "/home/guacamole/.guacamole/guacamole.properties".
11:53:14.126 [localhost-startStop-1] INFO  o.a.g.rest.auth.HashTokenSessionMap - Sessions will expire after 60 minutes of inactivity.
11:53:14.837 [localhost-startStop-1] INFO  o.a.g.extension.ExtensionModule - Extension "PostgreSQL Authentication" (postgresql) loaded.
11:53:14.911 [localhost-startStop-1] INFO  o.a.g.t.w.WebSocketTunnelModule - Loading JSR-356 WebSocket support...
27-Nov-2024 11:53:15.537 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployWAR Deployment of web application archive [/home/guacamole/tomcat/webapps/guacamole.war] has finished in [2,813] ms
27-Nov-2024 11:53:15.538 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
27-Nov-2024 11:53:15.545 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 2847 ms
11:54:00.477 [http-nio-8080-exec-1] INFO  o.a.g.r.auth.AuthenticationService - User "guac" successfully authenticated from [82.135.X.X, 192.168.X.X].
11:54:04.548 [http-nio-8080-exec-2] INFO  o.a.g.tunnel.TunnelRequestService - User "guac" connected to connection "1".
@boschkundendienst
Copy link
Owner

Hi, I can not help you a lot with the provided information but many thanks for the logs. It would be nice to also see your docker-compose.yml file. Maybe you can post it here (after removing credentials)?
One thing that comes to my mind is if you could verify, that the PGDATA environment from this line in docker-compose.yml is pointing to a subfolder of /var/lib/postgresql/data/ e.g. /var/lib/postgresql/data/guacamole and not only to /var/lib/postgresql/data/guacamole if you mount it to a local folder..

environment:
  PGDATA: /var/lib/postgresql/data/guacamole # subfolder guacamole
volumes:
   ./data:/var/lib/postgresql/data:Z

As you can see above the correct way is to map the local volume ./data to the folder /var/lib/postgresql/data but use the PGDATA environment variable to point to the folder /var/lib/postgresql/data/guacamole.

If this is done wrong, the database will not work correctly since the way the Postgresql official container works is to run through some scripts at startup and setting some permissions. This process will not work correctly if PGDATA is not set correctly. See this link for more information. (Make sure you read this section very closely to understand it.)

@Hisayoo
Copy link
Author

Hisayoo commented Nov 27, 2024

Hi, I can not help you a lot with the provided information but many thanks for the logs. It would be nice to also see your docker-compose.yml file. Maybe you can post it here (after removing credentials)? One thing that comes to my mind is if you could verify, that the PGDATA environment from this line in docker-compose.yml is pointing to a subfolder of /var/lib/postgresql/data/ e.g. /var/lib/postgresql/data/guacamole and not only to /var/lib/postgresql/data/guacamole if you mount it to a local folder..

environment:
  PGDATA: /var/lib/postgresql/data/guacamole # subfolder guacamole
volumes:
   ./data:/var/lib/postgresql/data:Z

As you can see above the correct way is to map the local volume ./data to the folder /var/lib/postgresql/data but use the PGDATA environment variable to point to the folder /var/lib/postgresql/data/guacamole.

If this is done wrong, the database will not work correctly since the way the Postgresql official container works is to run through some scripts at startup and setting some permissions. This process will not work correctly if PGDATA is not set correctly. See this link for more information. (Make sure you read this section very closely to understand it.)

Thanks for the response this is my compose

####################################################################################
# docker-compose file for Apache Guacamole
# created by PCFreak 2017-06-28
#
# Apache Guacamole is a clientless remote desktop gateway. It supports standard
# protocols like VNC, RDP, and SSH. We call it clientless because no plugins or
# client software are required. Thanks to HTML5, once Guacamole is installed on
# a server, all you need to access your desktops is a web browser.
####################################################################################
#
# What does this file do?
#
# Using docker-compose it will:
#
# - create a network 'guacnetwork_compose' with the 'bridge' driver.
# - create a service 'guacd_compose' from 'guacamole/guacd' connected to 'guacnetwork_compose'
# - create a service 'postgres_guacamole_compose' (1) from 'postgres' connected to 'guacnetwork_compose'
# - create a service 'guacamole_compose' (2)  from 'guacamole/guacamole/' conn. to 'guacnetwork_compose'
# - create a service 'nginx_guacamole_compose' (3) from 'nginx' connected to 'guacnetwork_compose'
#
# (1)
#  DB-Init script is in './init/initdb.sql' it has been created executing
#  'docker run --rm guacamole/guacamole /opt/guacamole/bin/initdb.sh --postgresql > ./init/initdb.sql'
#  once.
#  DATA-DIR       is in './data'
#  If you want to change the DB password change all lines with 'POSTGRES_PASSWORD:' and
#  change it to your needs before first start.
#  To start from scratch delete './data' dir completely
#  './data' will hold all data after first start!
#  The initdb.d scripts are only executed the first time the container is started
#  (and the database files are empty). If the database files already exist then the initdb.d
#  scripts are ignored (e.g. when you mount a local directory or when docker-compose saves
#  the volume and reuses it for the new container).
#
#  !!!!! MAKE SURE your folder './init' is executable (chmod +x ./init)
#  !!!!! or 'initdb.sql' will be ignored!
#  
#  './data' will hold all data after first start!
#
# (2)
#  Make sure you use the same value for 'POSTGRES_USER' and 'POSTGRES_PASSWORD'
#  as configured under (1)
#
# (3)
#  ./nginx/templates folder will be mapped read-only into the container at /etc/nginx/templates
#  and according to the official nginx container docs the guacamole.conf.template will be
#  placed in /etc/nginx/conf.d/guacamole.conf after container startup.
#  ./nginx/ssl will be mapped into the container at /etc/nginx/ssl
#  prepare.sh creates a a self-signed certificate. If you want to use your own certs
#  just remove the part that generates the certs from prepare.sh and replace
#  'self-ssl.key' and 'self.cert' with your certificate.
#  nginx will export port 8443 to the outside world, make sure that this port is reachable
#  on your system from the "outside world". All other traffic is only internal.
#
#  You could remove the entire 'nginx' service from this file if you want to use your own
#  reverse proxy in front of guacamole. If doing so, make sure you change the line
#   from     - 8080/tcp
#   to       - 8080:8080/tcp
#  within the 'guacamole' service. This will expose the guacamole webinterface directly
#  on port 8080 and you can use it for your own purposes.
#  Note: Guacamole is available on :8080/guacamole, not /.
#
# !!!!! FOR INITAL SETUP (after git clone) run ./prepare.sh once
#
# !!!!! FOR A FULL RESET (WILL ERASE YOUR DATABASE, YOUR FILES, YOUR RECORDS AND CERTS) DO A
# !!!!!  ./reset.sh
#
#
# The initial login to the guacamole webinterface is:
#
#     Username: guacadmin
#     Password: guacadmin
#
# Make sure you change it immediately!
#
# version            date              comment
# 0.1                2017-06-28        initial release
# 0.2                2017-10-09        minor fixes + internal GIT push
# 0.3                2017-10-09        minor fixes + public GIT push
# 0.4                2019-08-14        creating of ssl certs now in prepare.sh
#                                      simplified nginx startup commands
# 0.5                2023-02-24        nginx now uses a template + some minor changes
# 0.6                2023-03-23        switched to postgres 15.2-alpine
# 0.61               2024-07-27        fix networks + version 3.0
# 0.62               2024-07-27        fix
#####################################################################################

#the attribute `version` is obsolete, it will be ignored, please remove it to avoid potential confusion
#version: '3.0'

# networks
# create a network 'guacnetwork_compose' in mode 'bridged'
networks:
  guacnetwork_compose:
    driver: bridge

# services
services:
  # guacd
  guacd:
    container_name: guacd_compose
    image: guacamole/guacd
    networks:
      - guacnetwork_compose
    restart: always
    volumes:
    - ./drive:/drive:rw
    - ./record:/record:rw
  # postgres
  postgres:
    container_name: postgres_guacamole_compose
    environment:
      PGDATA: /var/lib/postgresql/data/guacamole
      POSTGRES_DB: guacamole_db
      POSTGRES_PASSWORD: 'XXX'
      POSTGRES_USER: guacamole_user
    image: postgres:15.2-alpine
    networks:
      - guacnetwork_compose
    restart: always
    volumes:
    - ./init:/docker-entrypoint-initdb.d:z
    - ./data:/var/lib/postgresql/data:Z

  # guacamole
  guacamole:
    container_name: guacamole_compose
    depends_on:
    - guacd
    - postgres
    environment:
      GUACD_HOSTNAME: guacd
      POSTGRES_DATABASE: guacamole_db
      POSTGRES_HOSTNAME: postgres
      POSTGRES_PASSWORD: 'XXX'
      POSTGRES_USER: guacamole_user
    image: guacamole/guacamole
    networks:
      - guacnetwork_compose
    volumes:
      - ./record:/record:rw
    ports:
## enable next line if not using nginx
##    - 8080:8080/tcp # Guacamole is on :8080/guacamole, not /.
## enable next line when using nginx
    - 8445:8080/tcp
    restart: always

@Hisayoo
Copy link
Author

Hisayoo commented Nov 27, 2024

ls -al
total 104
drwxr-xr-x  8 appuser users  4096 Nov 10 21:04 .
drwxrwxr-x 38 appuser users  4096 Nov 10 20:54 ..
-rw-r--r--  1 appuser users  3215 Nov 10 20:54 CODE_OF_CONDUCT.md
drwxr-xr-x  3 appuser users  4096 Nov 10 21:04 data
-rw-r--r--  1 appuser users  5949 Nov 10 20:58 docker-compose.yml
drwxr-xr-x  2 appuser users  4096 Nov 10 21:04 drive
drwxr-xr-x  8 appuser users  4096 Nov 10 20:54 .git
-rw-r--r--  1 appuser users    77 Nov 10 20:54 .gitattributes
-rw-r--r--  1 appuser users    59 Nov 10 20:54 .gitignore
drwxr-xr-x  2 appuser users  4096 Nov 10 21:03 init
-rw-r--r--  1 appuser users 35149 Nov 10 20:54 LICENSE
drwxr-xr-x  3 appuser users  4096 Nov 10 20:54 nginx
-rwxr-xr-x  1 appuser users   803 Nov 10 21:02 prepare.sh
-rw-r--r--  1 appuser users  6408 Nov 10 20:54 README.md
drwxr-xr-x  2 appuser users  4096 Nov 10 21:04 record
-rwxr-xr-x  1 appuser users   466 Nov 10 20:54 reset.sh
ls -al
total 12
drwxr-xr-x  3 appuser users 4096 Nov 10 21:04 .
drwxr-xr-x  8 appuser users 4096 Nov 10 21:04 ..
drwx------ 19      70 users 4096 Nov 27 12:53 guacamole
root@guacserver:/docker/appdata/guacamole-docker-compose/data#
ls -al
total 136
drwx------ 19      70 users  4096 Nov 27 12:53 .
drwxr-xr-x  3 appuser users  4096 Nov 10 21:04 ..
drwx------  6      70 users  4096 Nov 10 21:04 base
drwx------  2      70 users  4096 Nov 27 12:53 global
drwx------  2      70 users  4096 Nov 10 21:04 pg_commit_ts
drwx------  2      70 users  4096 Nov 10 21:04 pg_dynshmem
-rw-------  1      70 users  4821 Nov 10 21:04 pg_hba.conf
-rw-------  1      70 users  1636 Nov 10 21:04 pg_ident.conf
drwx------  4      70 users  4096 Nov 27 15:53 pg_logical
drwx------  4      70 users  4096 Nov 10 21:04 pg_multixact
drwx------  2      70 users  4096 Nov 10 21:04 pg_notify
drwx------  2      70 users  4096 Nov 10 21:04 pg_replslot
drwx------  2      70 users  4096 Nov 10 21:04 pg_serial
drwx------  2      70 users  4096 Nov 10 21:04 pg_snapshots
drwx------  2      70 users  4096 Nov 23 06:32 pg_stat
drwx------  2      70 users  4096 Nov 10 21:04 pg_stat_tmp
drwx------  2      70 users  4096 Nov 10 21:04 pg_subtrans
drwx------  2      70 users  4096 Nov 10 21:04 pg_tblspc
drwx------  2      70 users  4096 Nov 10 21:04 pg_twophase
-rw-------  1      70 users     3 Nov 10 21:04 PG_VERSION
drwx------  3      70 users  4096 Nov 10 21:04 pg_wal
drwx------  2      70 users  4096 Nov 10 21:04 pg_xact
-rw-------  1      70 users    88 Nov 10 21:04 postgresql.auto.conf
-rw-------  1      70 users 29408 Nov 10 21:04 postgresql.conf
-rw-------  1      70 users    24 Nov 27 12:53 postmaster.opts
-rw-------  1      70    70   104 Nov 27 12:53 postmaster.pid
root@guacserver:/docker/appdata/guacamole-docker-compose/data/guacamole#

It appears It's owned by 70 for some reason ?

@boschkundendienst
Copy link
Owner

Just tested and all the postgres files are owned by 70:70 here.

docker compose up -d

sudo ls -al data/guacamole/
insgesamt 136
drwx------ 19   70 root  4096 28. Nov 01:12 .
drwxr-xr-x  3 root root  4096 28. Nov 01:12 ..
drwx------  6   70   70  4096 28. Nov 01:12 base
drwx------  2   70   70  4096 28. Nov 01:12 global
drwx------  2   70   70  4096 28. Nov 01:12 pg_commit_ts
drwx------  2   70   70  4096 28. Nov 01:12 pg_dynshmem
-rw-------  1   70   70  4821 28. Nov 01:12 pg_hba.conf
-rw-------  1   70   70  1636 28. Nov 01:12 pg_ident.conf
drwx------  4   70   70  4096 28. Nov 01:12 pg_logical
drwx------  4   70   70  4096 28. Nov 01:12 pg_multixact
drwx------  2   70   70  4096 28. Nov 01:12 pg_notify
drwx------  2   70   70  4096 28. Nov 01:12 pg_replslot
drwx------  2   70   70  4096 28. Nov 01:12 pg_serial
drwx------  2   70   70  4096 28. Nov 01:12 pg_snapshots
drwx------  2   70   70  4096 28. Nov 01:12 pg_stat
drwx------  2   70   70  4096 28. Nov 01:12 pg_stat_tmp
drwx------  2   70   70  4096 28. Nov 01:12 pg_subtrans
drwx------  2   70   70  4096 28. Nov 01:12 pg_tblspc
drwx------  2   70   70  4096 28. Nov 01:12 pg_twophase
-rw-------  1   70   70     3 28. Nov 01:12 PG_VERSION
drwx------  3   70   70  4096 28. Nov 01:12 pg_wal
drwx------  2   70   70  4096 28. Nov 01:12 pg_xact
-rw-------  1   70   70    88 28. Nov 01:12 postgresql.auto.conf
-rw-------  1   70   70 29408 28. Nov 01:12 postgresql.conf
-rw-------  1   70   70    24 28. Nov 01:12 postmaster.opts
-rw-------  1   70   70   104 28. Nov 01:12 postmaster.pid

Since postmaster.pid will be removed on a clean shutdown of the container (docker compose down) I can see no problem.

docker compose down

sudo ls -al data/guacamole/
 
insgesamt 132
drwx------ 19   70 root  4096 28. Nov 01:18 .
drwxr-xr-x  3 root root  4096 28. Nov 01:12 ..
drwx------  6   70   70  4096 28. Nov 01:12 base
drwx------  2   70   70  4096 28. Nov 01:14 global
drwx------  2   70   70  4096 28. Nov 01:12 pg_commit_ts
drwx------  2   70   70  4096 28. Nov 01:12 pg_dynshmem
-rw-------  1   70   70  4821 28. Nov 01:12 pg_hba.conf
-rw-------  1   70   70  1636 28. Nov 01:12 pg_ident.conf
drwx------  4   70   70  4096 28. Nov 01:18 pg_logical
drwx------  4   70   70  4096 28. Nov 01:12 pg_multixact
drwx------  2   70   70  4096 28. Nov 01:12 pg_notify
drwx------  2   70   70  4096 28. Nov 01:12 pg_replslot
drwx------  2   70   70  4096 28. Nov 01:12 pg_serial
drwx------  2   70   70  4096 28. Nov 01:12 pg_snapshots
drwx------  2   70   70  4096 28. Nov 01:18 pg_stat
drwx------  2   70   70  4096 28. Nov 01:12 pg_stat_tmp
drwx------  2   70   70  4096 28. Nov 01:12 pg_subtrans
drwx------  2   70   70  4096 28. Nov 01:12 pg_tblspc
drwx------  2   70   70  4096 28. Nov 01:12 pg_twophase
-rw-------  1   70   70     3 28. Nov 01:12 PG_VERSION
drwx------  3   70   70  4096 28. Nov 01:12 pg_wal
drwx------  2   70   70  4096 28. Nov 01:12 pg_xact
-rw-------  1   70   70    88 28. Nov 01:12 postgresql.auto.conf
-rw-------  1   70   70 29408 28. Nov 01:12 postgresql.conf
-rw-------  1   70   70    24 28. Nov 01:12 postmaster.opts

As you can see with a coordinated shutdown postmaster.pid is gone!

How do you startup the container? Do you use docker compose up -d?

Because you have a postmaster.pid at startup of the postgresql container I assume your container crashed. Could it be that maybe your system runs out of resources at one point and the system kills the containers resulting having the postgresql files in a undefined state?

I do no longer use this project, I switched to run guacamole using podman on RHEL but anyways I think nothing is wrong, must be something related to your specific system but I think the root cause is an uncoordinated container crash. Maybe you could somehow store the logs of the container somehow to have it after the container crashed (when your web interface is not reachable)?

@Hisayoo
Copy link
Author

Hisayoo commented Dec 3, 2024

I don't think the container is crashing because all of my other docker containers are fine. My Server usually automatically shuts down at night, but nothing gets corrupted. Maybe it's some user/group permission error? I probably have gotten this same error on all the other guacamole docker images but for those you couldn't see the logs of individual containers.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants