Note: This is a beta release of Red Hat Bugzilla 5.0. The data contained within is a snapshot of the live data so any changes you make will not be reflected in the production Bugzilla. Also email is disabled so feel free to test any aspect of the site that you want. File any problems you find or give feedback here.
Bug 1517075 - SSUI: ERROR after login `Failed to upgrade to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: WebSocket)`
Summary: SSUI: ERROR after login `Failed to upgrade to WebSocket (REQUEST_METHOD: GET,...
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Red Hat CloudForms Management Engine
Classification: Red Hat
Component: UI - Service
Version: 5.9.0
Hardware: Unspecified
OS: Unspecified
medium
medium
Target Milestone: GA
: 5.10.0
Assignee: Allen W
QA Contact: Dave Johnson
URL:
Whiteboard: ssui:error:testathon
Depends On:
Blocks: 1525115
TreeView+ depends on / blocked
 
Reported: 2017-11-24 07:07 UTC by Yadnyawalk Tale
Modified: 2018-06-21 20:41 UTC (History)
12 users (show)

Fixed In Version: 5.10.0.0
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
: 1525115 (view as bug list)
Environment:
Last Closed: 2018-06-21 20:41:27 UTC
Category: Bug
Cloudforms Team: CFME Core
ytale: automate_bug-


Attachments (Terms of Use)
logs (deleted)
2017-11-24 07:07 UTC, Yadnyawalk Tale
no flags Details

Description Yadnyawalk Tale 2017-11-24 07:07:23 UTC
Description of problem:
Production ERROR occurring after login to SSUI

Version-Release number of selected component (if applicable):
5.9.0.10.20171121225911_a2209d2

How reproducible:
100%

Steps to Reproduce:
(You should keep running production.log during process)
1. Add vsphere55
2. Create simple dialog, catalog and catalog item for v55
3. Order service from OPS
4. Login to SSUI and check production.log

Actual results:
Error: Failed to upgrade to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: WebSocket)

Expected results:
Should not appear that

Additional info:
Log folder attached (Need to check production.log only)

Comment 2 Chris Kacerguis 2017-11-27 14:36:38 UTC
At first glance this seems like at issue from the web socket server.  Going to send this to the backend team to give it a test.

In the meantime, could you spin up a new appliance and test (wondering if this was some kind of fluke)

Comment 3 Yadnyawalk Tale 2017-11-27 15:45:58 UTC
Created attachment 1359526 [details]
retested_log_files

Hi Chris,

Retested it with new 5.9.0.10.20171121225911_a2209d2 appliance but error remains the same there. Little change in steps, this time I added cata_item from OPS and without ordering cata_item I checked log during SSUI login.

Doesn't seems like fluke, let see what backend guys says.

Thanks!

Comment 4 Gregg Tanzillo 2017-11-29 20:35:37 UTC
Here's the full context of the error from the production.log file - 

[----] I, [2017-11-24T01:41:13.998802 #13293:3e0b3a4]  INFO -- : Started GET "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-11-24 01:41:13 -0500
[----] I, [2017-11-24T01:41:13.998878 #13293:3e0b3a4]  INFO -- : Successfully upgraded to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: WebSocket)
[----] E, [2017-11-24T01:41:13.999578 #13293:4e9a724] ERROR -- : An unauthorized connection attempt was rejected
[----] E, [2017-11-24T01:41:13.999782 #13293:4e9a724] ERROR -- : Failed to upgrade to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: WebSocket)
[----] I, [2017-11-24T01:41:13.999864 #13293:4e9a724]  INFO -- : Finished "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-11-24 01:41:13 -0500
[----] I, [2017-11-24T01:41:14.299533 #13293:4e9a724]  INFO -- : Finished "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-11-24 01:41:14 -0500

Comment 9 Alex Mayberry 2017-12-06 00:33:55 UTC
I've recently upgraded from 5.7.1.3-1  to cfme-5.7.3.2-1.

2 UIs
4 Workers
2 HA dedicated VMDBs

Everything was stopped, updated, restarted.  These errors started after the update, showing up every few minutes.  No errors of this nature were found in the previous 30 days worth of logs.

Below is an example, showing worker process #15539 initializing, and related ERROR messages.

$ cat websocket.log
......snip
[----] I, [2017-12-05T18:08:30.158669 #15539:a3514c]  INFO -- : Initializing websocket worker!




$ cat production.log | grep '#15539'
[----] I, [2017-12-05T18:08:44.511301 #15539:1005be4]  INFO -- : Started GET "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:08:44 -0600
[----] I, [2017-12-05T18:08:44.511422 #15539:1005be4]  INFO -- : Successfully upgraded to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: WebSocket)
[----] E, [2017-12-05T18:08:44.548844 #15539:1115480] ERROR -- : An unauthorized connection attempt was rejected
[----] E, [2017-12-05T18:08:44.550089 #15539:1115480] ERROR -- : Failed to upgrade to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: WebSocket)
[----] I, [2017-12-05T18:08:44.550177 #15539:1115480]  INFO -- : Finished "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:08:44 -0600
[----] I, [2017-12-05T18:08:44.552425 #15539:1115480]  INFO -- : Finished "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:08:44 -0600
[----] I, [2017-12-05T18:09:41.597971 #15539:100241c]  INFO -- : Started GET "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:09:41 -0600
[----] I, [2017-12-05T18:09:41.598142 #15539:100241c]  INFO -- : Successfully upgraded to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: WebSocket)
[----] E, [2017-12-05T18:09:41.602180 #15539:1115480] ERROR -- : An unauthorized connection attempt was rejected
[----] E, [2017-12-05T18:09:41.602385 #15539:1115480] ERROR -- : Failed to upgrade to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: WebSocket)
[----] I, [2017-12-05T18:09:41.602464 #15539:1115480]  INFO -- : Finished "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:09:41 -0600
[----] I, [2017-12-05T18:09:41.605007 #15539:1115480]  INFO -- : Finished "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:09:41 -0600
[----] I, [2017-12-05T18:10:10.196049 #15539:1002a20]  INFO -- : Started GET "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:10:10 -0600
[----] I, [2017-12-05T18:10:10.196437 #15539:1002a20]  INFO -- : Successfully upgraded to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: WebSocket)
[----] E, [2017-12-05T18:10:10.201108 #15539:1115480] ERROR -- : An unauthorized connection attempt was rejected
[----] E, [2017-12-05T18:10:10.201461 #15539:1115480] ERROR -- : Failed to upgrade to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: WebSocket)
[----] I, [2017-12-05T18:10:10.201640 #15539:1115480]  INFO -- : Finished "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:10:10 -0600
[----] I, [2017-12-05T18:10:10.204460 #15539:1115480]  INFO -- : Finished "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:10:10 -0600
[----] I, [2017-12-05T18:11:07.420720 #15539:1003538]  INFO -- : Started GET "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:11:07 -0600
[----] I, [2017-12-05T18:11:07.420986 #15539:1003538]  INFO -- : Successfully upgraded to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: WebSocket)
[----] E, [2017-12-05T18:11:07.425142 #15539:1115480] ERROR -- : An unauthorized connection attempt was rejected
[----] E, [2017-12-05T18:11:07.425435 #15539:1115480] ERROR -- : Failed to upgrade to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: WebSocket)
[----] I, [2017-12-05T18:11:07.425596 #15539:1115480]  INFO -- : Finished "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:11:07 -0600
[----] I, [2017-12-05T18:11:07.428543 #15539:1115480]  INFO -- : Finished "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:11:07 -0600
[----] I, [2017-12-05T18:11:36.061768 #15539:10032a4]  INFO -- : Started GET "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:11:36 -0600
[----] I, [2017-12-05T18:11:36.061930 #15539:10032a4]  INFO -- : Successfully upgraded to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: WebSocket)
[----] E, [2017-12-05T18:11:36.065027 #15539:1115480] ERROR -- : An unauthorized connection attempt was rejected
[----] E, [2017-12-05T18:11:36.065215 #15539:1115480] ERROR -- : Failed to upgrade to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: WebSocket)
[----] I, [2017-12-05T18:11:36.065281 #15539:1115480]  INFO -- : Finished "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:11:36 -0600
[----] I, [2017-12-05T18:11:36.067319 #15539:1115480]  INFO -- : Finished "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:11:36 -0600
[----] I, [2017-12-05T18:12:33.398462 #15539:1005be4]  INFO -- : Started GET "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:12:33 -0600
[----] I, [2017-12-05T18:12:33.398663 #15539:1005be4]  INFO -- : Successfully upgraded to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: WebSocket)
[----] E, [2017-12-05T18:12:33.403169 #15539:1115480] ERROR -- : An unauthorized connection attempt was rejected
[----] E, [2017-12-05T18:12:33.403464 #15539:1115480] ERROR -- : Failed to upgrade to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: WebSocket)
[----] I, [2017-12-05T18:12:33.403661 #15539:1115480]  INFO -- : Finished "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:12:33 -0600
[----] I, [2017-12-05T18:12:33.406305 #15539:1115480]  INFO -- : Finished "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:12:33 -0600
[----] I, [2017-12-05T18:13:02.124355 #15539:100241c]  INFO -- : Started GET "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:13:02 -0600
[----] I, [2017-12-05T18:13:02.124550 #15539:100241c]  INFO -- : Successfully upgraded to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: WebSocket)
[----] E, [2017-12-05T18:13:02.128718 #15539:1115480] ERROR -- : An unauthorized connection attempt was rejected
[----] E, [2017-12-05T18:13:02.129032 #15539:1115480] ERROR -- : Failed to upgrade to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: WebSocket)
[----] I, [2017-12-05T18:13:02.129166 #15539:1115480]  INFO -- : Finished "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:13:02 -0600
[----] I, [2017-12-05T18:13:02.132144 #15539:1115480]  INFO -- : Finished "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:13:02 -0600
[----] I, [2017-12-05T18:13:59.529069 #15539:1002a20]  INFO -- : Started GET "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:13:59 -0600
[----] I, [2017-12-05T18:13:59.529340 #15539:1002a20]  INFO -- : Successfully upgraded to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: WebSocket)
[----] E, [2017-12-05T18:13:59.532564 #15539:1115480] ERROR -- : An unauthorized connection attempt was rejected
[----] E, [2017-12-05T18:13:59.532731 #15539:1115480] ERROR -- : Failed to upgrade to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: WebSocket)
[----] I, [2017-12-05T18:13:59.532819 #15539:1115480]  INFO -- : Finished "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:13:59 -0600
[----] I, [2017-12-05T18:13:59.534993 #15539:1115480]  INFO -- : Finished "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:13:59 -0600
[----] I, [2017-12-05T18:14:28.265267 #15539:1003538]  INFO -- : Started GET "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:14:28 -0600
[----] I, [2017-12-05T18:14:28.265381 #15539:1003538]  INFO -- : Successfully upgraded to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: WebSocket)
[----] E, [2017-12-05T18:14:28.269789 #15539:1115480] ERROR -- : An unauthorized connection attempt was rejected
[----] E, [2017-12-05T18:14:28.270299 #15539:1115480] ERROR -- : Failed to upgrade to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: WebSocket)
[----] I, [2017-12-05T18:14:28.270440 #15539:1115480]  INFO -- : Finished "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:14:28 -0600
[----] I, [2017-12-05T18:14:28.273031 #15539:1115480]  INFO -- : Finished "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:14:28 -0600
[----] I, [2017-12-05T18:15:25.795557 #15539:10032a4]  INFO -- : Started GET "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:15:25 -0600
[----] I, [2017-12-05T18:15:25.795726 #15539:10032a4]  INFO -- : Successfully upgraded to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: WebSocket)
[----] E, [2017-12-05T18:15:25.799970 #15539:1115480] ERROR -- : An unauthorized connection attempt was rejected
[----] E, [2017-12-05T18:15:25.800269 #15539:1115480] ERROR -- : Failed to upgrade to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: WebSocket)
[----] I, [2017-12-05T18:15:25.800403 #15539:1115480]  INFO -- : Finished "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:15:25 -0600
[----] I, [2017-12-05T18:15:25.803594 #15539:1115480]  INFO -- : Finished "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:15:25 -0600
[----] I, [2017-12-05T18:15:54.586437 #15539:1005be4]  INFO -- : Started GET "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:15:54 -0600
[----] I, [2017-12-05T18:15:54.586633 #15539:1005be4]  INFO -- : Successfully upgraded to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: WebSocket)
[----] E, [2017-12-05T18:15:54.590843 #15539:1115480] ERROR -- : An unauthorized connection attempt was rejected
[----] E, [2017-12-05T18:15:54.591320 #15539:1115480] ERROR -- : Failed to upgrade to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: WebSocket)
[----] I, [2017-12-05T18:15:54.591445 #15539:1115480]  INFO -- : Finished "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:15:54 -0600
[----] I, [2017-12-05T18:15:54.594093 #15539:1115480]  INFO -- : Finished "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:15:54 -0600
[----] I, [2017-12-05T18:16:52.208200 #15539:100241c]  INFO -- : Started GET "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:16:52 -0600
[----] I, [2017-12-05T18:16:52.208359 #15539:100241c]  INFO -- : Successfully upgraded to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: WebSocket)
[----] E, [2017-12-05T18:16:52.212738 #15539:1115480] ERROR -- : An unauthorized connection attempt was rejected
[----] E, [2017-12-05T18:16:52.213076 #15539:1115480] ERROR -- : Failed to upgrade to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: WebSocket)
[----] I, [2017-12-05T18:16:52.213205 #15539:1115480]  INFO -- : Finished "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:16:52 -0600
[----] I, [2017-12-05T18:16:52.215275 #15539:1115480]  INFO -- : Finished "/ws/notifications" [WebSocket] for 127.0.0.1 at 2017-12-05 18:16:52 -0600

Comment 11 Allen W 2017-12-06 16:13:49 UTC
Ok good news, a fix is up there! https://github.com/ManageIQ/manageiq-ui-service/pull/1314

Comment 12 Alex Mayberry 2017-12-06 16:37:38 UTC
Great news, Allen!   So this is related to a trust chain?  Are you able to provide any insights into the impact of these error messages?  Is this limited to the UI notifications not showing up, or is it more far-reaching than that?

Comment 13 Allen W 2017-12-06 17:08:29 UTC
Not related to trust chain, no impact aside from log verbosity, just trying to do something before we have enough info to do something (creating the actioncable subscription before the necessary cookie was in place as Dávid had mentioned)

Comment 14 Allen W 2017-12-12 15:50:42 UTC
This made it in!

Comment 16 Alex Mayberry 2017-12-12 16:05:56 UTC
Awesome, great work!


Note You need to log in before you can comment on or make changes to this bug.