Bug 1638443 - Local EVM Server not Found
Summary: Local EVM Server not Found
Keywords:
Status: CLOSED INSUFFICIENT_DATA
Alias: None
Product: Red Hat CloudForms Management Engine
Classification: Red Hat
Component: Appliance
Version: 5.9.3
Hardware: Unspecified
OS: Unspecified
high
high
Target Milestone: GA
: 5.9.6
Assignee: Joe Rafaniello
QA Contact: Sudhir Mallamprabhakara
Red Hat CloudForms Documentation
URL:
Whiteboard:
Depends On:
Blocks: 1622587
TreeView+ depends on / blocked
 
Reported: 2018-10-11 14:51 UTC by Niladri Roy
Modified: 2022-03-13 15:44 UTC (History)
7 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2018-11-10 04:47:05 UTC
Category: ---
Cloudforms Team: CFME Core
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)

Description Niladri Roy 2018-10-11 14:51:55 UTC
Description of problem:
After launching a new appliance and trying to join in existing region, evm service is running but below output is seen

vmdb]# rake evm:status
Checking EVM status...
Local EVM Server not Found

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

How reproducible:
Everytime at Cu environement

Steps to Reproduce:
1. create new cloudforms instance 
2. join it to existing region
3. run rake evm:status

Actual results:
Local EVM server not found

Expected results:
All workers should be up and running

Additional info:

Comment 4 Joe Rafaniello 2018-10-22 13:39:19 UTC
I'm still looking at this issue, but from the prior BZ, this could happen if the appliance evmserverd service didn't start and the database hadn't been initialized yet.  This could happen if the database was reconfigured to use another database for the first time.  Perhaps the HA environment was involved but this will require more time to investigate.  After bug #1626005, we'll be able to better understand if this is still an issue.

