Some time ago I've installed Apache Guacamole(Guacd->Tomcat9->Apache [as reverse proxy for guac to be accessible vhost]) on my LAMP server, installation was simple as instructions were clear and understandable and the instance of Guacamole worked flawlessly no matter the RDP, SSH or VNC.
Yesterday I've encountered a problem with Guacamole - starting from the frontend:
An internal error has occurred within the Guacamole server, and the connection has been terminated. If the problem persists, please notify your system administrator, or check your system logs.
So the problem states that there is a problem with Guacamole server alone, reading status of the Guacamole:
maj 20 10:02:02 mywebsite.here systemd[1]: Starting LSB: Guacamole proxy daemon...
maj 20 10:02:02 mywebsite.here guacd[32305]: Guacamole proxy daemon (guacd) version 1.4.0 started
maj 20 10:02:02 mywebsite.here guacd[32303]: Starting guacd:
maj 20 10:02:02 mywebsite.here guacd[32305]: guacd[32305]: INFO: Guacamole proxy daemon (guacd) version 1.4.0 started
maj 20 10:02:02 mywebsite.here guacd[32307]: Listening on host ::1, port 4822
maj 20 10:02:02 mywebsite.here guacd[32303]: SUCCESS
maj 20 10:02:02 mywebsite.here systemd[1]: Started LSB: Guacamole proxy daemon.
From the current logs of guacd everything seems to be okay, guacd listens on localhost and binds to 4822 - checking the netstat to verify service availability:
tcp6 0 0 localhost:4822 [::]:* LISTEN 32307/guacd
And telnet to localhost:4822 :
telnet localhost 4822
Trying ::1...
Connected to localhost.
Escape character is '^]'.
pressing enter
Connection closed by foreign host.
Back to Guacamole:
guacd[32307]: Guacamole protocol violation. Perhaps the version of guacamole-client is incompatible with this version of guacd?
So as you can't use telnet with guacamole the connection is terminated but from what I can see by this is that the service is available & ready to be used.
As the Guacamole seems to be okay it's time for Tomcat9 :
[2022-05-20 10:20:26] [info] 10:20:26.434 [http-nio-8080-exec-10] ERROR o.a.g.w.GuacamoleWebSocketTunnelEndpoint - Creation of WebSocket tunnel to guacd failed: java.net.ConnectException: Połączenie odrzucone (Connection refused)
[2022-05-20 10:20:26] [info] 10:20:26.682 [http-nio-8080-exec-8] ERROR o.a.g.s.GuacamoleHTTPTunnelServlet - HTTP tunnel request failed: java.net.ConnectException: Połączenie odrzucone (Connection refused)
It's getting more clear that the problem has to be between Tomcat9 and Guacamole itself and from the Tomcat side - do you have any ideas how to debug this?
Tomcat logs with increased loglevel:
Error moment:
[2022-05-24 08:56:11] [info] 08:56:11.135 [http-nio-8080-exec-3] DEBUG o.a.i.d.pooled.PooledDataSource - Testing connection 29049410 ...
[2022-05-24 08:56:11] [info] 08:56:11.139 [http-nio-8080-exec-3] DEBUG o.a.i.d.pooled.PooledDataSource - Connection 29049410 is GOOD!
[2022-05-24 08:56:11] [info] 08:56:11.139 [http-nio-8080-exec-3] DEBUG o.a.i.d.pooled.PooledDataSource - Returned connection 29049410 to pool.
[2022-05-24 08:56:11] [info] 08:56:11.140 [http-nio-8080-exec-3] ERROR o.a.g.w.GuacamoleWebSocketTunnelEndpoint - Creation of WebSocket tunnel to guacd failed: java.net.ConnectException: Połączenie odrzucone (Connection refused)
[2022-05-24 08:56:11] [info] 08:56:11.159 [http-nio-8080-exec-3] DEBUG o.a.g.w.GuacamoleWebSocketTunnelEndpoint - Error connecting WebSocket tunnel.
[2022-05-24 08:56:11] [info] org.apache.guacamole.GuacamoleServerException: java.net.ConnectException: Połączenie odrzucone (Connection refused)
[2022-05-24 08:56:11] [info] #011at org.apache.guacamole.net.InetGuacamoleSocket.<init>(InetGuacamoleSocket.java:114)
[2022-05-24 08:56:11] [info] #011at org.apache.guacamole.auth.jdbc.tunnel.ManagedInetGuacamoleSocket.<init>(ManagedInetGuacamoleSocket.java:56)
[2022-05-24 08:56:11] [info] #011at org.apache.guacamole.auth.jdbc.tunnel.AbstractGuacamoleTunnelService.getUnconfiguredGuacamoleSocket(AbstractGuacamoleTunnelService.java:319)
[2022-05-24 08:56:11] [info] #011at org.apache.guacamole.auth.jdbc.tunnel.AbstractGuacamoleTunnelService.assignGuacamoleTunnel(AbstractGuacamoleTunnelService.java:483)
[2022-05-24 08:56:11] [info] #011at org.apache.guacamole.auth.jdbc.tunnel.AbstractGuacamoleTunnelService.getGuacamoleTunnel(AbstractGuacamoleTunnelService.java:643)
[2022-05-24 08:56:11] [info] #011at org.mybatis.guice.transactional.TransactionalMethodInterceptor.invoke(TransactionalMethodInterceptor.java:96)
[2022-05-24 08:56:11] [info] #011at org.apache.guacamole.auth.jdbc.connection.ConnectionService.connect(ConnectionService.java:548)
[2022-05-24 08:56:11] [info] #011at org.apache.guacamole.auth.jdbc.connection.ModeledConnection.connect(ModeledConnection.java:274)
[2022-05-24 08:56:11] [info] #011at org.apache.guacamole.tunnel.TunnelRequestService.createConnectedTunnel(TunnelRequestService.java:216)
[2022-05-24 08:56:11] [info] #011at org.apache.guacamole.tunnel.TunnelRequestService.createTunnel(TunnelRequestService.java:347)
[2022-05-24 08:56:11] [info] #011at org.apache.guacamole.tunnel.websocket.RestrictedGuacamoleWebSocketTunnelEndpoint.createTunnel(RestrictedGuacamoleWebSocketTunnelEndpoint.java:113)
[2022-05-24 08:56:11] [info] #011at org.apache.guacamole.websocket.GuacamoleWebSocketTunnelEndpoint.onOpen(GuacamoleWebSocketTunnelEndpoint.java:200)
[2022-05-24 08:56:11] [info] #011at org.apache.tomcat.websocket.server.WsHttpUpgradeHandler.init(WsHttpUpgradeHandler.java:136)
[2022-05-24 08:56:11] [info] #011at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:934)
[2022-05-24 08:56:11] [info] #011at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1684)
[2022-05-24 08:56:11] [info] #011at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
[2022-05-24 08:56:11] [info] #011at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
[2022-05-24 08:56:11] [info] #011at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
[2022-05-24 08:56:11] [info] #011at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
[2022-05-24 08:56:11] [info] #011at java.base/java.lang.Thread.run(Thread.java:829)
[2022-05-24 08:56:11] [info] Caused by: java.net.ConnectException: Połączenie odrzucone (Connection refused)
[2022-05-24 08:56:11] [info] #011at java.base/java.net.PlainSocketImpl.socketConnect(Native Method)
[2022-05-24 08:56:11] [info] #011at java.base/java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:412)
[2022-05-24 08:56:11] [info] #011at java.base/java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:255)
[2022-05-24 08:56:11] [info] #011at java.base/java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:237)
[2022-05-24 08:56:11] [info] #011at java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
[2022-05-24 08:56:11] [info] #011at java.base/java.net.Socket.connect(Socket.java:609)
[2022-05-24 08:56:11] [info] #011at org.apache.guacamole.net.InetGuacamoleSocket.<init>(InetGuacamoleSocket.java:100)
[2022-05-24 08:56:11] [info] #011... 19 common frames omitted
I am not into Java for any means but I belive that actual error reason is inside that part of log. I'll be grateful for anyone who is related to Java to take a look and provide their opinion if this is related.
Guacamole.properties:
MySQL properties
mysql-hostname: 127.0.0.1
mysql-port: 3306
mysql-database: guacamole_db
mysql-username: guacamole_admin
mysql-password: guacamole_******
Hostname and port of guacamole proxy
guacd-hostname: 192.168.1.49
guacd-port: 4822
change between localhost representations (127.0.0.1/::1/localhost/192.168.1.49[local static addr]) doesn't make diffrence
Analyze of Apache log is probably pointless as attempt to use Guacamole through Tomcat9 only provided the same result.
By default on IPv6 enabled systems guacd listens on ::1. Even specifying localhost on /etc/guacamole/guacd.conf does not work. Here is the guacd.conf file that worked.
[daemon]
pid_file = /var/run/guacd.pid
#log_level = debug
[server]
#bind_host = localhost
bind_host = 127.0.0.1
bind_port = 4822
#[ssl]
#server_certificate = /etc/ssl/certs/guacd.crt
#server_key = /etc/ssl/private/guacd.key
Setting it to debug showed daemon is listing on ::1. Changed localhost to 127.0.0.1 and it worked!
Also including the error on client so folks can arrive at this question/answer: an internal error has occurred within the guacamole server, and the connection has been terminated. if the problem persists, please notify your system administrator, or check your system logs
If you get this message check the tomcat catalina.out file for the issue. Here is what I had for the issue:
[2022-11-12 07:47:47] [info] 07:47:47.251 [http-nio-8080-exec-2] ERROR o.a.g.w.GuacamoleWebSocketTunnelEndpoint - Creation of WebSocket tunnel to guacd failed: java.net.ConnectException: Connection refused (Connection refused)
[2022-11-12 07:47:47] [info] 07:47:47.301 [http-nio-8080-exec-3] ERROR o.a.g.s.GuacamoleHTTPTunnelServlet - HTTP tunnel request failed: java.net.ConnectException: Connection refused (Connection refused)