ERPNext Conference 2019* ERPNext.com Blog

Often refused to connect


#1

Hello,
I have an ERPnext instance on a VPS (1 vCPU, 2GB RAM). Sometimes it refused to connect and I have to ‘’‘bench restart ‘’’ when it happens. I do not see any abnormality in error log ~/frappe/frappe-bench/logs/*

Can you give me clue on what should I investigate to prevent this? Thank you
EDIT:
Here I attach log, with currently 3 active user on 1 site (other 2 sites are for testing purposes)

14:00:04 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'frappe.limits.update_space_usage', kwargs={}, method=u'frappe.limits.update_space_usage', site=u'kdb.mydomain.com', user=u'Administrator') (6a5f20d5-1502-4e1e-9eb9-2c3868423298)

==> logs/frappe.log <==

[DEBUG] 2019-09-11 14:00:04,586 | /home/frappe/frappe-bench/apps/frappe/frappe/utils/scheduler.py:

Site: mti.mydomain.com

Queued events for site mti.mydomain.com

==> logs/worker.error.log <==

14:00:04 short: Job OK (6a5f20d5-1502-4e1e-9eb9-2c3868423298)

14:00:04 Result is kept for 500 seconds

14:00:04 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'frappe.limits.update_site_usage', kwargs={}, method=u'frappe.limits.update_site_usage', site=u'kdb.mydomain.com', user=u'Administrator') (c5b3d523-4440-4f73-a5a2-d8e48abd5639)

==> logs/frappe.log <==

[DEBUG] 2019-09-11 14:00:04,849 | /home/frappe/frappe-bench/apps/frappe/frappe/utils/scheduler.py:

Site: mti3.mydomain.com

Queued events for site mti3.mydomain.com

==> logs/worker.error.log <==

14:00:04 short: Job OK (c5b3d523-4440-4f73-a5a2-d8e48abd5639)

14:00:04 Result is kept for 500 seconds

14:00:04 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'frappe.desk.doctype.auto_repeat.auto_repeat.make_auto_repeat_entry', kwargs={}, method=u'frappe.desk.doctype.auto_repeat.auto_repeat.make_auto_repeat_entry', site=u'kdb.mydomain.com', user=u'Administrator') (9e7634cf-8a09-4743-b69a-c10fc77aa2b2)

14:00:04 short: Job OK (9e7634cf-8a09-4743-b69a-c10fc77aa2b2)

14:00:04 Result is kept for 500 seconds

14:00:04 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'erpnext.hr.doctype.daily_work_summary_group.daily_work_summary_group.trigger_emails', kwargs={}, method=u'erpnext.hr.doctype.daily_work_summary_group.daily_work_summary_group.trigger_emails', site=u'kdb.mydomain.com', user=u'Administrator') (758eebde-d87d-4543-b5ae-2c9ee7b8b156)

14:00:04 short: Job OK (758eebde-d87d-4543-b5ae-2c9ee7b8b156)

14:00:04 Result is kept for 500 seconds

14:00:04 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'erpnext.accounts.doctype.subscription.subscription.process_all', kwargs={}, method=u'erpnext.accounts.doctype.subscription.subscription.process_all', site=u'kdb.mydomain.com', user=u'Administrator') (07a55885-2f7c-414c-b36e-50fe05b3010d)

14:00:05 short: Job OK (07a55885-2f7c-414c-b36e-50fe05b3010d)

14:00:05 Result is kept for 500 seconds

14:00:05 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'erpnext.erpnext_integrations.doctype.amazon_mws_settings.amazon_mws_settings.schedule_get_order_details', kwargs={}, method=u'erpnext.erpnext_integrations.doctype.amazon_mws_settings.amazon_mws_settings.schedule_get_order_details', site=u'kdb.mydomain.com', user=u'Administrator') (3f721549-d277-4fa5-965d-4f3e4111a35f)

14:00:05 short: Job OK (3f721549-d277-4fa5-965d-4f3e4111a35f)

14:00:05 Result is kept for 500 seconds

14:00:05 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'erpnext.erpnext_integrations.doctype.plaid_settings.plaid_settings.automatic_synchronization', kwargs={}, method=u'erpnext.erpnext_integrations.doctype.plaid_settings.plaid_settings.automatic_synchronization', site=u'kdb.mydomain.com', user=u'Administrator') (469f4b03-b31c-455a-a4f1-bde3c1e816bc)

14:00:05 short: Job OK (469f4b03-b31c-455a-a4f1-bde3c1e816bc)

14:00:05 Result is kept for 500 seconds

14:00:05 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'erpnext.projects.doctype.project.project.hourly_reminder', kwargs={}, method=u'erpnext.projects.doctype.project.project.hourly_reminder', site=u'kdb.mydomain.com', user=u'Administrator') (bcbbd613-59fe-4757-a3fa-65858c1568a3)

14:00:05 short: Job OK (bcbbd613-59fe-4757-a3fa-65858c1568a3)

14:00:05 Result is kept for 500 seconds

14:00:05 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'erpnext.projects.doctype.project.project.collect_project_status', kwargs={}, method=u'erpnext.projects.doctype.project.project.collect_project_status', site=u'kdb.mydomain.com', user=u'Administrator') (626a4012-3a6d-4e41-8a0d-fc3f09b4b904)

14:00:05 short: Job OK (626a4012-3a6d-4e41-8a0d-fc3f09b4b904)

14:00:05 Result is kept for 500 seconds

14:00:05 short: frappe.utils.background_jobs.execute_job(event=u'all', is_async=True, job_name=u'frappe.email.queue.flush', kwargs={}, method=u'frappe.email.queue.flush', site=u'kdb.mydomain.com', user=u'Administrator') (7f75e74e-65ad-4cad-8973-2a690f6a5524)

14:00:05 short: Job OK (7f75e74e-65ad-4cad-8973-2a690f6a5524)

14:00:05 Result is kept for 500 seconds

14:00:05 short: frappe.utils.background_jobs.execute_job(event=u'all', is_async=True, job_name=u'frappe.email.doctype.email_account.email_account.pull', kwargs={}, method=u'frappe.email.doctype.email_account.email_account.pull', site=u'kdb.mydomain.com', user=u'Administrator') (8ba62d3e-4257-4c8c-b572-5837110d1935)

14:00:05 short: Job OK (8ba62d3e-4257-4c8c-b572-5837110d1935)

14:00:05 Result is kept for 500 seconds

14:00:05 short: frappe.utils.background_jobs.execute_job(event=u'all', is_async=True, job_name=u'frappe.email.doctype.email_account.email_account.notify_unreplied', kwargs={}, method=u'frappe.email.doctype.email_account.email_account.notify_unreplied', site=u'kdb.mydomain.com', user=u'Administrator') (a36a710b-9a92-45bd-a653-3bf988288390)

14:00:05 short: Job OK (a36a710b-9a92-45bd-a653-3bf988288390)

14:00:05 Result is kept for 500 seconds

14:00:05 short: frappe.utils.background_jobs.execute_job(event=u'all', is_async=True, job_name=u'frappe.oauth.delete_oauth2_data', kwargs={}, method=u'frappe.oauth.delete_oauth2_data', site=u'kdb.mydomain.com', user=u'Administrator') (3fc9bd90-13a2-47eb-9673-81937ca89feb)

14:00:05 short: Job OK (3fc9bd90-13a2-47eb-9673-81937ca89feb)

14:00:05 Result is kept for 500 seconds

14:00:05 short: frappe.utils.background_jobs.execute_job(event=u'all', is_async=True, job_name=u'frappe.integrations.doctype.razorpay_settings.razorpay_settings.capture_payment', kwargs={}, method=u'frappe.integrations.doctype.razorpay_settings.razorpay_settings.capture_payment', site=u'kdb.mydomain.com', user=u'Administrator') (7c42786d-ae38-4b8c-b716-1ebe07a7ba14)

14:00:05 short: Job OK (7c42786d-ae38-4b8c-b716-1ebe07a7ba14)

14:00:05 Result is kept for 500 seconds

14:00:05 short: frappe.utils.background_jobs.execute_job(event=u'all', is_async=True, job_name=u'frappe.twofactor.delete_all_barcodes_for_users', kwargs={}, method=u'frappe.twofactor.delete_all_barcodes_for_users', site=u'kdb.mydomain.com', user=u'Administrator') (ade40a78-6e84-42d8-92af-24f577763d67)

14:00:05 short: Job OK (ade40a78-6e84-42d8-92af-24f577763d67)

14:00:05 Result is kept for 500 seconds

14:00:05 short: frappe.utils.background_jobs.execute_job(event=u'all', is_async=True, job_name=u'frappe.integrations.doctype.gcalendar_settings.gcalendar_settings.sync', kwargs={}, method=u'frappe.integrations.doctype.gcalendar_settings.gcalendar_settings.sync', site=u'kdb.mydomain.com', user=u'Administrator') (1f91912e-cc5a-4053-b2b5-8fb436815bc7)

14:00:05 short: Job OK (1f91912e-cc5a-4053-b2b5-8fb436815bc7)

14:00:05 Result is kept for 500 seconds

14:00:05 short: frappe.utils.background_jobs.execute_job(event=u'all', is_async=True, job_name=u'frappe.website.doctype.web_page.web_page.check_publish_status', kwargs={}, method=u'frappe.website.doctype.web_page.web_page.check_publish_status', site=u'kdb.mydomain.com', user=u'Administrator') (51a3fdd3-22d4-4719-805e-d57a9be2714a)

14:00:05 short: Job OK (51a3fdd3-22d4-4719-805e-d57a9be2714a)

14:00:05 Result is kept for 500 seconds

14:00:05 short: frappe.utils.background_jobs.execute_job(event=u'all', is_async=True, job_name=u'frappe.utils.global_search.sync_global_search', kwargs={}, method=u'frappe.utils.global_search.sync_global_search', site=u'kdb.mydomain.com', user=u'Administrator') (52998845-2c97-45aa-a909-934e4f06bd75)

14:00:05 short: Job OK (52998845-2c97-45aa-a909-934e4f06bd75)

14:00:05 Result is kept for 500 seconds

14:00:05 short: frappe.utils.background_jobs.execute_job(event=u'all', is_async=True, job_name=u'erpnext.projects.doctype.project.project.project_status_update_reminder', kwargs={}, method=u'erpnext.projects.doctype.project.project.project_status_update_reminder', site=u'kdb.mydomain.com', user=u'Administrator') (24ced416-8feb-4e4f-9611-6f8626dd08a3)

14:00:05 short: Job OK (24ced416-8feb-4e4f-9611-6f8626dd08a3)

14:00:05 Result is kept for 500 seconds

14:00:05 short: frappe.utils.background_jobs.execute_job(event=u'all', is_async=True, job_name=u'frappe.email.queue.flush', kwargs={}, method=u'frappe.email.queue.flush', site=u'mti.mydomain.com', user=u'Administrator') (0c5c62d3-ac97-4ddc-986c-41c5a10786cd)

14:00:05 short: Job OK (0c5c62d3-ac97-4ddc-986c-41c5a10786cd)

14:00:05 Result is kept for 500 seconds

14:00:05 short: frappe.utils.background_jobs.execute_job(event=u'all', is_async=True, job_name=u'frappe.email.doctype.email_account.email_account.pull', kwargs={}, method=u'frappe.email.doctype.email_account.email_account.pull', site=u'mti.mydomain.com', user=u'Administrator') (660a2e8f-f4c2-47be-bb6f-6e5af4cb3c59)

14:00:05 short: Job OK (660a2e8f-f4c2-47be-bb6f-6e5af4cb3c59)

14:00:05 Result is kept for 500 seconds

14:00:05 short: frappe.utils.background_jobs.execute_job(event=u'all', is_async=True, job_name=u'frappe.email.doctype.email_account.email_account.notify_unreplied', kwargs={}, method=u'frappe.email.doctype.email_account.email_account.notify_unreplied', site=u'mti.mydomain.com', user=u'Administrator') (c079c008-9714-48d6-9d2a-34701c0df7d6)

14:00:05 short: Job OK (c079c008-9714-48d6-9d2a-34701c0df7d6)

14:00:05 Result is kept for 500 seconds

14:00:05 short: frappe.utils.background_jobs.execute_job(event=u'all', is_async=True, job_name=u'frappe.oauth.delete_oauth2_data', kwargs={}, method=u'frappe.oauth.delete_oauth2_data', site=u'mti.mydomain.com', user=u'Administrator') (d768b3ce-9018-4960-a365-cff5eea598cd)

14:00:06 short: Job OK (d768b3ce-9018-4960-a365-cff5eea598cd)

14:00:06 Result is kept for 500 seconds

14:00:06 short: frappe.utils.background_jobs.execute_job(event=u'all', is_async=True, job_name=u'frappe.integrations.doctype.razorpay_settings.razorpay_settings.capture_payment', kwargs={}, method=u'frappe.integrations.doctype.razorpay_settings.razorpay_settings.capture_payment', site=u'mti.mydomain.com', user=u'Administrator') (9344a797-ad94-4b60-84fe-140e08923e40)

14:00:06 short: Job OK (9344a797-ad94-4b60-84fe-140e08923e40)

14:00:06 Result is kept for 500 seconds

14:00:06 short: frappe.utils.background_jobs.execute_job(event=u'all', is_async=True, job_name=u'frappe.twofactor.delete_all_barcodes_for_users', kwargs={}, method=u'frappe.twofactor.delete_all_barcodes_for_users', site=u'mti.mydomain.com', user=u'Administrator') (3e6d7dca-5fff-43ef-af14-c2498d76c079)

14:00:06 short: Job OK (3e6d7dca-5fff-43ef-af14-c2498d76c079)

14:00:06 Result is kept for 500 seconds

14:00:06 short: frappe.utils.background_jobs.execute_job(event=u'all', is_async=True, job_name=u'frappe.integrations.doctype.gcalendar_settings.gcalendar_settings.sync', kwargs={}, method=u'frappe.integrations.doctype.gcalendar_settings.gcalendar_settings.sync', site=u'mti.mydomain.com', user=u'Administrator') (b03c90ec-63ca-4c21-b2f8-51e061863a42)

14:00:06 short: Job OK (b03c90ec-63ca-4c21-b2f8-51e061863a42)

14:00:06 Result is kept for 500 seconds

14:00:06 short: frappe.utils.background_jobs.execute_job(event=u'all', is_async=True, job_name=u'frappe.website.doctype.web_page.web_page.check_publish_status', kwargs={}, method=u'frappe.website.doctype.web_page.web_page.check_publish_status', site=u'mti.mydomain.com', user=u'Administrator') (81126905-2a63-48ce-92db-9ba902bbafdb)

14:00:06 short: Job OK (81126905-2a63-48ce-92db-9ba902bbafdb)

14:00:06 Result is kept for 500 seconds

14:00:06 short: frappe.utils.background_jobs.execute_job(event=u'all', is_async=True, job_name=u'frappe.utils.global_search.sync_global_search', kwargs={}, method=u'frappe.utils.global_search.sync_global_search', site=u'mti.mydomain.com', user=u'Administrator') (c7f79d43-a55d-4218-b5cc-eb9859da175d)

14:00:06 short: Job OK (c7f79d43-a55d-4218-b5cc-eb9859da175d)

14:00:06 Result is kept for 500 seconds

14:00:06 short: frappe.utils.background_jobs.execute_job(event=u'all', is_async=True, job_name=u'erpnext.projects.doctype.project.project.project_status_update_reminder', kwargs={}, method=u'erpnext.projects.doctype.project.project.project_status_update_reminder', site=u'mti.mydomain.com', user=u'Administrator') (efb8d352-1d58-4755-b311-9c049ee92909)

14:00:06 short: Job OK (efb8d352-1d58-4755-b311-9c049ee92909)

14:00:06 Result is kept for 500 seconds

14:00:06 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'frappe.model.utils.link_count.update_link_count', kwargs={}, method=u'frappe.model.utils.link_count.update_link_count', site=u'mti.mydomain.com', user=u'Administrator') (0924c7cf-a942-4549-a830-fe59b10f1269)

14:00:06 short: Job OK (0924c7cf-a942-4549-a830-fe59b10f1269)

14:00:06 Result is kept for 500 seconds

14:00:06 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'frappe.model.utils.user_settings.sync_user_settings', kwargs={}, method=u'frappe.model.utils.user_settings.sync_user_settings', site=u'mti.mydomain.com', user=u'Administrator') (b65b6be6-aa35-4400-a0dc-f318183b3899)

14:00:06 short: Job OK (b65b6be6-aa35-4400-a0dc-f318183b3899)

14:00:06 Result is kept for 500 seconds

14:00:06 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'frappe.utils.error.collect_error_snapshots', kwargs={}, method=u'frappe.utils.error.collect_error_snapshots', site=u'mti.mydomain.com', user=u'Administrator') (a0493551-4bdb-49ae-9b5a-85382878d2c9)

14:00:06 short: Job OK (a0493551-4bdb-49ae-9b5a-85382878d2c9)

14:00:06 Result is kept for 500 seconds

14:00:06 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'frappe.desk.page.backups.backups.delete_downloadable_backups', kwargs={}, method=u'frappe.desk.page.backups.backups.delete_downloadable_backups', site=u'mti.mydomain.com', user=u'Administrator') (ad1efbba-a77e-4b55-81f1-1d0a31235e36)

14:00:06 short: Job OK (ad1efbba-a77e-4b55-81f1-1d0a31235e36)

14:00:06 Result is kept for 500 seconds

14:00:06 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'frappe.limits.update_space_usage', kwargs={}, method=u'frappe.limits.update_space_usage', site=u'mti.mydomain.com', user=u'Administrator') (bf35c729-e0ee-4039-a671-230ab5496ca3)

14:00:06 short: Job OK (bf35c729-e0ee-4039-a671-230ab5496ca3)

14:00:06 Result is kept for 500 seconds

14:00:06 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'frappe.limits.update_site_usage', kwargs={}, method=u'frappe.limits.update_site_usage', site=u'mti.mydomain.com', user=u'Administrator') (ed8ec957-74c6-414f-8d6d-ae0d493c3a3c)

14:00:06 short: Job OK (ed8ec957-74c6-414f-8d6d-ae0d493c3a3c)

14:00:06 Result is kept for 500 seconds

14:00:06 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'frappe.desk.doctype.auto_repeat.auto_repeat.make_auto_repeat_entry', kwargs={}, method=u'frappe.desk.doctype.auto_repeat.auto_repeat.make_auto_repeat_entry', site=u'mti.mydomain.com', user=u'Administrator') (755fee16-405a-4167-9181-45ad7e3565fc)

14:00:06 short: Job OK (755fee16-405a-4167-9181-45ad7e3565fc)

14:00:06 Result is kept for 500 seconds

14:00:06 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'erpnext.hr.doctype.daily_work_summary_group.daily_work_summary_group.trigger_emails', kwargs={}, method=u'erpnext.hr.doctype.daily_work_summary_group.daily_work_summary_group.trigger_emails', site=u'mti.mydomain.com', user=u'Administrator') (ca6e88b4-2046-40e5-8f53-52db007fe8a0)

14:00:06 short: Job OK (ca6e88b4-2046-40e5-8f53-52db007fe8a0)

14:00:06 Result is kept for 500 seconds

14:00:06 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'erpnext.accounts.doctype.subscription.subscription.process_all', kwargs={}, method=u'erpnext.accounts.doctype.subscription.subscription.process_all', site=u'mti.mydomain.com', user=u'Administrator') (074de0d1-a858-4384-b027-1daafe81fa3f)

14:00:06 short: Job OK (074de0d1-a858-4384-b027-1daafe81fa3f)

14:00:06 Result is kept for 500 seconds

14:00:06 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'erpnext.erpnext_integrations.doctype.amazon_mws_settings.amazon_mws_settings.schedule_get_order_details', kwargs={}, method=u'erpnext.erpnext_integrations.doctype.amazon_mws_settings.amazon_mws_settings.schedule_get_order_details', site=u'mti.mydomain.com', user=u'Administrator') (2bcad146-f44e-4d95-a75b-d4b9d58f298e)

14:00:07 short: Job OK (2bcad146-f44e-4d95-a75b-d4b9d58f298e)

14:00:07 Result is kept for 500 seconds

14:00:07 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'erpnext.erpnext_integrations.doctype.plaid_settings.plaid_settings.automatic_synchronization', kwargs={}, method=u'erpnext.erpnext_integrations.doctype.plaid_settings.plaid_settings.automatic_synchronization', site=u'mti.mydomain.com', user=u'Administrator') (3bc9b279-bb16-4dd7-9f3b-2df335180352)

14:00:07 short: Job OK (3bc9b279-bb16-4dd7-9f3b-2df335180352)

14:00:07 Result is kept for 500 seconds

14:00:07 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'erpnext.projects.doctype.project.project.hourly_reminder', kwargs={}, method=u'erpnext.projects.doctype.project.project.hourly_reminder', site=u'mti.mydomain.com', user=u'Administrator') (1eac219c-790d-4388-b92a-c9cedbc87406)

14:00:07 short: Job OK (1eac219c-790d-4388-b92a-c9cedbc87406)

14:00:07 Result is kept for 500 seconds

14:00:07 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'erpnext.projects.doctype.project.project.collect_project_status', kwargs={}, method=u'erpnext.projects.doctype.project.project.collect_project_status', site=u'mti.mydomain.com', user=u'Administrator') (cda5317a-4290-4cea-8601-c15365e60969)

14:00:07 short: Job OK (cda5317a-4290-4cea-8601-c15365e60969)

14:00:07 Result is kept for 500 seconds

14:00:07 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'frappe.model.utils.link_count.update_link_count', kwargs={}, method=u'frappe.model.utils.link_count.update_link_count', site=u'mti3.mydomain.com', user=u'Administrator') (5d055596-dc61-4bd7-8993-78ac1df7cb0c)

14:00:07 short: Job OK (5d055596-dc61-4bd7-8993-78ac1df7cb0c)

14:00:07 Result is kept for 500 seconds

14:00:07 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'frappe.model.utils.user_settings.sync_user_settings', kwargs={}, method=u'frappe.model.utils.user_settings.sync_user_settings', site=u'mti3.mydomain.com', user=u'Administrator') (7d54e796-fc26-48dd-b686-8a421eca0c78)

14:00:07 short: Job OK (7d54e796-fc26-48dd-b686-8a421eca0c78)

14:00:07 Result is kept for 500 seconds

14:00:07 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'frappe.utils.error.collect_error_snapshots', kwargs={}, method=u'frappe.utils.error.collect_error_snapshots', site=u'mti3.mydomain.com', user=u'Administrator') (a96f1283-1073-40cc-bb15-9ddd623a1836)

14:00:07 short: Job OK (a96f1283-1073-40cc-bb15-9ddd623a1836)

14:00:07 Result is kept for 500 seconds

14:00:07 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'frappe.desk.page.backups.backups.delete_downloadable_backups', kwargs={}, method=u'frappe.desk.page.backups.backups.delete_downloadable_backups', site=u'mti3.mydomain.com', user=u'Administrator') (74aadcd4-050b-4469-8dca-a930223dcb20)

14:00:07 short: Job OK (74aadcd4-050b-4469-8dca-a930223dcb20)

14:00:07 Result is kept for 500 seconds

14:00:07 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'frappe.limits.update_space_usage', kwargs={}, method=u'frappe.limits.update_space_usage', site=u'mti3.mydomain.com', user=u'Administrator') (e15c528f-1a0f-4e58-8b88-e036b8e9dbf1)

14:00:07 short: Job OK (e15c528f-1a0f-4e58-8b88-e036b8e9dbf1)

14:00:07 Result is kept for 500 seconds

14:00:07 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'frappe.limits.update_site_usage', kwargs={}, method=u'frappe.limits.update_site_usage', site=u'mti3.mydomain.com', user=u'Administrator') (7a633b41-a263-4166-9bf6-ad39620fa638)

14:00:07 short: Job OK (7a633b41-a263-4166-9bf6-ad39620fa638)

14:00:07 Result is kept for 500 seconds

14:00:07 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'frappe.desk.doctype.auto_repeat.auto_repeat.make_auto_repeat_entry', kwargs={}, method=u'frappe.desk.doctype.auto_repeat.auto_repeat.make_auto_repeat_entry', site=u'mti3.mydomain.com', user=u'Administrator') (8ee2f072-8734-4d57-a490-25f37e929a78)

14:00:07 short: Job OK (8ee2f072-8734-4d57-a490-25f37e929a78)

14:00:07 Result is kept for 500 seconds

14:00:07 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'erpnext.hr.doctype.daily_work_summary_group.daily_work_summary_group.trigger_emails', kwargs={}, method=u'erpnext.hr.doctype.daily_work_summary_group.daily_work_summary_group.trigger_emails', site=u'mti3.mydomain.com', user=u'Administrator') (7415b140-e219-4ee0-9617-ebfeb7f6f0e0)

14:00:07 short: Job OK (7415b140-e219-4ee0-9617-ebfeb7f6f0e0)

14:00:07 Result is kept for 500 seconds

14:00:07 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'erpnext.accounts.doctype.subscription.subscription.process_all', kwargs={}, method=u'erpnext.accounts.doctype.subscription.subscription.process_all', site=u'mti3.mydomain.com', user=u'Administrator') (2c2a49de-14ed-422e-b64c-22be4262783d)

14:00:07 short: Job OK (2c2a49de-14ed-422e-b64c-22be4262783d)

14:00:07 Result is kept for 500 seconds

14:00:07 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'erpnext.erpnext_integrations.doctype.amazon_mws_settings.amazon_mws_settings.schedule_get_order_details', kwargs={}, method=u'erpnext.erpnext_integrations.doctype.amazon_mws_settings.amazon_mws_settings.schedule_get_order_details', site=u'mti3.mydomain.com', user=u'Administrator') (fad5eb32-d33c-4dc0-afa1-a965bd2ab1c9)

14:00:08 short: Job OK (fad5eb32-d33c-4dc0-afa1-a965bd2ab1c9)

14:00:08 Result is kept for 500 seconds

14:00:08 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'erpnext.erpnext_integrations.doctype.plaid_settings.plaid_settings.automatic_synchronization', kwargs={}, method=u'erpnext.erpnext_integrations.doctype.plaid_settings.plaid_settings.automatic_synchronization', site=u'mti3.mydomain.com', user=u'Administrator') (5696a6a6-b8d7-4029-96c0-ea4f2ae61c11)

14:00:08 short: Job OK (5696a6a6-b8d7-4029-96c0-ea4f2ae61c11)

14:00:08 Result is kept for 500 seconds

14:00:08 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'erpnext.projects.doctype.project.project.hourly_reminder', kwargs={}, method=u'erpnext.projects.doctype.project.project.hourly_reminder', site=u'mti3.mydomain.com', user=u'Administrator') (6a38c1de-2e12-42c8-a7fc-26fbbc991912)

14:00:08 short: Job OK (6a38c1de-2e12-42c8-a7fc-26fbbc991912)

14:00:08 Result is kept for 500 seconds

14:00:08 short: frappe.utils.background_jobs.execute_job(event=u'hourly', is_async=True, job_name=u'erpnext.projects.doctype.project.project.collect_project_status', kwargs={}, method=u'erpnext.projects.doctype.project.project.collect_project_status', site=u'mti3.mydomain.com', user=u'Administrator') (5bf9e664-fc13-4c3b-86b9-71c7a8d06ba8)

14:00:08 short: Job OK (5bf9e664-fc13-4c3b-86b9-71c7a8d06ba8)

14:00:08 Result is kept for 500 seconds

14:00:08 short: frappe.utils.background_jobs.execute_job(event=u'all', is_async=True, job_name=u'frappe.email.queue.flush', kwargs={}, method=u'frappe.email.queue.flush', site=u'mti3.mydomain.com', user=u'Administrator') (221210b7-68dd-4cff-8f9d-e49a4a40fc50)

14:00:08 short: Job OK (221210b7-68dd-4cff-8f9d-e49a4a40fc50)

14:00:08 Result is kept for 500 seconds

14:00:08 short: frappe.utils.background_jobs.execute_job(event=u'all', is_async=True, job_name=u'frappe.email.doctype.email_account.email_account.pull', kwargs={}, method=u'frappe.email.doctype.email_account.email_account.pull', site=u'mti3.mydomain.com', user=u'Administrator') (d36d5204-a02a-49e4-9d02-af559260e66e)

14:00:08 short: Job OK (d36d5204-a02a-49e4-9d02-af559260e66e)

14:00:08 Result is kept for 500 seconds

14:00:08 short: frappe.utils.background_jobs.execute_job(event=u'all', is_async=True, job_name=u'frappe.email.doctype.email_account.email_account.notify_unreplied', kwargs={}, method=u'frappe.email.doctype.email_account.email_account.notify_unreplied', site=u'mti3.mydomain.com', user=u'Administrator') (ce073514-479b-4a46-b0b7-d0bd84171dc9)

14:00:08 short: Job OK (ce073514-479b-4a46-b0b7-d0bd84171dc9)

14:00:08 Result is kept for 500 seconds

14:00:08 short: frappe.utils.background_jobs.execute_job(event=u'all', is_async=True, job_name=u'frappe.oauth.delete_oauth2_data', kwargs={}, method=u'frappe.oauth.delete_oauth2_data', site=u'mti3.mydomain.com', user=u'Administrator') (f0d6e7da-6566-411f-9d00-192e44a37743)

14:00:09 short: Job OK (f0d6e7da-6566-411f-9d00-192e44a37743)

14:00:09 Result is kept for 500 seconds

14:00:09 short: frappe.utils.background_jobs.execute_job(event=u'all', is_async=True, job_name=u'frappe.integrations.doctype.razorpay_settings.razorpay_settings.capture_payment', kwargs={}, method=u'frappe.integrations.doctype.razorpay_settings.razorpay_settings.capture_payment', site=u'mti3.mydomain.com', user=u'Administrator') (412776f5-88b5-4874-af63-5471cce2cf9c)

14:00:09 short: Job OK (412776f5-88b5-4874-af63-5471cce2cf9c)

14:00:09 Result is kept for 500 seconds

14:00:09 short: frappe.utils.background_jobs.execute_job(event=u'all', is_async=True, job_name=u'frappe.twofactor.delete_all_barcodes_for_users', kwargs={}, method=u'frappe.twofactor.delete_all_barcodes_for_users', site=u'mti3.mydomain.com', user=u'Administrator') (ab0356c9-eb4c-4696-aaec-e1f11749d854)

14:00:09 short: Job OK (ab0356c9-eb4c-4696-aaec-e1f11749d854)

14:00:09 Result is kept for 500 seconds

14:00:09 short: frappe.utils.background_jobs.execute_job(event=u'all', is_async=True, job_name=u'frappe.integrations.doctype.gcalendar_settings.gcalendar_settings.sync', kwargs={}, method=u'frappe.integrations.doctype.gcalendar_settings.gcalendar_settings.sync', site=u'mti3.mydomain.com', user=u'Administrator') (1a01c9ed-02d6-4cfd-8e52-e2614ef84280)

14:00:09 short: Job OK (1a01c9ed-02d6-4cfd-8e52-e2614ef84280)

14:00:09 Result is kept for 500 seconds

14:00:09 short: frappe.utils.background_jobs.execute_job(event=u'all', is_async=True, job_name=u'frappe.website.doctype.web_page.web_page.check_publish_status', kwargs={}, method=u'frappe.website.doctype.web_page.web_page.check_publish_status', site=u'mti3.mydomain.com', user=u'Administrator') (5e080c64-a282-46da-86e5-4dbaf20e1a85)

14:00:09 short: Job OK (5e080c64-a282-46da-86e5-4dbaf20e1a85)

14:00:09 Result is kept for 500 seconds

14:00:09 short: frappe.utils.background_jobs.execute_job(event=u'all', is_async=True, job_name=u'frappe.utils.global_search.sync_global_search', kwargs={}, method=u'frappe.utils.global_search.sync_global_search', site=u'mti3.mydomain.com', user=u'Administrator') (79b46cdb-454a-4a0e-ac8e-3cbadd290ed6)

14:00:09 short: Job OK (79b46cdb-454a-4a0e-ac8e-3cbadd290ed6)

14:00:09 Result is kept for 500 seconds

14:00:09 short: frappe.utils.background_jobs.execute_job(event=u'all', is_async=True, job_name=u'erpnext.projects.doctype.project.project.project_status_update_reminder', kwargs={}, method=u'erpnext.projects.doctype.project.project.project_status_update_reminder', site=u'mti3.mydomain.com', user=u'Administrator') (b3557162-5c40-41b1-86e4-b04f5796bd3e)

14:00:09 short: Job OK (b3557162-5c40-41b1-86e4-b04f5796bd3e)

14:00:09 Result is kept for 500 seconds

==> logs/frappe.log <==

[DEBUG] 2019-09-11 14:01:04,931 | /home/frappe/frappe-bench/apps/frappe/frappe/utils/scheduler.py:

Site: kdb.mydomain.com

Queued events for site kdb.mydomain.com

[DEBUG] 2019-09-11 14:01:04,945 | /home/frappe/frappe-bench/apps/frappe/frappe/utils/scheduler.py:

Site: mti.mydomain.com

Queued events for site mti.mydomain.com

[DEBUG] 2019-09-11 14:01:04,960 | /home/frappe/frappe-bench/apps/frappe/frappe/utils/scheduler.py:

Site: mti3.mydomain.com

Queued events for site mti3.mydomain.com

#2

update: I still unable to trace what is the problem. Does TOP command result help me to trace it?

top - 09:25:12 up 58 days, 19:24,  1 user,  load average: 0.02, 0.08, 0.14
Tasks: 118 total,   1 running,  78 sleeping,   0 stopped,   0 zombie
%Cpu(s):  1.3 us,  0.3 sy,  0.0 ni, 98.0 id,  0.3 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem :  2041232 total,   579808 free,  1198648 used,   262776 buff/cache
KiB Swap:  2097148 total,  1934588 free,   162560 used.   686564 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND                              
  667 dnsmasq   20   0   52872   2160   1892 S  0.0  0.1 246:02.50 dnsmasq                              
  638 root      20   0  445660  17980   4772 S  0.0  0.9 103:52.17 fail2ban-server                      
  678 redis     20   0   51444   2168   2028 S  0.0  0.1  89:37.10 redis-server                         
30139 mysql     20   0 2076560 639604   9228 S  0.3 31.3  71:41.00 mysqld                               
    8 root      20   0       0      0      0 I  0.0  0.0  63:06.80 rcu_sched                            
 1277 frappe    20   0   51444   3464   2584 S  0.0  0.2  59:29.05 redis-server                         
 1278 frappe    20   0   76020  11844   2580 S  0.0  0.6  55:02.75 redis-server                         
 1279 frappe    20   0   51444   2908   2632 S  0.0  0.1  43:50.04 redis-server                         
  616 root      20   0   67664   8516   3692 S  0.0  0.4  31:46.58 supervisord                          
    7 root      20   0       0      0      0 S  0.0  0.0   9:32.50 ksoftirqd/0                          
11759 systemd+  20   0   74152   7504   3756 S  0.0  0.4   2:59.70 systemd-resolve                      
  618 root      20   0  287620   2340   1756 S  0.0  0.1   2:46.12 accounts-daemon                      
  622 message+  20   0   50292   3800   3116 S  0.0  0.2   2:31.35 dbus-daemon                          
  167 root       0 -20       0      0      0 I  0.0  0.0   2:09.97 kworker/0:1H                         
  341 root      20   0       0      0      0 S  0.0  0.0   2:05.91 jbd2/sda-8                           
    1 root      20   0  225476   6164   3740 S  0.0  0.3   1:49.63 systemd                              
  789 root      20   0   72296   3376   3272 S  0.0  0.2   1:20.76 sshd                                 
  608 syslog    20   0  263036   3480   2404 S  0.0  0.2   1:20.33 rsyslogd                             
  645 root      20   0  288880   2576   2140 S  0.0  0.1   1:15.06 polkitd                              
13184 www-data  20   0   47676   7340   4792 S  0.0  0.4   0:45.24 nginx                                
11727 systemd+  20   0   71848   2880   2632 S  0.0  0.1   0:30.95 systemd-network                      
  839 frappe    20   0  233508 119080   7888 S  0.0  5.8   0:30.04 gunicorn                             
11799 root      19  -1  103452  16988   7700 S  0.0  0.8   0:24.73 systemd-journal                      
 1179 root      20   0   67376   3196   3076 S  0.0  0.2   0:18.92 master                               
   11 root      rt   0       0      0      0 S  0.0  0.0   0:15.10 watchdog/0                           
   34 root      20   0       0      0      0 S  0.0  0.0   0:14.59 kswapd0      

I found log entry that may be the problem (IP address is random address):

==> logs/web.error.log <==

[2019-09-16 09:56:37 +0000] [1272] [INFO] Worker exiting (pid: 1272)

==> logs/web.log <==

172.151.54.239 does not exist

==> logs/web.error.log <==

[2019-09-16 09:56:38 +0000] [1700] [INFO] Booting worker with pid: 1700

[2019-09-16 09:56:40 +0000] [1700] [INFO] Worker exiting (pid: 1700)

==> logs/web.log <==

172.151.54.239 does not exist

==> logs/web.error.log <==

[2019-09-16 09:56:40 +0000] [1701] [INFO] Booting worker with pid: 1701

Somebody please help, this is getting pretty annoying lately.