Closed RichAyotte closed 7 years ago
I'd have to see your schemas and resolvers, because of the recursive nature of graphql you can have code that is hit a great deal and slow down performance
Good to know this isn't normal.
I'll have a look at the resolvers.
Do you have any tips for troubleshooting this type of problem?
We faced something similar in the beginning, i recall we debugged it the old fashioned boring way of adding timing statements everywhere
Here's another test and continuing investigation. SQL was generated from graphql-sequelize. There's definitely not a problem with node or mysql2.
Node -> mysql2: 78ms Node -> koa -> koa-router -> graphql -> graphql-sequelize -> sequelize: 3720ms
console.time('queries')
await connection.execute('SELECT `id`, `project_id`, `service_id`, `branch_id`, `occurs_on`, `occurs_at`, `status`, `invoice_number`, `created_by`, `google_calendar_event_id`, `minutes_estimate`, `minutes_actual` FROM `ProjectServices` AS `ProjectServices` ORDER BY `ProjectServices`.`id` ASC LIMIT 20;')
await connection.execute('SELECT `id`, `project_service_id`, `type`, `note`, `company_address_id`, `company_person_id` FROM `ProjectServiceAddresses` AS `ProjectServiceAddresses` WHERE `ProjectServiceAddresses`.`project_service_id` IN (101, 102, 103, 104, 105, 106, 107, 108, 109, 110, 111, 112, 113, 114, 115, 116, 117, 118, 119, 120) ORDER BY `ProjectServiceAddresses`.`id` ASC;')
await connection.execute('SELECT `id`, `project_service_id`, `asset_id` FROM `ProjectServiceAssets` AS `ProjectServiceAssets` WHERE `ProjectServiceAssets`.`project_service_id` IN (101, 102, 103, 104, 105, 106, 107, 108, 109, 110, 111, 112, 113, 114, 115, 116, 117, 118, 119, 120) ORDER BY `ProjectServiceAssets`.`id` ASC;')
await connection.execute('SELECT `id`, `project_service_id`, `person_id`, `message`, `timestamp` FROM `ProjectServiceChanges` AS `ProjectServiceChanges` WHERE `ProjectServiceChanges`.`project_service_id` IN (101, 102, 103, 104, 105, 106, 107, 108, 109, 110, 111, 112, 113, 114, 115, 116, 117, 118, 119, 120) ORDER BY `ProjectServiceChanges`.`id` ASC;')
await connection.execute('SELECT `id`, `project_service_id`, `equipment_id`, `quantity_requested`, `quantity_actual` FROM `ProjectServiceEquipment` AS `ProjectServiceEquipment` WHERE `ProjectServiceEquipment`.`project_service_id` IN (101, 102, 103, 104, 105, 106, 107, 108, 109, 110, 111, 112, 113, 114, 115, 116, 117, 118, 119, 120) ORDER BY `ProjectServiceEquipment`.`id` ASC;')
await connection.execute('SELECT `id`, `project_service_id`, `supply_id`, `quantity` FROM `ProjectServiceSupplies` AS `ProjectServiceSupplies` WHERE `ProjectServiceSupplies`.`project_service_id` IN (101, 102, 103, 104, 105, 106, 107, 108, 109, 110, 111, 112, 113, 114, 115, 116, 117, 118, 119, 120) ORDER BY `ProjectServiceSupplies`.`id` ASC;')
await connection.execute('SELECT `id`, `project_service_id`, `file_url`, `name`, `description`, `mime_type`, `owned_by` FROM `ProjectServiceFiles` AS `ProjectServiceFiles` WHERE `ProjectServiceFiles`.`project_service_id` IN (101, 102, 103, 104, 105, 106, 107, 108, 109, 110, 111, 112, 113, 114, 115, 116, 117, 118, 119, 120) ORDER BY `ProjectServiceFiles`.`id` ASC;')
await connection.execute('SELECT `id`, `project_service_id`, `entered_by`, `entered_on`, `content`, `access_level` FROM `ProjectServiceNotes` AS `ProjectServiceNotes` WHERE `ProjectServiceNotes`.`project_service_id` IN (101, 102, 103, 104, 105, 106, 107, 108, 109, 110, 111, 112, 113, 114, 115, 116, 117, 118, 119, 120) ORDER BY `ProjectServiceNotes`.`id` ASC;')
await connection.execute('SELECT `id`, `company_person_id`, `project_service_id`, `service_role_id`, `payroll_run_id`, `scheduled_in_at`, `clocked_in_at`, `scheduled_out_at`, `clocked_out_at`, `breaked_for`, `travelled_for`, `wheniwork_id`, `is_no_top_up`, `is_refused_shift` FROM `ProjectServicePeople` AS `ProjectServicePeople` WHERE `ProjectServicePeople`.`project_service_id` IN (101, 102, 103, 104, 105, 106, 107, 108, 109, 110, 111, 112, 113, 114, 115, 116, 117, 118, 119, 120) ORDER BY `ProjectServicePeople`.`id` ASC;')
await connection.execute('SELECT `id`, `name`, `customer_id`, `changed_on`, `entered_by`, `booked_by`, `managed_by`, `branch_id`, `po_number`, `customer_customer_id`, `default_quote_type`, `archived_on` FROM `Projects` AS `Projects` WHERE `Projects`.`id` IN (146, 50, 51, 50, 52, 50, 53, 53, 53, 54, 53, 53, 56, 57, 58, 59, 57, 57, 59, 49);')
await connection.execute('SELECT `id`, `name` FROM `Services` AS `Services` WHERE `Services`.`id` IN (2, 9, 9, 9, 12, 9, 36, 36, 19, 2, 19, 14, 18, 11, 4, 9, 11, 12, 2, 1);')
await connection.execute('SELECT `id`, `company_id`, `address_id`, `notes`, `is_primary`, `wheniwork_id` FROM `CompanyAddresses` AS `CompanyAddresses` WHERE `CompanyAddresses`.`id` IN (67, 55, 56, 55, 73, 55, 58, 58, 58, 53, 59, 58, 58, 60, 61, 62, 63, 65, 66, 61, 62, 62, 65, 66, 67);')
await connection.execute('SELECT `id`, `first_name`, `middle_name`, `last_name`, `common_name`, `title_id`, `email`, `phone`, `mobile_phone`, `phone_email`, `notes`, `born_on`, `social_insurance_number`, `drivers_license_number`, `emergency_contact_id` FROM `People` AS `People` WHERE `People`.`id` IN (47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 49, 49, 49, 49, 49, 49, 49, 49, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 50, 47, 47, 47, 47, 47, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 49, 49, 49, 49, 49, 49, 49, 49, 49, 50, 47, 47, 47, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 49, 49, 49, 49, 49, 49, 49, 49, 49, 49, 49, 49, 49, 49, 49, 49, 49, 49, 50, 47, 47, 47, 47, 47, 47, 47, 47, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 49, 49, 49, 49, 49, 49, 49, 49, 49, 49, 49, 49, 49, 49, 49, 50, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 50, 47, 47, 47, 47, 47, 47, 47, 54, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 49, 49, 49, 50, 49, 49, 49, 49, 240, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 50, 50, 49, 49, 49, 49, 49, 240, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 49, 49, 240, 47, 47, 47, 47, 47, 47, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 54, 49, 49, 49, 50, 47, 47, 47, 47, 47, 47, 47, 47, 49, 49, 49, 50, 50, 50, 50, 47, 47, 49, 49, 47, 47, 240, 47, 47, 47, 47, 47, 47, 47, 47, 50, 49, 49, 240, 47, 47, 47, 47, 47, 47, 47, 47, 49, 49, 49, 49, 50, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 240, 47, 47, 47, 47, 47, 47, 47, 50, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 49, 49, 49, 50, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 240, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 240, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 49, 49, 49, 49, 49, 49, 50, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 47, 54, 54, 54, 54, 50);')
await connection.execute('SELECT `id`, `name`, `description`, `owned_by`, `model_number`, `image_url`, `manual_url` FROM `Equipment` AS `Equipment` WHERE `Equipment`.`id` IN (34, 2, 18, 17, 1, 7, 23, 24, 34, 27, 2, 1, 18, 27, 34, 34, 34, 1, 17, 27, 44, 16, 17, 1, 27, 27, 34, 1, 17, 2, 18, 19, 4, 42, 27, 34, 27, 34, 27, 4, 18, 2, 1, 17, 19, 23, 24);')
await connection.execute('SELECT `id`, `name` FROM `Supplies` AS `Supplies` WHERE `Supplies`.`id` IN (20, 16, 15, 1, 7);')
await connection.execute('SELECT `id`, `name`, `rank`, `wheniwork_id` FROM `ServiceRoles` AS `ServiceRoles` WHERE `ServiceRoles`.`id` IN (10, 7, 7, 7, 7, 7, 7, 7, 10, 3, 7, 7, 4, 4, 4, 4, 4, 4, 5, 4, 4, 4, 4, 4, 4, 3, 7, 17, 4, 4, 4, 4, 4, 4, 7, 7, 4, 4, 4, 4, 4, 4, 4, 10, 10, 4, 4, 4, 7, 7, 7, 10, 7, 7, 7, 7, 7, 3, 4, 18, 7, 7, 3, 4, 3, 4, 7, 7, 10, 3, 4, 4, 4, 4, 4, 4, 4, 7, 3, 3, 4, 4, 10, 4, 4, 3, 10, 4, 4, 4, 4, 4, 3, 3, 4, 4, 4, 4, 7);')
await connection.execute('SELECT `id`, `custom_id`, `company_id`, `person_id`, `position`, `reports_to`, `phone`, `phone1`, `email`, `status`, `hired_on`, `is_payroll`, `is_salary`, `is_wheniwork`, `wheniwork_id`, `is_contractor`, `payweb_emp_id`, `department` FROM `CompanyPeople` AS `CompanyPeople` WHERE `CompanyPeople`.`id` IN (205, 206, 282, 266, 266, 256, 304, 226, 278, 286, 275, 222, 296, 255, 300, 253, 304, 270, 282, 216, 206, 229, 253, 255, 270, 272, 271, 266, 266, 253, 235, 333, 299, 242, 226, 340, 229, 209, 234, 217, 230, 295, 295, 295, 209, 295, 295, 295, 295, 295, 274, 302, 717, 225, 295, 274, 270, 201, 717, 219, 227, 247, 223, 282, 277, 304, 302, 225);')
await connection.execute('SELECT `id`, `type_id`, `name`, `email`, `url`, `phone`, `fax`, `note`, `parent_company_id`, `primary_colour`, `secondary_colour`, `logo_url`, `url_prefix`, `verified_on` FROM `Companies` AS `Companies` WHERE `Companies`.`id` IN (18, 18, 18, 18, 18, 18, 19, 19, 19, 18, 19, 19, 18, 20, 18, 18, 20, 20, 18, 18);')
await connection.execute('SELECT `id`, `building_name`, `description`, `unit_designator`, `unit`, `floor`, `civic_number`, `civic_number_suffix`, `street_name`, `address_street_type_id`, `street_direction`, `rural_route`, `station`, `city_id`, `postal_code`, `notes`, `latitude`, `longitude` FROM `Addresses` AS `Addresses` WHERE `Addresses`.`id` IN (62, 50, 51, 50, 68, 50, 53, 53, 53, 48, 54, 53, 53, 55, 56, 57, 58, 60, 61, 56, 57, 57, 60, 61, 62);')
await connection.execute('SELECT `id`, `first_name`, `middle_name`, `last_name`, `common_name`, `title_id`, `email`, `phone`, `mobile_phone`, `phone_email`, `notes`, `born_on`, `social_insurance_number`, `drivers_license_number`, `emergency_contact_id` FROM `People` AS `People` WHERE `People`.`id` IN (55, 56, 138, 122, 122, 112, 160, 81, 134, 142, 131, 77, 152, 111, 156, 109, 160, 126, 138, 69, 56, 84, 109, 111, 126, 128, 127, 122, 122, 109, 91, 203, 155, 98, 81, 226, 84, 60, 90, 70, 85, 151, 151, 151, 60, 151, 151, 151, 151, 151, 130, 158, 57, 80, 151, 130, 126, 49, 57, 72, 82, 103, 78, 138, 133, 160, 158, 80);')
await connection.execute('SELECT `id`, `name`, `province_id` FROM `Cities` AS `Cities` WHERE `Cities`.`id` IN (52, 91, 52, 91, 15, 91, 12, 12, 12, 51, 91, 12, 12, 52, 91, 95, 91, 51, 51, 91, 95, 95, 51, 51, 52);')
await connection.execute('SELECT `id`, `country_id`, `abbreviation`, `name` FROM `Provinces` AS `Provinces` WHERE `Provinces`.`id` IN (1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1);')
console.timeEnd('queries')
GraphQL for completeness.
{
ProjectServices(limit: 20) {
occurs_at
occurs_on
id
status
Project {
name
Customer {
name
}
SubCustomer {
name
}
}
Service {
name
}
Addresses {
CompanyAddress {
Address {
civic_number
City {
name
Province {
name
}
}
}
}
}
Assets {
Asset {
name
}
}
Changes {
ChangedBy {
first_name
last_name
}
}
Equipments {
id
quantity_requested
quantity_actual
Equipment {
name
}
}
Supplies {
id
quantity
Supply {
name
}
}
Files {
id
file_url
name
description
mime_type
}
Notes {
id
entered_by
entered_on
content
}
People {
id
scheduled_in_at
scheduled_out_at
ServiceRole {
name
}
CompanyPerson {
Person {
name
}
}
}
}
}
I don't have any immediate guesses, if you could put together a benchmark project for me i'd love to dig into it.
Here are some resolver timings. It's difficult to know how much processing time is spent in each because they're wrapped in promises so I need to dive a bit deeper into the resolvers.
ProjectServices => ProjectServices 91.401ms
ProjectServices => Projects 526.224ms
ProjectServices => Services 552.470ms
ProjectServices => Addresses 178.386ms
ProjectServices => Assets 195.785ms
ProjectServices => Changes 233.250ms
ProjectServices => Equipments 450.416ms
ProjectServices => Supplies 473.899ms
ProjectServices => Files 472.306ms
ProjectServices => Notes 470.655ms
ProjectServices => People 468.616ms
ProjectServiceAddresses => CompanyAddresses 371.471ms
ProjectServiceChanges => ChangedBy 378.456ms
ProjectServiceChanges => ChangedBy 378.990ms
ProjectServiceChanges => ChangedBy 377.785ms
ProjectServiceChanges => ChangedBy 376.552ms
ProjectServiceChanges => ChangedBy 376.465ms
ProjectServiceChanges => ChangedBy 375.259ms
ProjectServiceChanges => ChangedBy 373.852ms
ProjectServiceChanges => ChangedBy 372.471ms
ProjectServiceChanges => ChangedBy 371.318ms
ProjectServiceChanges => ChangedBy 368.079ms
ProjectServiceChanges => ChangedBy 366.366ms
ProjectServiceChanges => ChangedBy 364.061ms
ProjectServiceChanges => ChangedBy 362.853ms
ProjectServiceChanges => ChangedBy 361.630ms
ProjectServiceChanges => ChangedBy 360.305ms
ProjectServiceChanges => ChangedBy 359.111ms
ProjectServiceChanges => ChangedBy 357.839ms
ProjectServiceChanges => ChangedBy 356.564ms
ProjectServiceChanges => ChangedBy 355.124ms
ProjectServiceChanges => ChangedBy 353.270ms
ProjectServiceChanges => ChangedBy 351.876ms
ProjectServiceChanges => ChangedBy 350.571ms
ProjectServiceChanges => ChangedBy 331.247ms
ProjectServiceChanges => ChangedBy 329.952ms
ProjectServiceChanges => ChangedBy 328.679ms
ProjectServiceChanges => ChangedBy 327.715ms
ProjectServiceChanges => ChangedBy 326.476ms
ProjectServiceChanges => ChangedBy 325.198ms
ProjectServiceChanges => ChangedBy 323.919ms
ProjectServiceChanges => ChangedBy 322.444ms
ProjectServiceChanges => ChangedBy 320.612ms
ProjectServiceChanges => ChangedBy 319.033ms
ProjectServiceChanges => ChangedBy 318.423ms
ProjectServiceChanges => ChangedBy 317.187ms
ProjectServiceChanges => ChangedBy 315.930ms
ProjectServiceChanges => ChangedBy 314.674ms
ProjectServiceChanges => ChangedBy 313.450ms
ProjectServiceChanges => ChangedBy 311.740ms
ProjectServiceChanges => ChangedBy 310.520ms
ProjectServiceChanges => ChangedBy 309.259ms
ProjectServiceChanges => ChangedBy 307.838ms
ProjectServiceChanges => ChangedBy 306.001ms
ProjectServiceChanges => ChangedBy 304.553ms
ProjectServiceChanges => ChangedBy 303.247ms
ProjectServiceChanges => ChangedBy 301.689ms
ProjectServiceChanges => ChangedBy 299.759ms
ProjectServiceChanges => ChangedBy 298.562ms
ProjectServiceChanges => ChangedBy 297.348ms
ProjectServiceChanges => ChangedBy 296.086ms
ProjectServiceChanges => ChangedBy 294.557ms
ProjectServiceChanges => ChangedBy 293.060ms
ProjectServiceChanges => ChangedBy 291.583ms
ProjectServiceChanges => ChangedBy 289.720ms
ProjectServiceChanges => ChangedBy 288.265ms
ProjectServiceChanges => ChangedBy 286.884ms
ProjectServiceChanges => ChangedBy 285.381ms
ProjectServiceChanges => ChangedBy 284.446ms
ProjectServiceChanges => ChangedBy 283.097ms
ProjectServiceChanges => ChangedBy 281.844ms
ProjectServiceChanges => ChangedBy 280.591ms
ProjectServiceChanges => ChangedBy 279.303ms
ProjectServiceEquipment => Equipments 186.500ms
ProjectServicePeople => ServiceRoles 165.631ms
ProjectServicePeople => CompanyPeople 163.798ms
ProjectServicePeople => ServiceRoles 161.566ms
ProjectServicePeople => CompanyPeople 41.475ms
ProjectServicePeople => ServiceRoles 158.696ms
ProjectServicePeople => CompanyPeople 38.673ms
ProjectServicePeople => ServiceRoles 155.925ms
ProjectServicePeople => CompanyPeople 35.957ms
ProjectServicePeople => ServiceRoles 153.161ms
ProjectServicePeople => CompanyPeople 33.231ms
ProjectServicePeople => ServiceRoles 149.358ms
ProjectServicePeople => CompanyPeople 29.006ms
ProjectServicePeople => ServiceRoles 145.655ms
ProjectServicePeople => CompanyPeople 24.999ms
ProjectServicePeople => ServiceRoles 141.975ms
ProjectServicePeople => CompanyPeople 21.737ms
Projects => Customer 128.778ms
Projects => SubCustomer 6.482ms
CompanyAddresses => Addresses 113.475ms
CompanyPeople => People 32.636ms
Addresses => Cities 18.732ms
Cities => Provinces 15.113ms
NODE_ENV=development was causing an order of magnitude performance hit. In case anyone runs into performance issues use, try NODE_ENV=testing or NODE_ENV=production first.
Calling resolvers is done by the underlying graphql library Hmm, i'd not think the NODE_ENV would impact it so greatly.
I didn't think so either. Here are the numbers for this query.
NODE_ENV=development
graphql 200 fetch VM197 graphql:61 78.9 KB 2.87 s
graphql 200 fetch VM197 graphql:61 78.8 KB 2.55 s
graphql 200 fetch VM197 graphql:61 78.8 KB 2.43 s
graphql 200 fetch VM197 graphql:61 78.8 KB 2.44 s
graphql 200 fetch VM197 graphql:61 78.8 KB 2.64 s
NODE_ENV=testing
graphql 200 fetch VM197 graphql:61 78.9 KB 487 ms
graphql 200 fetch VM197 graphql:61 78.8 KB 228 ms
graphql 200 fetch VM197 graphql:61 78.8 KB 190 ms
graphql 200 fetch VM197 graphql:61 78.8 KB 239 ms
graphql 200 fetch VM197 graphql:61 78.8 KB 191 ms
graphql 200 fetch VM197 graphql:61 78.8 KB 178 ms
graphql 200 fetch VM197 graphql:61 78.8 KB 157 ms
graphql 200 fetch VM197 graphql:61 78.8 KB 170 ms
I have a question about performance.
The following GraphQL query.
Generates the following SQL statements.
Timing when run with the MySQL command line client.
Total: 3.63 ms
When run through node -> koa -> graphql -> sequelize -> mysql2
Total: 466ms
Versions
Does this stack really introduce a 12,837% performance hit or am I doing something wrong?