Bug 1544956

Summary:	UI crashing when provisioning or creating/editing reports
Product:	Red Hat CloudForms Management Engine	Reporter:	Ryan Spagnola <rspagnol>
Component:	Appliance	Assignee:	Joe Rafaniello <jrafanie>
Status:	CLOSED DUPLICATE	QA Contact:	Dave Johnson <dajohnso>
Severity:	urgent	Docs Contact:
Priority:	high
Version:	5.8.0	CC:	abellott, cpelland, gtanzill, hkataria, jocarter, jrafanie, lavenel, mpovolny, obarenbo, rspagnol, simaishi
Target Milestone:	GA
Target Release:	5.9.1
Hardware:	All
OS:	All
Whiteboard:
Fixed In Version:		Doc Type:	If docs needed, set a value
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2018-03-08 21:50:27 UTC	Type:	Bug
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	Bug
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	CFME Core	Target Upstream Version:
Embargoed:

Comment 3 Joe Rafaniello 2018-02-13 23:02:55 UTC

We get timeouts in apache log starting at 9:41 AM on 2/12.  The all point to port 3000.

evm_current_REDACTED_20180212_145355.tar.xz/log/apache/ssl_error.log:[Mon Feb 12 09:41:24.234672 2018] [proxy_http:error] [pid 20976] (70007)The timeout specified has expired: [client x.x.x.x:60406] AH01102: error reading status line from remote server 0.0.0.0:3000, referer: https://REDACTED/report/explorer
evm_current_REDACTED_20180212_145355.tar.xz/log/apache/ssl_error.log:[Mon Feb 12 09:43:40.644056 2018] [proxy_http:error] [pid 24521] (70007)The timeout specified has expired: [client x.x.x.x:60484] AH01102: error reading status line from remote server 0.0.0.0:3000, referer: https://REDACTED/report/explorer


About 20 minutes before 10:01 (9:41), port 3000 was owned by pid 1972 and we can see CPU usage rises to nearly 100% and never drops:

zgrep -E "timesync|3000" evm_archive_<REDACTED>_20180213_094137.tar.xz/log/top_output*

