[jira] [Commented] (GUACAMOLE-919) An I/O error occurred while sending to the backend
[ https://issues.apache.org/jira/browse/GUACAMOLE-919?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17153270#comment-17153270 ] Douglas Heriot commented on GUACAMOLE-919: -- Sorry I've not looked at this for a while. I've just rebased my changes over the current master since the 1.2.0 release, and addressed the issues raised in the pull request review: [https://github.com/apache/guacamole-client/pull/488] I've also added a pull request that adds documentation for these new properties: [https://github.com/apache/guacamole-manual/pull/146] > An I/O error occurred while sending to the backend > -- > > Key: GUACAMOLE-919 > URL: https://issues.apache.org/jira/browse/GUACAMOLE-919 > Project: Guacamole > Issue Type: Bug > Components: guacamole-auth-jdbc-postgresql >Affects Versions: 1.0.0 >Reporter: Mechanix >Assignee: Nick Couchman >Priority: Minor > Attachments: image-2020-01-27-15-19-26-634.png > > > Hi, > we use guacamole with postgresql and openid extension. Guacamole and guacd is > deployed inside a k8s cluster. > For some reason, the authentication doesn't succeed sporadically; there is > only a blank page and this error message in the guacamole log: > *[pool-1-thread-1] WARN o.a.i.d.pooled.PooledDataSource - Execution of ping > query 'SELECT 1' failed: An I/O error occurred while sending to the backend.* > I suspect there is a weird timeout happening between guacamole and postgresql > but couldn't figure out why. > Any hints are much appreciated. Thanks > > -- This message was sent by Atlassian Jira (v8.3.4#803005)
[jira] [Commented] (GUACAMOLE-919) An I/O error occurred while sending to the backend
[ https://issues.apache.org/jira/browse/GUACAMOLE-919?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17144806#comment-17144806 ] Mechanix commented on GUACAMOLE-919: Hi [~DouglasHeriot] , any updates ? Thanks > An I/O error occurred while sending to the backend > -- > > Key: GUACAMOLE-919 > URL: https://issues.apache.org/jira/browse/GUACAMOLE-919 > Project: Guacamole > Issue Type: Bug > Components: guacamole-auth-jdbc-postgresql >Affects Versions: 1.0.0 >Reporter: Mechanix >Assignee: Nick Couchman >Priority: Minor > Attachments: image-2020-01-27-15-19-26-634.png > > > Hi, > we use guacamole with postgresql and openid extension. Guacamole and guacd is > deployed inside a k8s cluster. > For some reason, the authentication doesn't succeed sporadically; there is > only a blank page and this error message in the guacamole log: > *[pool-1-thread-1] WARN o.a.i.d.pooled.PooledDataSource - Execution of ping > query 'SELECT 1' failed: An I/O error occurred while sending to the backend.* > I suspect there is a weird timeout happening between guacamole and postgresql > but couldn't figure out why. > Any hints are much appreciated. Thanks > > -- This message was sent by Atlassian Jira (v8.3.4#803005)
[jira] [Commented] (GUACAMOLE-919) An I/O error occurred while sending to the backend
[ https://issues.apache.org/jira/browse/GUACAMOLE-919?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17076410#comment-17076410 ] Mechanix commented on GUACAMOLE-919: [~DouglasHeriot] I've build the image from your PR and I can confirm that it works; no blank page anymore after a idle time > 60m Thanks for your support. > An I/O error occurred while sending to the backend > -- > > Key: GUACAMOLE-919 > URL: https://issues.apache.org/jira/browse/GUACAMOLE-919 > Project: Guacamole > Issue Type: Bug > Components: guacamole-auth-jdbc-postgresql >Affects Versions: 1.0.0 >Reporter: Mechanix >Assignee: Nick Couchman >Priority: Minor > Attachments: image-2020-01-27-15-19-26-634.png > > > Hi, > we use guacamole with postgresql and openid extension. Guacamole and guacd is > deployed inside a k8s cluster. > For some reason, the authentication doesn't succeed sporadically; there is > only a blank page and this error message in the guacamole log: > *[pool-1-thread-1] WARN o.a.i.d.pooled.PooledDataSource - Execution of ping > query 'SELECT 1' failed: An I/O error occurred while sending to the backend.* > I suspect there is a weird timeout happening between guacamole and postgresql > but couldn't figure out why. > Any hints are much appreciated. Thanks > > -- This message was sent by Atlassian Jira (v8.3.4#803005)
[jira] [Commented] (GUACAMOLE-919) An I/O error occurred while sending to the backend
[ https://issues.apache.org/jira/browse/GUACAMOLE-919?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17073761#comment-17073761 ] Douglas Heriot commented on GUACAMOLE-919: -- [~mechanix] socketTimeout is not a setting on pgBouncer - it's a setting on Guacamole that I've added in to pass through to the pgjdbc driver. It looks like by your test that pgBouncer isn't actually solving the issue - the socketTimeout setting is essential to fix this. Can you try building guacamole with my pull request, and running with POSTGRES_SOCKET_TIMEOUT=5 ? > An I/O error occurred while sending to the backend > -- > > Key: GUACAMOLE-919 > URL: https://issues.apache.org/jira/browse/GUACAMOLE-919 > Project: Guacamole > Issue Type: Bug > Components: guacamole-auth-jdbc-postgresql >Affects Versions: 1.0.0 >Reporter: Mechanix >Assignee: Nick Couchman >Priority: Minor > Attachments: image-2020-01-27-15-19-26-634.png > > > Hi, > we use guacamole with postgresql and openid extension. Guacamole and guacd is > deployed inside a k8s cluster. > For some reason, the authentication doesn't succeed sporadically; there is > only a blank page and this error message in the guacamole log: > *[pool-1-thread-1] WARN o.a.i.d.pooled.PooledDataSource - Execution of ping > query 'SELECT 1' failed: An I/O error occurred while sending to the backend.* > I suspect there is a weird timeout happening between guacamole and postgresql > but couldn't figure out why. > Any hints are much appreciated. Thanks > > -- This message was sent by Atlassian Jira (v8.3.4#803005)
[jira] [Commented] (GUACAMOLE-919) An I/O error occurred while sending to the backend
[ https://issues.apache.org/jira/browse/GUACAMOLE-919?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17073725#comment-17073725 ] Mechanix commented on GUACAMOLE-919: OK, I've disabled the openid plugin and can confirm that the same issue occurs. Guacamole connects to pgBouncer and here are the logs from start of guacamole: 11:56:15.015 [http-nio-8080-exec-6] DEBUG o.a.i.t.jdbc.JdbcTransaction - Setting autocommit to false on JDBC Connection [org.postgresql.jdbc.PgConnection@2e60eb9c] 11:56:15.015 [http-nio-8080-exec-6] DEBUG o.a.g.a.j.b.E.selectEffectiveGroupIdentifiers - ==> Preparing: WITH RECURSIVE related_entity(entity_id) AS ( SELECT guacamole_user_group.entity_id FROM guacamole_user_group JOIN guacamole_user_group_member ON guacamole_user_group.user_group_id = guacamole_user_group_member.user_group_id WHERE guacamole_user_group_member.member_entity_id = ? AND guacamole_user_group.disabled = false UNION SELECT guacamole_user_group.entity_id FROM related_entity JOIN guacamole_user_group_member ON related_entity.entity_id = guacamole_user_group_member.member_entity_id JOIN guacamole_user_group ON guacamole_user_group.user_group_id = guacamole_user_group_member.user_group_id WHERE guacamole_user_group.disabled = false ) SELECT name FROM related_entity JOIN guacamole_entity ON related_entity.entity_id = guacamole_entity.entity_id WHERE guacamole_entity.type = 'USER_GROUP'::guacamole_entity_type; 11:56:15.015 [http-nio-8080-exec-6] DEBUG o.a.g.a.j.b.E.selectEffectiveGroupIdentifiers - ==> Parameters: 1(Integer) 11:56:15.016 [http-nio-8080-exec-2] DEBUG o.a.g.a.j.b.E.selectEffectiveGroupIdentifiers - <== Total: 0 11:56:15.017 [http-nio-8080-exec-2] DEBUG o.m.g.t.TransactionalMethodInterceptor - [Intercepted method: public java.util.Set org.apache.guacamole.auth.jdbc.base.EntityService.retrieveEffectiveGroups(org.apache.guacamole.auth.jdbc.base.ModeledPermissions,java.util.Collection)] - SqlSession of thread: 21 committing 11:56:15.017 [http-nio-8080-exec-2] DEBUG o.m.g.t.TransactionalMethodInterceptor - [Intercepted method: public java.util.Set org.apache.guacamole.auth.jdbc.base.EntityService.retrieveEffectiveGroups(org.apache.guacamole.auth.jdbc.base.ModeledPermissions,java.util.Collection)] - SqlSession of thread: 21 terminated its life-cycle, closing it 11:56:15.018 [http-nio-8080-exec-2] DEBUG o.a.i.t.jdbc.JdbcTransaction - Resetting autocommit to true on JDBC Connection [org.postgresql.jdbc.PgConnection@77bb9a31] 11:56:15.020 [http-nio-8080-exec-6] DEBUG o.a.g.a.j.b.E.selectEffectiveGroupIdentifiers - <== Total: 0 11:56:15.020 [http-nio-8080-exec-6] DEBUG o.m.g.t.TransactionalMethodInterceptor - [Intercepted method: public java.util.Set org.apache.guacamole.auth.jdbc.base.EntityService.retrieveEffectiveGroups(org.apache.guacamole.auth.jdbc.base.ModeledPermissions,java.util.Collection)] - SqlSession of thread: 25 committing 11:56:15.020 [http-nio-8080-exec-6] DEBUG o.m.g.t.TransactionalMethodInterceptor - [Intercepted method: public java.util.Set org.apache.guacamole.auth.jdbc.base.EntityService.retrieveEffectiveGroups(org.apache.guacamole.auth.jdbc.base.ModeledPermissions,java.util.Collection)] - SqlSession of thread: 25 terminated its life-cycle, closing it 11:56:15.020 [http-nio-8080-exec-6] DEBUG o.a.i.t.jdbc.JdbcTransaction - Resetting autocommit to true on JDBC Connection [org.postgresql.jdbc.PgConnection@2e60eb9c] 11:56:15.022 [http-nio-8080-exec-2] DEBUG o.a.i.t.jdbc.JdbcTransaction - Closing JDBC Connection [org.postgresql.jdbc.PgConnection@77bb9a31] 11:56:15.022 [http-nio-8080-exec-2] DEBUG o.a.i.d.pooled.PooledDataSource - Testing connection 2008783409 ... 11:56:15.024 [http-nio-8080-exec-6] DEBUG o.a.i.t.jdbc.JdbcTransaction - Closing JDBC Connection [org.postgresql.jdbc.PgConnection@2e60eb9c] 11:56:15.024 [http-nio-8080-exec-2] DEBUG o.a.i.d.pooled.PooledDataSource - Connection 2008783409 is GOOD! 11:56:15.024 [http-nio-8080-exec-2] DEBUG o.a.i.d.pooled.PooledDataSource - Returned connection 2008783409 to pool. 11:56:15.025 [http-nio-8080-exec-2] DEBUG o.m.g.t.TransactionalMethodInterceptor - [Intercepted method: public java.util.Set org.apache.guacamole.auth.jdbc.base.EntityService.retrieveEffectiveGroups(org.apache.guacamole.auth.jdbc.base.ModeledPermissions,java.util.Collection)] - SqlSession not set for thread: 21, creating a new one 11:56:15.025 [http-nio-8080-exec-6] DEBUG o.a.i.d.pooled.PooledDataSource - Testing connection 778103708 ... 11:56:15.025 [http-nio-8080-exec-2] DEBUG o.a.i.t.jdbc.JdbcTransaction - Opening JDBC Connection 11:56:15.027 [http-nio-8080-exec-6] DEBUG o.a.i.d.pooled.PooledDataSource - Connection 778103708 is GOOD! 11:56:15.027 [http-nio-8080-exec-6] DEBUG o.a.i.d.pooled.PooledDataSource - Returned connection 778103708 to pool. 11:56:15.027 [http-nio-8080-exec-2] DEBUG o.a.i.d.pooled.PooledDataSource - Checked out
[jira] [Commented] (GUACAMOLE-919) An I/O error occurred while sending to the backend
[
https://issues.apache.org/jira/browse/GUACAMOLE-919?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17073565#comment-17073565
]
Mechanix commented on GUACAMOLE-919:
[~DouglasHeriot] Thanks for opening a PR, much appreciated.
Which socketTimeout do you mean? I couldn't find that one in
https://www.pgbouncer.org/config.html#dangerous-timeouts
I've redeployed pgBouncer and the pod starts with:
{code:bash}
Wrote authentication credentials to /etc/pgbouncer/userlist.txt
Create pgbouncer config in /etc/pgbouncer
## Auto generated ##
[databases]
guacamole = host=10.2.133.8 port=5432 user=guacamole
[pgbouncer]
listen_addr = 0.0.0.0
listen_port = 5432
unix_socket_dir =
user = postgres
auth_file = /etc/pgbouncer/userlist.txt
auth_type = md5
pool_mode = session
ignore_startup_parameters = extra_float_digits
# Log settings
admin_users = postgres
# Connection sanity checks, timeouts
server_reset_query = DISCARD ALL
# TLS settings
# Dangerous timeouts
query_wait_timeout = 7
tcp_keepalive = 1
tcp_keepidle = 7200
## end file ##
{code}
But I'm still getting this errors and the blank page after 1h of idle time:
08:37:55.274 [http-nio-8080-exec-2] DEBUG o.a.i.t.jdbc.JdbcTransaction -
Opening JDBC Connection
{color:#DE350B}08:42:30.247 [pool-1-thread-1] WARN
o.a.i.d.pooled.PooledDataSource - Execution of ping query 'SELECT 1' failed:
ERROR: server conn crashed?
08:42:30.248 [pool-1-thread-1] DEBUG o.a.i.d.pooled.PooledDataSource -
Connection 143715841 is BAD: ERROR: server conn crashed?
08:42:30.248 [pool-1-thread-1] DEBUG o.a.i.d.pooled.PooledDataSource - A bad
connection (143715841) was returned from the pool, getting another connection.
08:42:30.248 [pool-1-thread-1] DEBUG o.a.i.d.pooled.PooledDataSource - Checked
out connection 65259250 from pool.
08:42:30.248 [pool-1-thread-1] DEBUG o.a.i.d.pooled.PooledDataSource - Testing
connection 65259250 ...
08:58:01.546 [pool-1-thread-1] WARN o.a.i.d.pooled.PooledDataSource - Execution
of ping query 'SELECT 1' failed: ERROR: server conn crashed?
08:58:01.546 [pool-1-thread-1] DEBUG o.a.i.d.pooled.PooledDataSource -
Connection 65259250 is BAD: ERROR: server conn crashed?
08:58:01.546 [pool-1-thread-1] DEBUG o.a.i.d.pooled.PooledDataSource - A bad
connection (65259250) was returned from the pool, getting another connection.
08:58:01.546 [pool-1-thread-1] DEBUG o.a.i.d.pooled.PooledDataSource - Checked
out connection 1404868066 from pool.
08:58:01.546 [pool-1-thread-1] DEBUG o.a.i.d.pooled.PooledDataSource - Testing
connection 1404868066 ...
09:13:33.898 [pool-1-thread-1] WARN o.a.i.d.pooled.PooledDataSource - Execution
of ping query 'SELECT 1' failed: ERROR: server conn crashed?
09:13:33.898 [pool-1-thread-1] DEBUG o.a.i.d.pooled.PooledDataSource -
Connection 1404868066 is BAD: ERROR: server conn crashed?{color}
09:13:33.898 [pool-1-thread-1] DEBUG o.a.i.d.pooled.PooledDataSource - A bad
connection (1404868066) was returned from the pool, getting another connection.
09:13:34.011 [pool-1-thread-1] DEBUG o.a.i.d.pooled.PooledDataSource - Created
connection 1606057130.
09:13:34.011 [pool-1-thread-1] DEBUG o.a.g.a.j.u.UserRecordMapper.update - ==>
Preparing: UPDATE guacamole_user_history SET remote_host = ?, user_id = (SELECT
user_id FROM guacamole_user JOIN guacamole_entity ON guacamole_user.entity_id =
guacamole_entity.entity_id WHERE guacamole_entity.name = ? AND
guacamole_entity.type = 'USER'::guacamole_entity_type), username = ?,
start_date = ?, end_date = ? WHERE history_id = ?::integer
09:13:34.013 [pool-1-thread-1] DEBUG o.a.g.a.j.u.UserRecordMapper.update - ==>
Parameters: 10.2.136.4(String), chuegel(String), chuegel(String), 2020-04-02
07:24:52.214(Timestamp), 2020-04-02 08:26:59.175(Timestamp), 97(Integer)
09:13:34.032 [pool-1-thread-1] DEBUG o.a.g.a.j.u.UserRecordMapper.update - <==
Updates: 1
09:13:34.032 [pool-1-thread-1] DEBUG o.a.i.t.jdbc.JdbcTransaction - Committing
JDBC Connection [org.postgresql.jdbc.PgConnection@5fba7caa]
09:13:34.047 [pool-1-thread-1] DEBUG o.a.i.t.jdbc.JdbcTransaction - Resetting
autocommit to true on JDBC Connection
[org.postgresql.jdbc.PgConnection@5fba7caa]
09:13:34.047 [pool-1-thread-1] DEBUG o.a.i.t.jdbc.JdbcTransaction - Closing
JDBC Connection [org.postgresql.jdbc.PgConnection@5fba7caa]
09:13:34.096 [http-nio-8080-exec-2] DEBUG o.a.i.d.pooled.PooledDataSource -
Created connection 1188204539.
09:13:34.097 [http-nio-8080-exec-2] DEBUG o.a.g.a.j.user.UserMapper.selectOne -
==> Preparing: SELECT guacamole_user.user_id, guacamole_entity.entity_id,
guacamole_entity.name, password_hash, password_salt, password_date, disabled,
expired, access_window_start, access_window_end, valid_from, valid_until,
timezone, full_name, email_address, organization, organizational_role,
MAX(start_date) AS last_active FROM guacamole_user JOIN guacamole_entity ON
[jira] [Commented] (GUACAMOLE-919) An I/O error occurred while sending to the backend
[ https://issues.apache.org/jira/browse/GUACAMOLE-919?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17072740#comment-17072740 ] Douglas Heriot commented on GUACAMOLE-919: -- [~mechanix] I think you're right - that's two separate issues. I think I've seen that JWK error when the time on the server was not configured correctly and the NTP service wasn't running. The separate thing with the SQL connection I think is showing it's connecting to pgBouncer. The error message "server conn crashed" is different to before and is what is showing up in my pgBouncer logs. The interesting option I'm setting in pgBouncer is PGBOUNCER_QUERY_WAIT_TIMEOUT=7 I'm pulling pgBouncer from docker hub pgbouncer/pgbouncer:1.12.0 [https://www.pgbouncer.org/config.html#dangerous-timeouts] I don't know what impact setting TCP keepalive has when it looks like the database is just silently ignoreing connections. For the past week we've been running a build of Guacamole set with socketTimeout and haven't had any issues! I haven't done a test whether it's pgBouncer or the socketTimeout that really fixed the issue - I think both options can acheive it. But testing reducing the socketTimeout time does make it quicker to start working than the pgBouncer alone option. I've just submitted a pull request with the change to pass this through: [https://github.com/apache/guacamole-client/pull/488] POSTGRES_SOCKET_TIMEOUT=5 > An I/O error occurred while sending to the backend > -- > > Key: GUACAMOLE-919 > URL: https://issues.apache.org/jira/browse/GUACAMOLE-919 > Project: Guacamole > Issue Type: Bug > Components: guacamole-auth-jdbc-postgresql >Affects Versions: 1.0.0 >Reporter: Mechanix >Assignee: Nick Couchman >Priority: Minor > Attachments: image-2020-01-27-15-19-26-634.png > > > Hi, > we use guacamole with postgresql and openid extension. Guacamole and guacd is > deployed inside a k8s cluster. > For some reason, the authentication doesn't succeed sporadically; there is > only a blank page and this error message in the guacamole log: > *[pool-1-thread-1] WARN o.a.i.d.pooled.PooledDataSource - Execution of ping > query 'SELECT 1' failed: An I/O error occurred while sending to the backend.* > I suspect there is a weird timeout happening between guacamole and postgresql > but couldn't figure out why. > Any hints are much appreciated. Thanks > > -- This message was sent by Atlassian Jira (v8.3.4#803005)
[jira] [Commented] (GUACAMOLE-919) An I/O error occurred while sending to the backend
[
https://issues.apache.org/jira/browse/GUACAMOLE-919?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17072678#comment-17072678
]
Mechanix commented on GUACAMOLE-919:
[~DouglasHeriot] this is getting weird now. I didn't receive these log messages
before:
{code:java}
11:13:47.537 [pool-1-thread-1] DEBUG o.a.i.d.pooled.PooledDataSource - Checked
out connection 25479307 from pool.
11:13:47.537 [pool-1-thread-1] DEBUG o.a.i.d.pooled.PooledDataSource - Testing
connection 25479307 ..
11:24:02.557 [http-nio-8080-exec-22] DEBUG o.a.g.resource.ResourceServlet -
Resource not modified: "/app.js"
11:24:03.001 [http-nio-8080-exec-18] DEBUG org.jose4j.jwk.HttpsJwks -
Refreshing/loading JWKS from
https://sso.example.com/auth/realms/nv-services/protocol/openid-connect/certs
11:24:03.001 [http-nio-8080-exec-18] DEBUG org.jose4j.http.Get - HTTP GET of
https://sso.example.com/auth/realms/nv-services/protocol/openid-connect/certs
11:24:03.094 [http-nio-8080-exec-18] DEBUG org.jose4j.http.Get - read 3438
characters
11:24:03.095 [http-nio-8080-exec-18] DEBUG org.jose4j.http.Get - HTTP GET of
https://sso.example.com/auth/realms/nv-services/protocol/openid-connect/certs
returned SimpleResponse{statusCode=200, statusMessage='OK',
headers={null=[HTTP/1.1 200 OK], date=[Wed, 01 Apr 2020 11:24:03 GMT],
server=[openresty/1.15.8.1], set-cookie=[route=1585740244.076.329.181539;
Path=/; Secure; HttpOnly], content-length=[3438], vary=[Accept-Encoding],
connection=[keep-alive], content-type=[application/json],
cache-control=[no-cache], strict-transport-security=[max-age=15724800;
includeSubDomains]},
body='{"keys":[{"kid":"FsgfrnQ8F8D9-nXwkCUV8DX9h7EwtWfjxrKGYa398WA","kty":"RSA","alg":"RS256","use":"sig","n":"mcfeuGp1o5Eh_mWl4uJsRXVB53edq7JWO0qWPxdnG0FPct_QTQxm2b9ezalnEMuot0QklkzeJqajla0uR4sdjP7rs-4K3PJKDOdd3TUhV3RciLVCCCI4Flfeiu2mxWaoAFRQWMlvbHPolUBZX6I_WVRMxppUxTnuU28fy7xtBdDHeFjlmQy8Ds19AsF1XnMDu-YrJYjpt3YuqSVnKvkZb-3daPy-1nAPcXbAbnUszyuCWedDnBq0lYUWDIBSYeGKscEGyNQg1CC40duFmMba3GCXr9GWuZlrX5zw7u0-q1xHfj5TmYSce2fVGbob8-VcKPlBoJonA7_9LKZ8nW9otw","e":"AQAB","x5c":["MIICpTCCAY0CBgFvBIsQqTANBgkqhkiG9w0BAQsFADAWMRQwEgYDVQQDDAtudi1zZXJ2aWNlczAeFw0xOTEyMTQxMzEyMDBaFw0yOTEyMTQxMzEzNDBaMBYxFDASBgNVBAMMC252LXNlcnZpY2VzMIIBIjANBgkqhkiG9w0BAQEFAAOCAQ8AMIIBCgKCAQEAmcfeuGp1o5Eh/mWl4uJsRXVB53edq7JWO0qWPxdnG0FPct/QTQxm2b9ezalnEMuot0Qklkqajla0uR4sdjP7rs+4K3PJKDOdd3TUhV3RciLVCCCI4Flfeiu2mxWaoAFRQWMlvbHPolUBZX6I/WVRMxppUxTnuU28fy7xtBdDHeFjlmQy8Ds19AsF1XnMDu+YrJYjpt3YuqSVnKvkZb+3daPy+1nAPcXbAbnUszyuCWedDnBq0lYUWDIBSYeGKscEGyNQg1CC40duFmMba3GCXr9GWuZlrX5zw7u0+q1xHfj5TmYSce2fVGbob8+VcKPlBoJonA7/9LKZ8nW9otwIDAQABMA0GCSqGSIb3DQEBCwUAA4IBAQAXxGVh7FrWQJUbd+b5VRRx4rS468i0N1TT5ZsVx98yERCEBVaoBFnvvYF2n+pBVhRaqJ8iH0DfddYmWUxh5eDOQc53DNM2uMbmRT8HYad9E+pTH5m4MXbQpBssn86P8A/ia0G9CIfHX/dwinJtqwblEcY75VYYU0jV+ntndV96bozS/H0bpUVdYhBgpu5tpzikqBvZqALiunlkeeurcUnt+dyR6sRo5pOGGzYYuFxjQzqt8lEZsvp2UP6hJX+P4/L6A+NKJmMlmIyhX7twP5p7ebH8nTRKIyimSHDinKLiMZL4998CQdNF9s2nCHNoo8WaWFJcxt+QLLvBjnN00SzO"],"x5t":"ZvHZcCWdzzfBwiqsRvFjrVtlCgU","x5t#S256":"R8
[jira] [Commented] (GUACAMOLE-919) An I/O error occurred while sending to the backend
[ https://issues.apache.org/jira/browse/GUACAMOLE-919?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17072605#comment-17072605 ] Mechanix commented on GUACAMOLE-919: [~DouglasHeriot] Unfortunately I do not have access to the DB server to perform a tcpdump. However, you brought me to the idea to deploy pgBouncer in k8s and point guacamole to use it. I've started pgBouncer with: TCP_KEEPIDLE 7200 TCP_KEEPALIVE 1 But the issue persists. When I receive the blank page in guacamole, I do not see any db requests in pgBouncer. It looks like guacamole doesn't even try to connect to the db. Any other options I need to take into consideration? > An I/O error occurred while sending to the backend > -- > > Key: GUACAMOLE-919 > URL: https://issues.apache.org/jira/browse/GUACAMOLE-919 > Project: Guacamole > Issue Type: Bug > Components: guacamole-auth-jdbc-postgresql >Affects Versions: 1.0.0 >Reporter: Mechanix >Assignee: Nick Couchman >Priority: Minor > Attachments: image-2020-01-27-15-19-26-634.png > > > Hi, > we use guacamole with postgresql and openid extension. Guacamole and guacd is > deployed inside a k8s cluster. > For some reason, the authentication doesn't succeed sporadically; there is > only a blank page and this error message in the guacamole log: > *[pool-1-thread-1] WARN o.a.i.d.pooled.PooledDataSource - Execution of ping > query 'SELECT 1' failed: An I/O error occurred while sending to the backend.* > I suspect there is a weird timeout happening between guacamole and postgresql > but couldn't figure out why. > Any hints are much appreciated. Thanks > > -- This message was sent by Atlassian Jira (v8.3.4#803005)
[jira] [Commented] (GUACAMOLE-919) An I/O error occurred while sending to the backend
[ https://issues.apache.org/jira/browse/GUACAMOLE-919?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17065432#comment-17065432 ] Douglas Heriot commented on GUACAMOLE-919: -- I've also found this bug in the old IBATIS bug tracker IBATIS-449 It was never resolved. > An I/O error occurred while sending to the backend > -- > > Key: GUACAMOLE-919 > URL: https://issues.apache.org/jira/browse/GUACAMOLE-919 > Project: Guacamole > Issue Type: Bug > Components: guacamole-auth-jdbc-postgresql >Affects Versions: 1.0.0 >Reporter: Mechanix >Assignee: Nick Couchman >Priority: Minor > Attachments: image-2020-01-27-15-19-26-634.png > > > Hi, > we use guacamole with postgresql and openid extension. Guacamole and guacd is > deployed inside a k8s cluster. > For some reason, the authentication doesn't succeed sporadically; there is > only a blank page and this error message in the guacamole log: > *[pool-1-thread-1] WARN o.a.i.d.pooled.PooledDataSource - Execution of ping > query 'SELECT 1' failed: An I/O error occurred while sending to the backend.* > I suspect there is a weird timeout happening between guacamole and postgresql > but couldn't figure out why. > Any hints are much appreciated. Thanks > > -- This message was sent by Atlassian Jira (v8.3.4#803005)
[jira] [Commented] (GUACAMOLE-919) An I/O error occurred while sending to the backend
[
https://issues.apache.org/jira/browse/GUACAMOLE-919?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17064509#comment-17064509
]
Douglas Heriot commented on GUACAMOLE-919:
--
Using pgbouncer seems to have solved the issue for me. It's interesting I can
see in the pgbouncer logs from a few hours after using Guacamole:
{code:java}
2020-03-22 16:40:42.176 UTC [1] LOG S-0x562e8b466510:
guacamole/guacamole@10.10.0.236:5432 closing because: server conn crashed?
(age=12690s)2020-03-22 16:40:42.176 UTC [1] LOG C-0x562e8b403b70:
guacamole/guacamole@172.19.0.4:36364 closing because: server conn crashed?
(age=12336s)2020-03-22 16:40:42.176 UTC [1] WARNING C-0x562e8b403b70:
guacamole/guacamole@172.19.0.4:36364 pooler error: server conn crashed?
{code}
A quick Google search for that error seems to suggest this can be replicated by
unplugging a network cable between application and database (pretty much what
we're seeing on the tcpdump - no replies from database).
Adding the defaultNetworkTimeout option sounds like a sensible fix to handle
that case.
> An I/O error occurred while sending to the backend
> --
>
> Key: GUACAMOLE-919
> URL: https://issues.apache.org/jira/browse/GUACAMOLE-919
> Project: Guacamole
> Issue Type: Bug
> Components: guacamole-auth-jdbc-postgresql
>Affects Versions: 1.0.0
>Reporter: Mechanix
>Assignee: Nick Couchman
>Priority: Minor
> Attachments: image-2020-01-27-15-19-26-634.png
>
>
> Hi,
> we use guacamole with postgresql and openid extension. Guacamole and guacd is
> deployed inside a k8s cluster.
> For some reason, the authentication doesn't succeed sporadically; there is
> only a blank page and this error message in the guacamole log:
> *[pool-1-thread-1] WARN o.a.i.d.pooled.PooledDataSource - Execution of ping
> query 'SELECT 1' failed: An I/O error occurred while sending to the backend.*
> I suspect there is a weird timeout happening between guacamole and postgresql
> but couldn't figure out why.
> Any hints are much appreciated. Thanks
>
>
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
[jira] [Commented] (GUACAMOLE-919) An I/O error occurred while sending to the backend
[ https://issues.apache.org/jira/browse/GUACAMOLE-919?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17064279#comment-17064279 ] Douglas Heriot commented on GUACAMOLE-919: -- I got a helpful response on the myBatis-user mailing list. The defaultStatementTimeout setting I was looking at probably won't be helpful. It operates at a higher-level and would not count network socket timeouts. There is a different setting defaultNetworkTimeout that we should try instead. [https://groups.google.com/forum/#!topic/mybatis-user/o8Ib0SUXOU0] Before I do a test build of guacamole with that option enabled, I've also tried putting pgBouncer in front of guacamole-client. I'll have to wait a few hours to see if it's solved the problem for me, but it's got a few low-level network settings easily exposed to adjust different timeouts and settings: [https://www.pgbouncer.org/config.html#low-level-network-settings] [~mechanix] it would be interesting if you can reproduce the failure state easily, then do a tcpdump and check netstat to see what's happening on the wire talking to the database. And since you've got your database on bare-metal, if you could check what you see both from the perspective of the guacamole container, and from the database itself to try and work out where the issue is? > An I/O error occurred while sending to the backend > -- > > Key: GUACAMOLE-919 > URL: https://issues.apache.org/jira/browse/GUACAMOLE-919 > Project: Guacamole > Issue Type: Bug > Components: guacamole-auth-jdbc-postgresql >Affects Versions: 1.0.0 >Reporter: Mechanix >Assignee: Nick Couchman >Priority: Minor > Attachments: image-2020-01-27-15-19-26-634.png > > > Hi, > we use guacamole with postgresql and openid extension. Guacamole and guacd is > deployed inside a k8s cluster. > For some reason, the authentication doesn't succeed sporadically; there is > only a blank page and this error message in the guacamole log: > *[pool-1-thread-1] WARN o.a.i.d.pooled.PooledDataSource - Execution of ping > query 'SELECT 1' failed: An I/O error occurred while sending to the backend.* > I suspect there is a weird timeout happening between guacamole and postgresql > but couldn't figure out why. > Any hints are much appreciated. Thanks > > -- This message was sent by Atlassian Jira (v8.3.4#803005)
[jira] [Commented] (GUACAMOLE-919) An I/O error occurred while sending to the backend
[
https://issues.apache.org/jira/browse/GUACAMOLE-919?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17063194#comment-17063194
]
Mechanix commented on GUACAMOLE-919:
[~DouglasHeriot]thank you very much for this thorough investigation.
{quote}I'm guessing that AWS RDS is just dropping long-lived idle connections
without closing them? Or it could be some other network configuration issue we
need to solve?
{quote}
Our PostgresDB is running outside k8s on bare metal though.
I'm looking forward to see this issue fix. If you need a testing hand, let me
know.
> An I/O error occurred while sending to the backend
> --
>
> Key: GUACAMOLE-919
> URL: https://issues.apache.org/jira/browse/GUACAMOLE-919
> Project: Guacamole
> Issue Type: Bug
> Components: guacamole-auth-jdbc-postgresql
>Affects Versions: 1.0.0
>Reporter: Mechanix
>Assignee: Nick Couchman
>Priority: Minor
> Attachments: image-2020-01-27-15-19-26-634.png
>
>
> Hi,
> we use guacamole with postgresql and openid extension. Guacamole and guacd is
> deployed inside a k8s cluster.
> For some reason, the authentication doesn't succeed sporadically; there is
> only a blank page and this error message in the guacamole log:
> *[pool-1-thread-1] WARN o.a.i.d.pooled.PooledDataSource - Execution of ping
> query 'SELECT 1' failed: An I/O error occurred while sending to the backend.*
> I suspect there is a weird timeout happening between guacamole and postgresql
> but could figure out why.
> Any hints are much appreciated. Thanks
>
>
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
[jira] [Commented] (GUACAMOLE-919) An I/O error occurred while sending to the backend
[
https://issues.apache.org/jira/browse/GUACAMOLE-919?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17062493#comment-17062493
]
Douglas Heriot commented on GUACAMOLE-919:
--
Ok, so today I had some time to look into this again. The only way I've found
to reproduce the issue is to wait a few hours from when guacamole was last used
by anyone.
Running netstat in the guacamole container just after a blocked request shows
there's some data in the Send-Q of the Postgres connection that hasn't been
acknowledged. Doing a tcpdump confirmed this - the query is sent and then TCP
retransmitted as there's no response from the database.
{code:java}
# nsenter -t 32264 -n netstat -n
Active Internet connections (w/o servers)
Proto Recv-Q Send-Q Local Address Foreign Address State
tcp0 52 172.17.0.9:5441410.10.0.236:5432 ESTABLISHED
tcp0 0 172.19.0.3:8080 172.19.0.4:41012TIME_WAIT
tcp0 0 172.17.0.9:5443610.10.0.236:5432 ESTABLISHED
tcp0 0 172.19.0.3:8080 172.19.0.4:40988TIME_WAIT
tcp0 0 172.19.0.3:8080 172.19.0.4:41002ESTABLISHED
tcp0 0 172.19.0.3:8080 172.19.0.4:41008ESTABLISHED
tcp0 0 172.19.0.3:8080 172.19.0.4:40986TIME_WAIT
tcp0 0 172.19.0.3:8080 172.19.0.4:41010
TIME_WAIT{code}
I'm guessing that AWS RDS is just dropping long-lived idle connections without
closing them? Or it could be some other network configuration issue we need to
solve?
With this clearer picture of what's happening, I had a closer look at how it's
being handled. I've not yet run Guacamole in a debugger, but reading through
code I think I've found where this happens in the MyBatis library.
There's a few interesting log messages (from initial post) to show what code
path is being taken. The first interesting one is "Testing connection" that
happens on the page requests where nothing loads.
Then when Guacamole starts working again, we see log messages like "Execution
of ping query 'SELECT 1' failed: An I/O error occurred while sending to the
backend".
These seem to come from here:
[https://github.com/mybatis/mybatis-3/blob/cb11469b3118c5d1d0501c489dcfe196d7c8568d/src/main/java/org/apache/ibatis/datasource/pooled/PooledDataSource.java#L555]
It looks like when the Postgres connection is returned from the connection
pool, if it's old then it is tested with SELECT 1 before its used. In the case
that the TCP connection is still in ESTABLISHED state but the database is not
acknowledging any TCP segments, we hang here indefinitely. I haven't caught an
example of when Guacamole starts working again, but I guess the TCP connections
finally are closed or change to a different state where an IO error is actually
returned, so that MyBatis can go fetch another connection.
How do we fix this? I've got an idea I'm about to try. MyBatis has a setting
"defaultStatementTimeout" that defaults to null (no timeout).
[https://mybatis.org/mybatis-3/configuration.html]
I think this can be set with the
"mybatis.configuration.defaultStatementTimeout" configuration setting
[https://github.com/mybatis/guice/blob/master/src/main/java/org/mybatis/guice/configuration/ConfigurationProvider.java#L86]
I'll have a go at adding this in and making it configurable. I'll also post on
the MyBatis mailing list asking what they recommend here - rather than setting
the defaultStatementTimeout that applies to all statements, there's also a
"poolTimeToWait" setting that's supposed to be a timeout for getting
connections, however it currently only applies to opening new connections, not
pinging existing ones.
The other thing I'm going to try to resolve this - use pgBouncer as a proxy on
the same host as guacamole, to hopefully deal with connections timeout out in a
better way. I'm not sure yet whether that will help or how it handles this case.
> An I/O error occurred while sending to the backend
> --
>
> Key: GUACAMOLE-919
> URL: https://issues.apache.org/jira/browse/GUACAMOLE-919
> Project: Guacamole
> Issue Type: Bug
> Components: guacamole-auth-jdbc-postgresql
>Affects Versions: 1.0.0
>Reporter: Mechanix
>Assignee: Nick Couchman
>Priority: Minor
> Attachments: image-2020-01-27-15-19-26-634.png
>
>
> Hi,
> we use guacamole with postgresql and openid extension. Guacamole and guacd is
> deployed inside a k8s cluster.
> For some reason, the authentication doesn't succeed sporadically; there is
> only a blank page and this error message in the guacamole log:
> *[pool-1-thread-1] WARN o.a.i.d.pooled.PooledDataSource - Execution of ping
> query 'SELECT 1' failed: An
[jira] [Commented] (GUACAMOLE-919) An I/O error occurred while sending to the backend
[
https://issues.apache.org/jira/browse/GUACAMOLE-919?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17026456#comment-17026456
]
Mike Jumper commented on GUACAMOLE-919:
---
{quote}
I have to say I disagree with this being a "minor" issue - it's preventing us
from using Guacamole at all!
{quote}
That may be so, but it doesn't appear to be encountered by most users. I would
definitely agree that "minor" is incorrect if this were an issue for any user
of PostgreSQL, but so far that doesn't seem to be the case.
Given that others are not encountering this, it also seems likely that there
may be a configuration change which allows things to work as expected, which
would mean any users that are affected would have a workaround in the meantime.
{quote}
It also seems like a regression - when running 1.0.0 it works, but in the
1.1.0-RC1 it doesn't work.
{quote}
This issue notes "1.0.0" as the affected version. Handling of database
connections has also not been touched between 1.0.0 and 1.1.0. Given that the
original reporter encountered this with 1.0.0, and given the nature of the
changes made to the database auth between the versions, this does not seem to
be a regression. If you are seeing things work with 1.0.0 but fail with 1.1.0,
I suggest looking elsewhere for other environmental differences which may have
taken effect at the same time.
> An I/O error occurred while sending to the backend
> --
>
> Key: GUACAMOLE-919
> URL: https://issues.apache.org/jira/browse/GUACAMOLE-919
> Project: Guacamole
> Issue Type: Bug
> Components: guacamole-auth-jdbc-postgresql
>Affects Versions: 1.0.0
>Reporter: Mechanix
>Assignee: Nick Couchman
>Priority: Minor
> Attachments: image-2020-01-27-15-19-26-634.png
>
>
> Hi,
> we use guacamole with postgresql and openid extension. Guacamole and guacd is
> deployed inside a k8s cluster.
> For some reason, the authentication doesn't succeed sporadically; there is
> only a blank page and this error message in the guacamole log:
> *[pool-1-thread-1] WARN o.a.i.d.pooled.PooledDataSource - Execution of ping
> query 'SELECT 1' failed: An I/O error occurred while sending to the backend.*
> I suspect there is a weird timeout happening between guacamole and postgresql
> but could figure out why.
> Any hints are much appreciated. Thanks
>
>
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
[jira] [Commented] (GUACAMOLE-919) An I/O error occurred while sending to the backend
[ https://issues.apache.org/jira/browse/GUACAMOLE-919?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17026455#comment-17026455 ] Nick Couchman commented on GUACAMOLE-919: - [~DouglasHeriot]: For you, yes, this is a show-stopper. The reason it has been classified as minor is that we only have two people reporting it at this time, and we don't really even know exactly what's causing it. We've identified a couple of possibilities for what might fix it, but, as far as Guacamole is concerned, it isn't a bug, it's an enhancement to overcome what we suspect is happening in a couple of specific situations related to timeout/latency between client and DB. It isn't being widely reported throughout the community on either 1.0.0 or 1.1.0, it seems to be pretty limited, so that's my rationale for having classified it as minor. As far as it being a regression - I'm skeptical of that. It is very interesting to me that it works for you in 1.0.0 and not in 1.1.0, but if you look at the original reported issue, it is against version 1.0.0, not 1.1.0-RC1. I don't know exactly what to make of that, but the fact that it is being reported by you and the original reporter in two different versions makes me think that it isn't a regression between those two versions, it's something else. Is your 1.1.0-RC1 deployment running on exactly the same systems as 1.0.0, and using exactly the same Postgres server, so that the only difference between the two is the Guacamole version? And you're saying that, if you go back to 1.0.0 right now (in the environment where 1.1.0-RC1 does ont work), that everything works as expected? > An I/O error occurred while sending to the backend > -- > > Key: GUACAMOLE-919 > URL: https://issues.apache.org/jira/browse/GUACAMOLE-919 > Project: Guacamole > Issue Type: Bug > Components: guacamole-auth-jdbc-postgresql >Affects Versions: 1.0.0 >Reporter: Mechanix >Assignee: Nick Couchman >Priority: Minor > Attachments: image-2020-01-27-15-19-26-634.png > > > Hi, > we use guacamole with postgresql and openid extension. Guacamole and guacd is > deployed inside a k8s cluster. > For some reason, the authentication doesn't succeed sporadically; there is > only a blank page and this error message in the guacamole log: > *[pool-1-thread-1] WARN o.a.i.d.pooled.PooledDataSource - Execution of ping > query 'SELECT 1' failed: An I/O error occurred while sending to the backend.* > I suspect there is a weird timeout happening between guacamole and postgresql > but could figure out why. > Any hints are much appreciated. Thanks > > -- This message was sent by Atlassian Jira (v8.3.4#803005)
[jira] [Commented] (GUACAMOLE-919) An I/O error occurred while sending to the backend
[ https://issues.apache.org/jira/browse/GUACAMOLE-919?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17026436#comment-17026436 ] Douglas Heriot commented on GUACAMOLE-919: -- I have to say I disagree with this being a "minor" issue - it's preventing us from using Guacamole at all! It also seems like a regression - when running 1.0.0 it works, but in the 1.1.0-RC1 it doesn't work. (We can't use 1.0.0 because it doesn't support using OpenID for authentication, and Postgres for assigning groups to access groups/connections) > An I/O error occurred while sending to the backend > -- > > Key: GUACAMOLE-919 > URL: https://issues.apache.org/jira/browse/GUACAMOLE-919 > Project: Guacamole > Issue Type: Bug > Components: guacamole-auth-jdbc-postgresql >Affects Versions: 1.0.0 >Reporter: Mechanix >Assignee: Nick Couchman >Priority: Minor > Attachments: image-2020-01-27-15-19-26-634.png > > > Hi, > we use guacamole with postgresql and openid extension. Guacamole and guacd is > deployed inside a k8s cluster. > For some reason, the authentication doesn't succeed sporadically; there is > only a blank page and this error message in the guacamole log: > *[pool-1-thread-1] WARN o.a.i.d.pooled.PooledDataSource - Execution of ping > query 'SELECT 1' failed: An I/O error occurred while sending to the backend.* > I suspect there is a weird timeout happening between guacamole and postgresql > but could figure out why. > Any hints are much appreciated. Thanks > > -- This message was sent by Atlassian Jira (v8.3.4#803005)
[jira] [Commented] (GUACAMOLE-919) An I/O error occurred while sending to the backend
[ https://issues.apache.org/jira/browse/GUACAMOLE-919?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17024152#comment-17024152 ] Mechanix commented on GUACAMOLE-919: [~mjumper] thanks for confirmation [~vnick]I think you´re right with this approach. The original postgres jdbc driver has a lot of options regarding to connection timeouts ([https://jdbc.postgresql.org/documentation/head/connect.html#connection-parameters). |https://jdbc.postgresql.org/documentation/head/connect.html#connection-parameters)] specially *connectTimeout* and *socketTimeout* I guess it would help if we could pass those parameters in guacamole.properties. If you have questions about my setup, please reach out to me. > An I/O error occurred while sending to the backend > -- > > Key: GUACAMOLE-919 > URL: https://issues.apache.org/jira/browse/GUACAMOLE-919 > Project: Guacamole > Issue Type: Bug > Components: guacamole-auth-jdbc-postgresql >Affects Versions: 1.0.0 >Reporter: Mechanix >Assignee: Nick Couchman >Priority: Minor > Attachments: image-2020-01-27-15-19-26-634.png > > > Hi, > we use guacamole with postgresql and openid extension. Guacamole and guacd is > deployed inside a k8s cluster. > For some reason, the authentication doesn't succeed sporadically; there is > only a blank page and this error message in the guacamole log: > *[pool-1-thread-1] WARN o.a.i.d.pooled.PooledDataSource - Execution of ping > query 'SELECT 1' failed: An I/O error occurred while sending to the backend.* > I suspect there is a weird timeout happening between guacamole and postgresql > but could figure out why. > Any hints are much appreciated. Thanks > > -- This message was sent by Atlassian Jira (v8.3.4#803005)
[jira] [Commented] (GUACAMOLE-919) An I/O error occurred while sending to the backend
[ https://issues.apache.org/jira/browse/GUACAMOLE-919?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17024126#comment-17024126 ] Mike Jumper commented on GUACAMOLE-919: --- It's also possible there may be a way to configure the connection pool to attempt to keep the connections alive with more frequent pings. It may be that the database is timing out large numbers of connections within the pool, causing delays and errors when attempts to query the database end up needing to iterate through the entire pool of dead connections before it's finally emptied and new connections are created. I don't see this in my own deployment, which uses PostgreSQL, but there may be (uncommon?) configuration or environmental differences that cause this to occur. > An I/O error occurred while sending to the backend > -- > > Key: GUACAMOLE-919 > URL: https://issues.apache.org/jira/browse/GUACAMOLE-919 > Project: Guacamole > Issue Type: Bug > Components: guacamole-auth-jdbc-postgresql >Affects Versions: 1.0.0 >Reporter: Mechanix >Assignee: Nick Couchman >Priority: Minor > Attachments: image-2020-01-27-15-19-26-634.png > > > Hi, > we use guacamole with postgresql and openid extension. Guacamole and guacd is > deployed inside a k8s cluster. > For some reason, the authentication doesn't succeed sporadically; there is > only a blank page and this error message in the guacamole log: > *[pool-1-thread-1] WARN o.a.i.d.pooled.PooledDataSource - Execution of ping > query 'SELECT 1' failed: An I/O error occurred while sending to the backend.* > I suspect there is a weird timeout happening between guacamole and postgresql > but could figure out why. > Any hints are much appreciated. Thanks > > -- This message was sent by Atlassian Jira (v8.3.4#803005)
[jira] [Commented] (GUACAMOLE-919) An I/O error occurred while sending to the backend
[ https://issues.apache.org/jira/browse/GUACAMOLE-919?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17024123#comment-17024123 ] Nick Couchman commented on GUACAMOLE-919: - [~mechanix] [~DouglasHeriot]: Hey, guys, While I do not doubt that you're running into problems, I do not believe the issues you are seeing are a bug in the Guacamole code. I think it's much more likely that they occur somewhere in the JDBC code, and are due to timeout and/or latency issues within the JDBC connections. This seems particularly likely based on [~DouglasHeriot]'s information about the DB being hosted over a DX link between an on-premise install of Guacamole Client (Tomcat) and a cloud-hosted database. That said, it seems like the best course of action would be to re-classify this as a feature request for the ability to configure the JDBC timeout. It looks like the MyBastis code (what handles much of Guacamole Client's JDBC support) allows you to configure timeouts in various ways, and this might help situations where the database is slower to respond than is normally expected. I'll try to see if I can reproduce the issues you are seeing, and put together a PR that you can try out that allows for configuring one or more timeout values. > An I/O error occurred while sending to the backend > -- > > Key: GUACAMOLE-919 > URL: https://issues.apache.org/jira/browse/GUACAMOLE-919 > Project: Guacamole > Issue Type: Bug > Components: guacamole-auth-jdbc-postgresql >Affects Versions: 1.0.0 >Reporter: Mechanix >Priority: Major > Attachments: image-2020-01-27-15-19-26-634.png > > > Hi, > we use guacamole with postgresql and openid extension. Guacamole and guacd is > deployed inside a k8s cluster. > For some reason, the authentication doesn't succeed sporadically; there is > only a blank page and this error message in the guacamole log: > *[pool-1-thread-1] WARN o.a.i.d.pooled.PooledDataSource - Execution of ping > query 'SELECT 1' failed: An I/O error occurred while sending to the backend.* > I suspect there is a weird timeout happening between guacamole and postgresql > but could figure out why. > Any hints are much appreciated. Thanks > > -- This message was sent by Atlassian Jira (v8.3.4#803005)
[jira] [Commented] (GUACAMOLE-919) An I/O error occurred while sending to the backend
[
https://issues.apache.org/jira/browse/GUACAMOLE-919?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17024076#comment-17024076
]
Douglas Heriot commented on GUACAMOLE-919:
--
[~mechanix] I have exactly this issue too! In our case we're running guacamole
inside Docker on an on-prem ESXI cluster. Postgres is hosted in AWS RDS
connected over AWS Direct Connect. We use the openid plugin for auth against
Microsoft365.
Same symptoms - get the WARN about SELECT 1 failing, and then {{ DEBUG
o.a.i.t.jdbc.JdbcTransaction - Opening JDBC Connection {color:#ff}*(blank
page - browser refresh page)*{color}}}
The fix has been to manually reboot guacamole-client when this happens (not
fun).
We're running a recent build of 1.1.0, and will update to the 1.1.0 RC1 now.
There's a pretty error message that comes up:
!image-2020-01-27-15-19-26-634.png|width=446,height=174!
I've noticed in the web inspector that it's specifically the API call to
/api/tokens that's timing out.
> An I/O error occurred while sending to the backend
> --
>
> Key: GUACAMOLE-919
> URL: https://issues.apache.org/jira/browse/GUACAMOLE-919
> Project: Guacamole
> Issue Type: Bug
> Components: guacamole-auth-jdbc-postgresql
>Affects Versions: 1.0.0
>Reporter: Mechanix
>Priority: Major
> Attachments: image-2020-01-27-15-19-26-634.png
>
>
> Hi,
> we use guacamole with postgresql and openid extension. Guacamole and guacd is
> deployed inside a k8s cluster.
> For some reason, the authentication doesn't succeed sporadically; there is
> only a blank page and this error message in the guacamole log:
> *[pool-1-thread-1] WARN o.a.i.d.pooled.PooledDataSource - Execution of ping
> query 'SELECT 1' failed: An I/O error occurred while sending to the backend.*
> I suspect there is a weird timeout happening between guacamole and postgresql
> but could figure out why.
> Any hints are much appreciated. Thanks
>
>
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
[jira] [Commented] (GUACAMOLE-919) An I/O error occurred while sending to the backend
[
https://issues.apache.org/jira/browse/GUACAMOLE-919?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17011779#comment-17011779
]
Mechanix commented on GUACAMOLE-919:
[~mjumper] thanks for your reply. I've enabled debug logs on the guacamole
deployment:
{{12:16:16.156 [http-nio-8080-exec-8] DEBUG o.a.g.resource.ResourceServlet -
Resource not modified: "/app.css"}}
{{12:16:16.167 [http-nio-8080-exec-7] DEBUG o.a.g.resource.ResourceServlet -
Resource not modified: "/app.js"}}
{{12:16:16.361 [http-nio-8080-exec-6] DEBUG o.a.i.t.jdbc.JdbcTransaction -
Opening JDBC Connection}}
{{12:16:16.361 [http-nio-8080-exec-6] DEBUG o.a.i.d.pooled.PooledDataSource -
Checked out connection 52832043 from pool.}}
{{12:16:16.361 [http-nio-8080-exec-6] DEBUG o.a.i.d.pooled.PooledDataSource -
Testing connection 52832043 ...}}
{{12:16:16.471 [http-nio-8080-exec-9] DEBUG o.a.g.resource.ResourceServlet -
Resource not modified: "/translations/en.json"}}
{{12:16:18.334 [http-nio-8080-exec-5] DEBUG o.a.i.t.jdbc.JdbcTransaction -
Opening JDBC Connection *(blank page - browser refresh page)*}}
{{12:16:19.199 [http-nio-8080-exec-9] DEBUG o.a.i.t.jdbc.JdbcTransaction -
Opening JDBC Connection *(blank page - browser refresh page)*}}
{{12:16:19.376 [http-nio-8080-exec-7] DEBUG o.a.i.t.jdbc.JdbcTransaction -
Opening JDBC Connection *(blank page - browser refresh page)*}}
{{12:16:19.609 [http-nio-8080-exec-1] DEBUG o.a.i.t.jdbc.JdbcTransaction -
Opening JDBC Connection *(blank page - browser refresh page)*}}
{{12:16:19.811 [http-nio-8080-exec-3] DEBUG o.a.i.t.jdbc.JdbcTransaction -
Opening JDBC Connection *(blank page - browser refresh page)***}}
{{12:17:12.064 [pool-1-thread-1] DEBUG o.a.g.rest.auth.HashTokenSessionMap -
Checking for expired sessions...}}
{{12:17:12.064 [pool-1-thread-1] DEBUG o.a.g.rest.auth.HashTokenSessionMap -
Session check completed in 0 ms.}}
{{12:17:12.809 [http-nio-8080-exec-8] DEBUG o.a.i.t.jdbc.JdbcTransaction -
Opening JDBC Connection}}
{{12:18:12.064 [pool-1-thread-1] DEBUG o.a.g.rest.auth.HashTokenSessionMap -
Checking for expired sessions...}}
{{12:18:12.064 [pool-1-thread-1] DEBUG o.a.g.rest.auth.HashTokenSessionMap -
Session check completed in 0 ms.}}
{{12:31:52.793 [http-nio-8080-exec-6] WARN o.a.i.d.pooled.PooledDataSource -
Execution of ping query 'SELECT 1' failed: An I/O error occurred while sending
to the backend.}}
{{12:31:52.794 [http-nio-8080-exec-6] DEBUG o.a.i.d.pooled.PooledDataSource -
Connection 52832043 is BAD: An I/O error occurred while sending to the
backend.}}
{{12:31:52.794 [http-nio-8080-exec-6] DEBUG o.a.i.d.pooled.PooledDataSource - A
bad connection (52832043) was returned from the pool, getting another
connection.}}
{{12:31:52.794 [http-nio-8080-exec-6] DEBUG o.a.i.d.pooled.PooledDataSource -
Checked out connection 699492272 from pool.}}
{{12:31:52.794 [http-nio-8080-exec-6] DEBUG o.a.i.d.pooled.PooledDataSource -
Testing connection 699492272 ...}}
{{12:32:12.064 [pool-1-thread-1] DEBUG o.a.g.rest.auth.HashTokenSessionMap -
Checking for expired sessions...}}
{{12:32:12.064 [pool-1-thread-1] DEBUG o.a.g.rest.auth.HashTokenSessionMap -
Session check completed in 0 ms.}}
{{12:33:12.064 [pool-1-thread-1] DEBUG o.a.g.rest.auth.HashTokenSessionMap -
Checking for expired sessions...}}
{{12:33:12.064 [pool-1-thread-1] DEBUG o.a.g.rest.auth.HashTokenSessionMap -
Session check completed in 0 ms.}}
{{12:34:12.064 [pool-1-thread-1] DEBUG o.a.g.rest.auth.HashTokenSessionMap -
Checking for expired sessions...}}
{{12:34:12.064 [pool-1-thread-1] DEBUG o.a.g.rest.auth.HashTokenSessionMap -
Session check completed in 0 ms.}}
{{12:34:36.385 [http-nio-8080-exec-4] DEBUG o.a.g.resource.ResourceServlet -
Resource not modified: "/app.css"}}
{{12:34:36.393 [http-nio-8080-exec-2] DEBUG o.a.g.resource.ResourceServlet -
Resource not modified: "/app.js"}}
{{12:34:36.489 [http-nio-8080-exec-10] DEBUG o.a.i.t.jdbc.JdbcTransaction -
Opening JDBC Connection}}
{{12:34:36.563 [http-nio-8080-exec-2] DEBUG o.a.g.resource.ResourceServlet -
Resource not modified: "/translations/en.json"}}
At this point every client gets a blank page. The only thing that helps is
restarting the guacamole deployment.
Funny thing though: the blank page has following source:
{{}}{{}}
{{}}
{{}}
{{ }}
{{ }}
{{ }}
{{ }}
{{ }}
{{ }}
{{ }}
{{ }}
{{ }}
{{ }}
{{ }}
{{ }}
{{ }}{{}}
{{ }}
{{ }}
{{ }}
{{ }}
{{ }}
{{ }}
{{ }}
{{ }}
{{ }}
{{ }}{{}}
{{ }}{{}}
{{ }}{{}}
{{ }}
{{ }}{{}}
{{ }}
{{ }}
{{ }}{{}}
{{ }}
{{ }}
{{ }}
{{ }}{{}}
{{ }}
{{ }}
{{ }}{{}}
{{ }}{{}}
{{ }}{{}}
{{}}
> An I/O error occurred while sending to the backend
> --
>
> Key: GUACAMOLE-919
> URL: https://issues.apache.org/jira/browse/GUACAMOLE-919
> Project: Guacamole
> Issue Type: Bug
> Components: guacamole-auth-jdbc-postgresql
>Affects
[jira] [Commented] (GUACAMOLE-919) An I/O error occurred while sending to the backend
[ https://issues.apache.org/jira/browse/GUACAMOLE-919?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17010865#comment-17010865 ] Mike Jumper commented on GUACAMOLE-919: --- Is there a roughly consistent period of time between each first occurrence of the error and the most recent successful auth attempt that precedes it? Are there any other errors in the logs at the time that authentication fails? > An I/O error occurred while sending to the backend > -- > > Key: GUACAMOLE-919 > URL: https://issues.apache.org/jira/browse/GUACAMOLE-919 > Project: Guacamole > Issue Type: Bug > Components: guacamole-auth-jdbc-postgresql >Affects Versions: 1.0.0 >Reporter: Mechanix >Priority: Major > > Hi, > we use guacamole with postgresql and openid extension. Guacamole and guacd is > deployed inside a k8s cluster. > For some reason, the authentication doesn't succeed sporadically; there is > only a blank page and this error message in the guacamole log: > *[pool-1-thread-1] WARN o.a.i.d.pooled.PooledDataSource - Execution of ping > query 'SELECT 1' failed: An I/O error occurred while sending to the backend.* > I suspect there is a weird timeout happening between guacamole and postgresql > but could figure out why. > Any hints are much appreciated. Thanks > > -- This message was sent by Atlassian Jira (v8.3.4#803005)
