On Mon, Sep 13, 2021 at 11:13 AM Regev Batchen <[email protected]> wrote:
> Hello team, > can somone please help me ? > > I upgraded docker to version 20.10.8 and docker-compose version 1.29.2 > and also guacd + guacamole version to latest version 1.3.0 > > Out of all my containers only guacamole gets stuck > this is what i see on kern.log: > > Sep 13 14:28:44 ansible kernel: [1548303.041290] br-4260ec4ed3f1: port > 19(veth842fd2a) entered disabled state > Sep 13 14:28:44 ansible kernel: [1548303.041444] veth8c74c8b: renamed from > eth0 > Sep 13 14:28:44 ansible kernel: [1548303.103365] br-4260ec4ed3f1: port > 19(veth842fd2a) entered disabled state > Sep 13 14:28:44 ansible kernel: [1548303.114983] device veth842fd2a left > promiscuous mode > Sep 13 14:28:44 ansible kernel: [1548303.114987] br-4260ec4ed3f1: port > 19(veth842fd2a) entered disabled state > Sep 13 14:28:45 ansible kernel: [1548303.703639] br-4260ec4ed3f1: port > 11(veth6370b5e) entered disabled state > Sep 13 14:28:45 ansible kernel: [1548303.703767] veth3a75fd3: renamed from > eth0 > Sep 13 14:28:45 ansible kernel: [1548303.769807] br-4260ec4ed3f1: port > 11(veth6370b5e) entered disabled state > Sep 13 14:28:45 ansible kernel: [1548303.778901] device veth6370b5e left > promiscuous mode > Sep 13 14:28:45 ansible kernel: [1548303.778906] br-4260ec4ed3f1: port > 11(veth6370b5e) entered disabled state > Sep 13 14:28:45 ansible kernel: [1548304.023824] br-4260ec4ed3f1: port > 11(veth0e30632) entered blocking state > Sep 13 14:28:45 ansible kernel: [1548304.023826] br-4260ec4ed3f1: port > 11(veth0e30632) entered disabled state > Sep 13 14:28:45 ansible kernel: [1548304.023993] device veth0e30632 > entered promiscuous mode > Sep 13 14:28:45 ansible kernel: [1548304.024117] IPv6: > ADDRCONF(NETDEV_UP): veth0e30632: link is not ready > Sep 13 14:28:45 ansible kernel: [1548304.024125] br-4260ec4ed3f1: port > 11(veth0e30632) entered blocking state > Sep 13 14:28:45 ansible kernel: [1548304.024127] br-4260ec4ed3f1: port > 11(veth0e30632) entered forwarding state > Sep 13 14:28:45 ansible kernel: [1548304.066552] br-4260ec4ed3f1: port > 11(veth0e30632) entered disabled state > Sep 13 14:28:46 ansible kernel: [1548305.059156] eth0: renamed from > veth0b98f17 > Sep 13 14:28:46 ansible kernel: [1548305.091017] IPv6: > ADDRCONF(NETDEV_CHANGE): veth0e30632: link becomes ready > > guacd : > > guacd_1 | 2021-09-13T14:15:42.167400545Z guacd[15338]: DEBUG: > guac_rdpdr_fs_process_create: [file_id=-2] desired_access=0x80, > file_attributes=0x0, create_disposition=0x1, create_options=0x1, path="" > guacd_1 | 2021-09-13T14:15:42.167403278Z guacd[15338]: ERROR: > File open refused (-2): "" > guacd_1 | 2021-09-13T14:17:02.948295495Z guacd[15338]: DEBUG: > Clipboard data received. Reporting availability of clipboard data to RDP > server. > guacd_1 | 2021-09-13T14:17:14.857231812Z guacd[15338]: DEBUG: > Clipboard data received. Reporting availability of clipboard data to RDP > server. > guacd_1 | 2021-09-13T14:18:16.590645926Z guacd[15338]: INFO: > Accepted format: 16-bit PCM with 2 channels at 44100 Hz > guacd_1 | 2021-09-13T14:18:51.820263319Z guacd[7]: DEBUG: > Guacamole connection closed during handshake > guacd_1 | 2021-09-13T14:18:51.820418741Z guacd[7]: DEBUG: > Error reading "select": End of stream reached while reading instruction > guacd_1 | 2021-09-13T14:21:51.700790573Z guacd[14814]: DEBUG: > Clipboard data received. Reporting availability of clipboard data to RDP > server. > guacd_1 | 2021-09-13T14:21:52.644317299Z guacd[14814]: INFO: > User "@4e696ad7-a66f-4415-a84f-aa599d6239ee" disconnected (0 users remain) > guacd_1 | 2021-09-13T14:21:52.644346809Z guacd[14814]: INFO: > Last user of connection "$ac241f0d-90de-487e-9bf5-d1fcab6463ed" > disconnected > guacd_1 | 2021-09-13T14:21:52.644350539Z guacd[14814]: DEBUG: > Requesting termination of client... > guacd_1 | 2021-09-13T14:21:52.712513048Z guacd[14814]: DEBUG: > Unloading device 0 (G) > guacd_1 | 2021-09-13T14:21:52.712527764Z guacd[14814]: DEBUG: > SVC "rdpdr" disconnected. > guacd_1 | 2021-09-13T14:21:52.712531208Z guacd[14814]: DEBUG: > SVC "rdpsnd" disconnected. > guacd_1 | 2021-09-13T14:21:52.713832474Z guacd[14814]: INFO: > Internal RDP client disconnected > guacd_1 | 2021-09-13T14:21:52.714336876Z guacd[14814]: DEBUG: > Client terminated successfully. > guacd_1 | 2021-09-13T14:21:52.719287612Z guacd[7]: INFO: > Connection "$ac241f0d-90de-487e-9bf5-d1fcab6463ed" removed. > guacd_1 | 2021-09-13T14:22:02.951448033Z guacd[15338]: DEBUG: > Clipboard data received. Reporting availability of clipboard data to RDP > server. > guacd_1 | 2021-09-13T14:23:52.041486801Z guacd[7]: DEBUG: > Guacamole connection closed during handshake > guacd_1 | 2021-09-13T14:23:52.041508185Z guacd[7]: DEBUG: > Error reading "select": End of stream reached while reading instruction > guacd_1 | 2021-09-13T14:24:33.529359679Z guacd[15338]: DEBUG: > Clipboard data received. Reporting availability of clipboard data to RDP > server. > guacd_1 | 2021-09-13T14:24:37.095385182Z guacd[15338]: DEBUG: > Clipboard data received. Reporting availability of clipboard data to RDP > server. > guacd_1 | 2021-09-13T14:28:15.375586356Z guacd[15338]: DEBUG: > Clipboard data received. Reporting availability of clipboard data to RDP > server. > guacd_1 | 2021-09-13T14:28:52.159743146Z guacd[7]: DEBUG: > Guacamole connection closed during handshake > guacd_1 | 2021-09-13T14:28:52.159773981Z guacd[7]: DEBUG: > Error reading "select": End of stream reached while reading instruction > guacd_1 | 2021-09-13T14:32:19.198653389Z guacd[15338]: DEBUG: > BIO_read returned a system error 104: Connection reset by peer > guacd_1 | 2021-09-13T14:32:19.198676263Z guacd[15338]: DEBUG: > transport_read_layer:freerdp_set_last_error_ex > ERRCONNECT_CONNECT_TRANSPORT_FAILED [0x0002000D] > guacd_1 | 2021-09-13T14:32:19.198747713Z guacd[15338]: ERROR: > Connection closed. > guacd_1 | 2021-09-13T14:32:19.207063823Z guacd[15338]: DEBUG: > Unloading device 0 (G) > guacd_1 | 2021-09-13T14:32:19.207082713Z guacd[15338]: DEBUG: > SVC "rdpdr" disconnected. > guacd_1 | 2021-09-13T14:32:19.207086339Z guacd[15338]: DEBUG: > SVC "rdpsnd" disconnected. > guacd_1 | 2021-09-13T14:32:19.211464966Z guacd[15338]: INFO: > Internal RDP client disconnected > guacd_1 | 2021-09-13T14:32:19.212441975Z guacd[15338]: INFO: > User "@b62dbd8f-0d04-4170-9f59-bab9436a4410" disconnected (0 users remain) > guacd_1 | 2021-09-13T14:32:19.212453322Z guacd[15338]: INFO: > Last user of connection "$cf755c62-ebb4-4866-bdd8-9b3c868ce3f7" > disconnected > guacd_1 | 2021-09-13T14:32:19.212658496Z guacd[15338]: DEBUG: > Requesting termination of client... > guacd_1 | 2021-09-13T14:32:19.213289155Z guacd[15338]: DEBUG: > Client terminated successfully. > guacd_1 | 2021-09-13T14:32:19.223127887Z guacd[7]: INFO: > Connection "$cf755c62-ebb4-4866-bdd8-9b3c868ce3f7" removed. > guacd_1 | 2021-09-13T14:33:52.257022053Z guacd[7]: DEBUG: > Guacamole connection closed during handshake > guacd_1 | 2021-09-13T14:33:52.257054063Z guacd[7]: DEBUG: > Error reading "select": End of stream reached while reading instruction > guacd_1 | 2021-09-13T14:38:52.349598898Z guacd[7]: DEBUG: > Guacamole connection closed during handshake > guacd_1 | 2021-09-13T14:38:52.349631320Z guacd[7]: DEBUG: > Error reading "select": End of stream reached while reading instruction > guacd_1 | 2021-09-13T14:43:52.457177071Z guacd[7]: DEBUG: > Guacamole connection closed during handshake > guacd_1 | 2021-09-13T14:43:52.457214339Z guacd[7]: DEBUG: > Error reading "select": End of stream reached while reading instruction > guacd_1 | 2021-09-13T14:48:52.569283904Z guacd[7]: DEBUG: > Guacamole connection closed during handshake > guacd_1 | 2021-09-13T14:48:52.569329287Z guacd[7]: DEBUG: > Error reading "select": End of stream reached while reading instruction > guacd_1 | 2021-09-13T14:53:52.686851881Z guacd[7]: DEBUG: > Guacamole connection closed during handshake > guacd_1 | 2021-09-13T14:53:52.686895047Z guacd[7]: DEBUG: > Error reading "select": End of stream reached while reading instruction > > > guacmole : > > guacamole_1 | 2021-09-13T14:18:44.269349795Z 14:18:44.269 > [http-nio-8080-exec-6] INFO o.a.g.r.auth.AuthenticationService - User > "guacadmin" successfully authenticated from [172.18.0.1, 172.18.0.19]. > guacamole_1 | 2021-09-13T14:21:52.644905551Z 14:21:52.644 > [http-nio-8080-exec-14] INFO o.a.g.tunnel.TunnelRequestService - User > "guacadmin" disconnected from connection "22743". Duration: 5446031 > milliseconds > guacamole_1 | 2021-09-13T14:32:19.212341284Z 14:32:19.212 > [http-nio-8080-exec-16] INFO o.a.g.tunnel.TunnelRequestService - User > "guacadmin" disconnected from connection "22672". Duration: 1031145 > milliseconds > guacamole_1 | 2021-09-13T14:32:19.214220909Z Exception in thread > "Thread-63" java.lang.IllegalStateException: Message will not be sent > because the WebSocket session has been closed > guacamole_1 | 2021-09-13T14:32:19.214297548Z at > org.apache.tomcat.websocket.WsRemoteEndpointImplBase.writeMessagePart(WsRemoteEndpointImplBase.java:438) > guacamole_1 | 2021-09-13T14:32:19.214302309Z at > org.apache.tomcat.websocket.WsRemoteEndpointImplBase.sendMessageBlock(WsRemoteEndpointImplBase.java:311) > guacamole_1 | 2021-09-13T14:32:19.214305247Z at > org.apache.tomcat.websocket.WsRemoteEndpointImplBase.sendMessageBlock(WsRemoteEndpointImplBase.java:251) > guacamole_1 | 2021-09-13T14:32:19.214308114Z at > org.apache.tomcat.websocket.WsRemoteEndpointImplBase.sendString(WsRemoteEndpointImplBase.java:192) > guacamole_1 | 2021-09-13T14:32:19.214310977Z at > org.apache.tomcat.websocket.WsRemoteEndpointBasic.sendText(WsRemoteEndpointBasic.java:37) > guacamole_1 | 2021-09-13T14:32:19.214338369Z at > org.apache.guacamole.websocket.GuacamoleWebSocketTunnelEndpoint.sendInstruction(GuacamoleWebSocketTunnelEndpoint.java:152) > guacamole_1 | 2021-09-13T14:32:19.214341240Z at > org.apache.guacamole.websocket.GuacamoleWebSocketTunnelEndpoint.access$200(GuacamoleWebSocketTunnelEndpoint.java:53) > guacamole_1 | 2021-09-13T14:32:19.214343913Z at > org.apache.guacamole.websocket.GuacamoleWebSocketTunnelEndpoint$2.run(GuacamoleWebSocketTunnelEndpoint.java:253) > > guacamole db: > ^[[36mpostgres_gqm_1 |^[[0m 2021-09-13T14:59:26.208925745Z > , > ^[[36mpostgres_gqm_1 |^[[0m 2021-09-13T14:59:26.208928037Z > $22730::integer > ^[[36mpostgres_gqm_1 |^[[0m 2021-09-13T14:59:26.208930370Z > , > ^[[36mpostgres_gqm_1 |^[[0m 2021-09-13T14:59:26.208932667Z > $22731::integer > ^[[36mpostgres_gqm_1 |^[[0m 2021-09-13T14:59:26.208934864Z > , > ^[[36mpostgres_gqm_1 |^[[0m 2021-09-13T14:59:26.208937008Z > $22732::integer > ^[[36mpostgres_gqm_1 |^[[0m 2021-09-13T14:59:26.208939254Z > , > ^[[36mpostgres_gqm_1 |^[[0m 2021-09-13T14:59:26.208941505Z > $22733::integer > ^[[36mpostgres_gqm_1 |^[[0m 2021-09-13T14:59:26.208943832Z > , > ^[[36mpostgres_gqm_1 |^[[0m 2021-09-13T14:59:26.208946145Z > $22734::integer > ^[[36mpostgres_gqm_1 |^[[0m 2021-09-13T14:59:26.208948457Z > , > ^[[36mpostgres_gqm_1 |^[[0m 2021-09-13T14:59:26.208950754Z > $22735::integer > ^[[36mpostgres_gqm_1 |^[[0m 2021-09-13T14:59:26.208955514Z > , > ^[[36mpostgres_gqm_1 |^[[0m 2021-09-13T14:59:26.208957654Z > $22736::integer > ^[[36mpostgres_gqm_1 |^[[0m 2021-09-13T14:59:26.208959843Z > , > ^[[36mpostgres_gqm_1 |^[[0m 2021-09-13T14:59:26.208962030Z > $22737::integer > ^[[36mpostgres_gqm_1 |^[[0m 2021-09-13T14:59:26.208964372Z > , > ^[[36mpostgres_gqm_1 |^[[0m 2021-09-13T14:59:26.208966687Z > $22738::integer > ^[[36mpostgres_gqm_1 |^[[0m 2021-09-13T14:59:26.208969021Z > , > ^[[36mpostgres_gqm_1 |^[[0m 2021-09-13T14:59:26.208971301Z > $22739::integer > ^[[36mpostgres_gqm_1 |^[[0m 2021-09-13T14:59:26.208973521Z > , > ^[[36mpostgres_gqm_1 |^[[0m 2021-09-13T14:59:26.208975652Z > $22740::integer > ^[[36mpostgres_gqm_1 |^[[0m 2021-09-13T14:59:26.208977856Z > , > ^[[36mpostgres_gqm_1 |^[[0m 2021-09-13T14:59:26.208980045Z > $22741::integer > ^[[36mpostgres_gqm_1 |^[[0m 2021-09-13T14:59:26.208982374Z > ) > ^[[36mpostgres_gqm_1 |^[[0m 2021-09-13T14:59:26.208984696Z > GROUP BY guacamole_connection.connection_id > > > couldn't get the query in the first row as it SUPER long! > What is going on? How can I solve this? > > why the guacamole service gets stuck? PLEASE HELP > > I don't really have any good ideas, except that I don't think it is specifically a Guacamole issue. I think it's some sort of issue with the Guacamole container(s) that is interrupting things, or perhaps with the DB container, but nothing about Guacamole itself is causing this problem. I'd suggest that you re-deploy the containers - you can even upgrade 1.2.0 -> 1.3.0 while you're at it - and see if clean containers take care of the issue. Obviously you'll want to make sure you save your database - either don't refresh that Postgres container, or make sure the data is in a persistent location. You should not have to restart your containers a couple of times a day or anything like that. But, this seems to me a Docker or DB issue, nothing with Guacamole. -Nick >