evm_archive_REDACTED_20180213_094137.tar.xz/log/top_output.log-20180213.gz: 1972  1647 root      21   1 1231956 895064   5296 S   1.3  7.4  15:18.23 puma 3.3.0 (tcp://127.0.0.1:3000) [MIQ: Web Server Worker]
evm_archive_REDACTED_20180213_094137.tar.xz/log/top_output.log-20180213.gz: 1972  1647 root      21   1 1231956 895064   5296 S  74.3  7.4  16:02.80 puma 3.3.0 (tcp://127.0.0.1:3000) [MIQ: Web Server Worker]
evm_archive_REDACTED_20180213_094137.tar.xz/log/top_output.log-20180213.gz: 1972  1647 root      21   1 1231956 895064   5296 S 100.0  7.4  17:02.84 puma 3.3.0 (tcp://127.0.0.1:3000) [MIQ: Web Server Worker]
evm_archive_REDACTED_20180213_094137.tar.xz/log/top_output.log-20180213.gz: 1972  1647 root      21   1 1231956 895064   5296 S  99.9  7.4  18:02.80 puma 3.3.0 (tcp://127.0.0.1:3000) [MIQ: Web Server Worker]
evm_archive_REDACTED_20180213_094137.tar.xz/log/top_output.log-20180213.gz: 1972  1647 root      21   1 1231956 895064   5296 S  99.9  7.4  19:02.80 puma 3.3.0 (tcp://127.0.0.1:3000) [MIQ: Web Server Worker]
evm_archive_REDACTED_20180213_094137.tar.xz/log/top_output.log-20180213.gz: 1972  1647 root      21   1 1231956 895064   5296 S  99.9  7.4  20:02.78 puma 3.3.0 (tcp://127.0.0.1:3000) [MIQ: Web Server Worker]
evm_archive_REDACTED_20180213_094137.tar.xz/log/top_output.log-20180213.gz: 1972  1647 root      21   1 1231956 895064   5296 S  99.9  7.4  21:02.73 puma 3.3.0 (tcp://127.0.0.1:3000) [MIQ: Web Server Worker]
evm_archive_REDACTED_20180213_094137.tar.xz/log/top_output.log-20180213.gz: 1972  1647 root      21   1 1231956 895064   5296 S  99.9  7.4  22:02.74 puma 3.3.0 (tcp://127.0.0.1:3000) [MIQ: Web Server Worker]
evm_archive_REDACTED_20180213_094137.tar.xz/log/top_output.log-20180213.gz: 1972  1647 root      21   1 1231956 895064   5296 S  99.9  7.4  23:02.68 puma 3.3.0 (tcp://127.0.0.1:3000) [MIQ: Web Server Worker]
evm_archive_REDACTED_20180213_094137.tar.xz/log/top_output.log-20180213.gz: 1972  1647 root      21   1 1231956 895064   5296 S  99.9  7.4  24:02.65 puma 3.3.0 (tcp://127.0.0.1:3000) [MIQ: Web Server Worker]
evm_archive_REDACTED_20180213_094137.tar.xz/log/top_output.log-20180213.gz: 1972  1647 root      21   1 1231956 895084   5312 S  99.9  7.4  25:02.61 puma 3.3.0 (tcp://127.0.0.1:3000) [MIQ: Web Server Worker]
evm_archive_REDACTED_20180213_094137.tar.xz/log/top_output.log-20180213.gz: 1972  1647 root      21   1 1231956 895084   5312 S  99.9  7.4  26:02.55 puma 3.3.0 (tcp://127.0.0.1:3000) [MIQ: Web Server Worker]
evm_archive_REDACTED_20180213_094137.tar.xz/log/top_output.log-20180213.gz: 1972  1647 root      21   1 1231956 895084   5312 S  99.9  7.4  27:02.57 puma 3.3.0 (tcp://127.0.0.1:3000) [MIQ: Web Server Worker]
evm_archive_REDACTED_20180213_094137.tar.xz/log/top_output.log-20180213.gz: 1972  1647 root      21   1 1231956 895084   5312 S  99.9  7.4  28:02.57 puma 3.3.0 (tcp://127.0.0.1:3000) [MIQ: Web Server Worker]
evm_archive_REDACTED_20180213_094137.tar.xz/log/top_output.log-20180213.gz: 1972  1647 root      21   1 1231956 895084   5312 S  99.9  7.4  29:02.57 puma 3.3.0 (tcp://127.0.0.1:3000) [MIQ: Web Server Worker]
evm_archive_REDACTED_20180213_094137.tar.xz/log/top_output.log-20180213.gz: 1972  1647 root      21   1 1231956 895084   5312 S  99.9  7.4  30:02.58 puma 3.3.0 (tcp://127.0.0.1:3000) [MIQ: Web Server Worker]
evm_archive_REDACTED_20180213_094137.tar.xz/log/top_output.log-20180213.gz: 1972  1647 root      21   1 1231956 895084   5312 S  99.9  7.4  31:02.58 puma 3.3.0 (tcp://127.0.0.1:3000) [MIQ: Web Server Worker]
evm_archive_REDACTED_20180213_094137.tar.xz/log/top_output.log-20180213.gz: 1972  1647 root      21   1 1231956 895084   5312 S  99.9  7.4  32:02.56 puma 3.3.0 (tcp://127.0.0.1:3000) [MIQ: Web Server Worker]
evm_archive_REDACTED_20180213_094137.tar.xz/log/top_output.log-20180213.gz: 1972  1647 root      21   1 1231956 895084   5312 S  99.8  7.4  33:02.48 puma 3.3.0 (tcp://127.0.0.1:3000) [MIQ: Web Server Worker]
evm_archive_REDACTED_20180213_094137.tar.xz/log/top_output.log-20180213.gz: 1972  1647 root      21   1 1231956 895084   5312 S  99.9  7.4  34:02.51 puma 3.3.0 (tcp://127.0.0.1:3000) [MIQ: Web Server Worker]
evm_archive_REDACTED_20180213_094137.tar.xz/log/top_output.log-20180213.gz: 1972  1647 root      21   1 1231956 895084   5312 S  99.9  7.4  35:02.52 puma 3.3.0 (tcp://127.0.0.1:3000) [MIQ: Web Server Worker]
evm_archive_REDACTED_20180213_094137.tar.xz/log/top_output.log-20180213.gz: 1972  1647 root      21   1 1231956 895084   5312 S  99.9  7.4  36:02.47 puma 3.3.0 (tcp://127.0.0.1:3000) [MIQ: Web Server Worker]
evm_archive_REDACTED_20180213_094137.tar.xz/log/top_output.log-20180213.gz:timesync: date time is-> Mon Feb 12 10:01:01 EST 2018 -0500


There is a very recent request processed by pid 1972 that is "Started" but never "Completed":

zgrep -E "1103f8c" evm_archive_pub-<REDACTED>_20180213_094137.tar.xz/log/production* | tail
evm_archive_pub-REDACTED_20180213_094137.tar.xz/log/production.log-20180213.gz:[----] I, [2018-02-12T09:39:24.221461 #1972:1103f8c]  INFO -- : Started GET "/report/miq_report_edit?tab=edit_3" for x.x.x.x at 2018-02-12 09:39:24 -0500
evm_archive_pub-REDACTED_20180213_094137.tar.xz/log/production.log-20180213.gz:[----] I, [2018-02-12T09:39:24.225174 #1972:1103f8c]  INFO -- : Processing by ReportController#miq_report_edit as JS
evm_archive_pub-REDACTED_20180213_094137.tar.xz/log/production.log-20180213.gz:[----] I, [2018-02-12T09:39:24.225293 #1972:1103f8c]  INFO -- :   Parameters: {"tab"=>"edit_3"}

Based on this, it seems like the same symptoms as fixed in bug 1519809
https://github.com/ManageIQ/manageiq/pull/16612

Comment 4 Joe Rafaniello 2018-02-23 20:17:44 UTC

Ryan, was the hotfix from bug 1519809 provided?  All of the symptoms seem to be the same so please let know if this bug was fixed by it and can be marked as a duplicate.  Thanks!

Comment 5 Ryan Spagnola 2018-03-08 20:07:58 UTC

Hi Joe,

I sent the customer the hotfix on 2/14 and then the errata on 2/28. They have not experienced a ui stop since.

Thank you,
Ryan

Comment 6 Joe Rafaniello 2018-03-08 21:50:27 UTC

Thanks Ryan,

I'll mark this as a dupe for now.  We can re-open if we find it still occurs even after applying the hotfix.

*** This bug has been marked as a duplicate of bug 1519809 ***