Comment 5 Jared Deubel 2018-10-24 21:24:45 UTC
Evm.log from troubled server
=======================================================
[----] I, [2018-10-24T11:49:57.540981 #31406:c5510c]  INFO -- : MIQ(EvmDatabase.seed) Seeding...
[----] I, [2018-10-24T11:59:02.056762 #31406:c5510c]  INFO -- : MIQ(EvmDatabase.seed) Seeding MiqDatabase
[----] I, [2018-10-24T11:59:02.075424 #31406:c5510c]  INFO -- : MIQ(EvmDatabase.seed) Seeding MiqRegion
[----] I, [2018-10-24T11:59:02.092787 #31406:c5510c]  INFO -- : MIQ(EvmDatabase.seed) Seeding MiqEnterprise
[----] I, [2018-10-24T11:59:02.122837 #31406:c5510c]  INFO -- : MIQ(EvmDatabase.seed) Seeding Zone
[----] I, [2018-10-24T11:59:02.124759 #31406:c5510c]  INFO -- : MIQ(EvmDatabase.seed) Seeding MiqServer
[----] I, [2018-10-24T11:59:02.137726 #31406:c5510c]  INFO -- : MIQ(EvmDatabase.seed) Seeding ServerRole
[----] I, [2018-10-24T11:59:02.152147 #31406:c5510c]  INFO -- : MIQ(EvmDatabase.seed) Seeding Tenant
[----] I, [2018-10-24T11:59:02.182208 #31406:c5510c]  INFO -- : MIQ(EvmDatabase.seed) Seeding MiqProductFeature
[----] I, [2018-10-24T11:59:02.669670 #31406:c5510c]  INFO -- : MIQ(EvmDatabase.seed) Seeding MiqUserRole
[----] I, [2018-10-24T11:59:03.041233 #31406:c5510c]  INFO -- : MIQ(EvmDatabase.seed) Seeding MiqGroup
[----] I, [2018-10-24T11:59:03.110639 #31406:c5510c]  INFO -- : MIQ(EvmDatabase.seed) Seeding User
[----] I, [2018-10-24T11:59:03.178470 #31406:c5510c]  INFO -- : MIQ(EvmDatabase.seed) Seeding MiqReport
...
[----] I, [2018-10-24T11:59:05.896865 #31406:c5510c]  INFO -- : MIQ(MiqReport.sync_from_file) Compare: [Clusters: Compare Template] file exists, synchronizing with model
[----] I, [2018-10-24T11:59:05.915974 #31406:c5510c]  INFO -- : MIQ(MiqReport.sync_from_file) Compare: [Hosts: Compare Template] file exists, synchronizing with model
[----] I, [2018-10-24T11:59:05.964267 #31406:c5510c]  INFO -- : MIQ(MiqReport.sync_from_file) Compare: [VMs: Compare Template] file exists, synchronizing with model
[----] I, [2018-10-24T11:59:06.043632 #31406:c5510c]  INFO -- : MIQ(EvmDatabase.seed) Seeding VmdbDatabase
[----] I, [2018-10-24T06:39:07.034782Z #1233:51f108]  INFO -- : EvmWatchdog - Detected a PID file: [31406], but server state should be: [not responding]...
=======================================================



Postgresql.log (Seeding Progressing until EOF client connection error) - Gap of 15:29 
=======================================================
2018-10-24 02:13:33 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:DEBUG:  parse a12: SELECT  "miq_user_roles".* FROM "miq_user_roles" WHERE "miq_user_roles"."name" = $1 LIMIT $2
2018-10-24 02:13:33 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:DEBUG:  StartTransactionCommand
2018-10-24 02:13:33 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:DEBUG:  CommitTransactionCommand
2018-10-24 02:13:33 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:DEBUG:  bind <unnamed> to a12
2018-10-24 02:13:33 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:DEBUG:  StartTransactionCommand
2018-10-24 02:13:33 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:DEBUG:  CommitTransactionCommand
2018-10-24 02:13:33 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:DEBUG:  parse <unnamed>: SELECT "miq_groups"."id" AS t0_r0, "miq_groups"."description" AS t0_r1, "miq_groups"."group_type" AS t0_r2, "miq_groups"."sequence" AS t0_r3, "miq_groups"."created_on" AS t0_r4, "miq_groups"."updated_on" AS t0_r5, "miq_groups"."settings" AS t0_r6, "miq_groups"."tenant_id" AS t0_r7, "entitlements"."id" AS t1_r0, "entitlements"."miq_group_id" AS t1_r1, "entitlements"."miq_user_role_id" AS t1_r2, "entitlements"."created_at" AS t1_r3, "entitlements"."updated_at" AS t1_r4, "entitlements"."filters" AS t1_r5, "entitlements"."filter_expression" AS t1_r6 FROM "miq_groups" LEFT OUTER JOIN "entitlements" ON "entitlements"."miq_group_id" = "miq_groups"."id" WHERE "miq_groups"."group_type" = $1 AND "entitlements"."miq_user_role_id" IS NULL
2018-10-24 02:13:33 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:DEBUG:  StartTransactionCommand
2018-10-24 02:13:33 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:DEBUG:  bind <unnamed> to <unnamed>
2018-10-24 02:13:33 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:DEBUG:  CommitTransactionCommand
2018-10-24 02:13:33 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:DEBUG:  StartTransactionCommand
2018-10-24 02:13:33 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:DEBUG:  CommitTransactionCommand
2018-10-24 02:13:33 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:DEBUG:  parse a13: SELECT  "users".* FROM "users" WHERE ("users"."id" BETWEEN $1 AND $2) AND ("users"."id" BETWEEN $3 AND $4) AND "users"."userid" = $5 LIMIT $6
2018-10-24 02:13:33 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:DEBUG:  StartTransactionCommand
2018-10-24 02:13:33 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:DEBUG:  CommitTransactionCommand
2018-10-24 02:13:33 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:DEBUG:  bind <unnamed> to a13
2018-10-24 02:13:33 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:DEBUG:  StartTransactionCommand
2018-10-24 02:13:33 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:DEBUG:  CommitTransactionCommand
2018-10-24 02:13:33 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:DEBUG:  parse <unnamed>: WITH pk_constraint AS (
2018-10-24 02:13:33 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:DEBUG:  StartTransactionCommand
2018-10-24 02:13:33 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:DEBUG:  bind <unnamed> to <unnamed>
2018-10-24 02:13:33 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:DEBUG:  CommitTransactionCommand
2018-10-24 02:13:33 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:DEBUG:  StartTransactionCommand
2018-10-24 02:13:33 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:DEBUG:  CommitTransactionCommand
2018-10-24 02:13:33 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:DEBUG:  parse a14: SELECT "miq_reports".* FROM "miq_reports" WHERE "miq_reports"."rpt_type" = $1 AND ("miq_reports"."template_type" = 'report' OR "miq_reports"."template_type" IS NULL) AND ("miq_reports"."filename" IS NOT NULL)
2018-10-24 02:13:33 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:DEBUG:  StartTransactionCommand
2018-10-24 02:13:33 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:DEBUG:  CommitTransactionCommand
2018-10-24 02:13:33 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:DEBUG:  bind <unnamed> to a14
2018-10-24 02:13:33 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:DEBUG:  StartTransactionCommand
2018-10-24 02:13:33 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:DEBUG:  CommitTransactionCommand
2018-10-24 02:29:02 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:LOG:  could not receive data from client: Connection timed out
2018-10-24 02:29:02 EDT:10.38.107.21(46556):5bd00d8c.1fac:root@vmdb_production:[8108]:LOG:  unexpected EOF on client connection with an open transaction
=======================================================

Comment 7 Joe Rafaniello 2018-11-02 18:14:08 UTC
We're still waiting on the customer.  They have had issues with HA and lost connections to the database, which may cause the issue of this bug as a side effect.  Once they have cycles to help us troubleshoot the original HA/database connection problems, we can see if the "Local EVM Server not Found" goes away.

For now, there is no update.

Comment 8 Joe Rafaniello 2018-11-05 16:51:39 UTC
Hi Jared,

Has the customer been able to review the HA/database connection problems they were having in bug #1626005?  I'm not sure what we can do with this BZ until that is resolved.  What do you think?


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