Our install of SuiteCRM - Version 7.11.6 - Sugar Version 6.5.25 (Build 344)
I often experience this error: User XXX’ has exceeded the ‘max_connections_per_hour’ resource (current value: 500)
I know that we are limited by Hostinger (Shared) to a max of 500 connections…
But what I don’t understand is that I am the ONLY user. I am editing PDF templates and testing them out. Sometimes it occurs when I am building out a module.
Is SuiteCRM that inefficient? What can I do to fix this?
I don’t remember ever having seen this error with SuiteCRM, something unusual is going on.
I don’t know what could be generating so many connections to the database? Do you have anything else suspicious in your logs?
Have you been doing Workflows? In Workflows module, option “View process audit”, do you see too many jobs, or some that didn’t complete?
I only have 1 Workflow. Create a record when in a custom module when a project status changes. At most 2-3 projects status’s changes once a day. Usually 1 project. No errors all showing complete.
My cron jobs are set to run every 4 hrs. But again they all show complete and no errors. I have even disabled them for a few days thinking this might be the issue.
Logs don’t show any errors other than the one I am telling you about.
I’m sorry, I don’t have any clues to understand this…
You need to try and debug it somehow. Maybe just leave an SSH window running
tail -f suitecrm.logAnd trying to figure out if there’s any action there that looks suspicious. I don’t know, something recursive going on, draining your resources, or some hacker trying to brute-force your server by trying root passwords…
Could you maybe have a quick look for me please?
It does appear that there is a call to the database every 30s or less.
There is something odd going on. Shows in the log file I attached.
Keeps saying:
[DEBUG] Hook called: ::server_round_trip
Then it runs a bunch of stuff but it does disonnect after:
[DEBUG] Calling MySQLi::disconnect()
This keep running every 30s or so… what is going on?
Cron jobs are set to run every 4hrs.
My 1 workflow is not being triggered.
Mon Sep 9 17:40:05 2019 [443213][-none-][DEBUG] current_language is: en_us
Mon Sep 9 17:40:05 2019 [443213][-none-][DEBUG] Found cache backend SugarCachesMash
Mon Sep 9 17:40:05 2019 [443213][-none-][DEBUG] Found cache backend SugarCacheMemory
Mon Sep 9 17:40:05 2019 [443213][-none-][DEBUG] Using cache backend SugarCacheMemory, since 999 is less than 1000
Mon Sep 9 17:40:05 2019 [443213][-none-][DEBUG] Found cache backend SugarCacheRedis
Mon Sep 9 17:40:05 2019 [443213][-none-][DEBUG] Found cache backend SugarCacheWincache
Mon Sep 9 17:40:05 2019 [443213][-none-][DEBUG] Found cache backend SugarCacheZend
Mon Sep 9 17:40:05 2019 [443213][-none-][DEBUG] Found cache backend SugarCacheMemcache
Mon Sep 9 17:40:05 2019 [443213][-none-][DEBUG] Found cache backend SugarCacheAPC
Mon Sep 9 17:40:05 2019 [443213][-none-][DEBUG] Found cache backend SugarCacheMemcached
Mon Sep 9 17:40:05 2019 [443213][-none-][DEBUG] Found cache backend SugarCacheFile
Mon Sep 9 17:40:05 2019 [443213][-none-][INFO] Found language file: en_us.lang.php
Mon Sep 9 17:40:05 2019 [443213][-none-][INFO] Found extended language file: en_us.lang.ext.php
Mon Sep 9 17:40:05 2019 [443213][-none-][INFO] Found custom language file: en_us.lang.php
Mon Sep 9 17:40:05 2019 [443213][-none-][INFO] Query:SELECT id, name, symbol, conversion_rate FROM currencies WHERE status = ‘Active’ and deleted = 0
Mon Sep 9 17:40:05 2019 [443213][-none-][INFO] Query Execution Time:0.0002291202545166
Mon Sep 9 17:40:05 2019 [443213][-none-][DEBUG] rebuilding cache for Users
Mon Sep 9 17:40:05 2019 [443213][-none-][INFO] Query:SELECT * FROM fields_meta_data WHERE custom_module=‘Users’ AND deleted = 0
Mon Sep 9 17:40:05 2019 [443213][-none-][INFO] Query Execution Time:0.00040197372436523
Mon Sep 9 17:40:05 2019 [443213][-none-][DEBUG] rebuilding cache for Employees
Mon Sep 9 17:40:05 2019 [443213][-none-][INFO] Query:SELECT * FROM fields_meta_data WHERE custom_module=‘Employees’ AND deleted = 0
Mon Sep 9 17:40:05 2019 [443213][-none-][INFO] Query Execution Time:0.00046205520629883
Mon Sep 9 17:40:05 2019 [443213][-none-][DEBUG] rebuilding cache for EmailAddresses
Mon Sep 9 17:40:05 2019 [443213][-none-][INFO] Query:SELECT * FROM fields_meta_data WHERE custom_module=‘EmailAddresses’ AND deleted = 0
Mon Sep 9 17:40:05 2019 [443213][-none-][INFO] Query Execution Time:0.00040984153747559
Mon Sep 9 17:40:05 2019 [443213][-none-][DEBUG] rebuilding cache for UserPreferences
Mon Sep 9 17:40:05 2019 [443213][-none-][INFO] Query:SELECT * FROM fields_meta_data WHERE custom_module=‘UserPreferences’ AND deleted = 0
Mon Sep 9 17:40:05 2019 [443213][-none-][INFO] Query Execution Time:0.00047397613525391
Mon Sep 9 17:40:05 2019 [443213][-none-][DEBUG] rebuilding cache for Administration
Mon Sep 9 17:40:05 2019 [443213][-none-][INFO] Query:SELECT * FROM fields_meta_data WHERE custom_module=‘Administration’ AND deleted = 0
Mon Sep 9 17:40:05 2019 [443213][-none-][INFO] Query Execution Time:0.00040102005004883
Mon Sep 9 17:40:05 2019 [443213][-none-][INFO] Query:SELECT category, name, value FROM config
Mon Sep 9 17:40:05 2019 [443213][-none-][INFO] Query Execution Time:0.00045180320739746
Mon Sep 9 17:40:05 2019 [443213][-none-][INFO] Query:SELECT id FROM outbound_email WHERE type = ‘system’
Mon Sep 9 17:40:05 2019 [443213][-none-][INFO] Query Execution Time:0.00022411346435547
Mon Sep 9 17:40:05 2019 [443213][-none-][INFO] Query:SELECT * FROM outbound_email WHERE id = ‘9db5418f-1aa2-2e7d-25a2-5d0c2ca71dc2’
Mon Sep 9 17:40:05 2019 [443213][-none-][INFO] Query Execution Time:0.00026702880859375
Mon Sep 9 17:40:05 2019 [443213][-none-][DEBUG] Hook called: ::after_entry_point
Mon Sep 9 17:40:05 2019 [443213][-none-][DEBUG] Including module specific hook file for custom/modules
Mon Sep 9 17:40:05 2019 [443213][-none-][DEBUG] Including Ext hook file for custom/application
Mon Sep 9 17:40:05 2019 [443213][-none-][DEBUG] Hook called: ::after_session_start
Mon Sep 9 17:40:05 2019 [443213][-none-][DEBUG] Unable to find SugarController:: get
Mon Sep 9 17:40:05 2019 [443213][-none-][DEBUG] We have an authenticated user id: 2c83f554-9f0f-948c-acbd-5cd2fe8e01de
Mon Sep 9 17:40:05 2019 [443213][-none-][DEBUG] Hook called: Users::before_retrieve
Mon Sep 9 17:40:05 2019 [443213][-none-][DEBUG] Including module specific hook file for custom/modules/Users
Mon Sep 9 17:40:05 2019 [443213][-none-][DEBUG] Retrieve User : SELECT users.,users_cstm. FROM users LEFT JOIN users_cstm ON users.id = users_cstm.id_c WHERE users.id = ‘2c83f554-9f0f-948c-acbd-5cd2fe8e01de’ AND users.deleted=0
Mon Sep 9 17:40:05 2019 [443213][-none-][DEBUG] Limit Query:SELECT users.,users_cstm. FROM users LEFT JOIN users_cstm ON users.id = users_cstm.id_c WHERE users.id = ‘2c83f554-9f0f-948c-acbd-5cd2fe8e01de’ AND users.deleted=0 Start: 0 count: 1
Mon Sep 9 17:40:05 2019 [443213][-none-][INFO] Query:SELECT users.,users_cstm. FROM users LEFT JOIN users_cstm ON users.id = users_cstm.id_c WHERE users.id = ‘2c83f554-9f0f-948c-acbd-5cd2fe8e01de’ AND users.deleted=0 LIMIT 0,1
Mon Sep 9 17:40:05 2019 [443213][-none-][INFO] Query Execution Time:0.00042009353637695
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][DEBUG] get_user_array query: SELECT id, first_name, last_name, user_name FROM users WHERE 1=1 ORDER BY first_name, last_name ASC
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][INFO] Query:SELECT id, first_name, last_name, user_name FROM users WHERE 1=1 ORDER BY first_name, last_name ASC
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][INFO] Query Execution Time:0.00026202201843262
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][INFO] Query:SELECT u1.first_name, u1.last_name from users u1, users u2 where u1.id = u2.reports_to_id AND u2.id = ‘2c83f554-9f0f-948c-acbd-5cd2fe8e01de’ and u1.deleted=0
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][INFO] Query Execution Time:0.00019502639770508
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][INFO] Query:SELECT
ea.email_address,
ea.email_address_caps,
ea.invalid_email,
ea.opt_out,
ea.confirm_opt_in,
ea.date_created,
ea.date_modified,
ear.id,
ear.email_address_id,
ear.bean_id,
ear.bean_module,
ear.primary_address,
ear.reply_to_address,
ear.deleted
FROM email_addresses ea LEFT JOIN email_addr_bean_rel ear ON ea.id = ear.email_address_id
WHERE
ear.bean_module = ‘Users’
AND ear.bean_id = ‘2c83f554-9f0f-948c-acbd-5cd2fe8e01de’
AND ear.deleted = 0
ORDER BY ear.reply_to_address, ear.primary_address DESC
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][INFO] Query Execution Time:0.00028800964355469
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][DEBUG] Hook called: Users::after_retrieve
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][DEBUG] FACTOR AUTH: -------------------------------------------------------------
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][DEBUG] FACTOR AUTH: --------------------- CHECK FACTOR AUtH ---------------------
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][DEBUG] FACTOR AUTH: -------------------------------------------------------------
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][DEBUG] FACTOR AUTH: User needs factor auth, request is not Logout
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][DEBUG] FACTOR AUTH: User does`nt need factor auth
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][DEBUG] Current user is: Madison
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][DEBUG] Current user is: Madison
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][DEBUG] setting cookie ck_login_id_20 to 2c83f554-9f0f-948c-acbd-5cd2fe8e01de
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][DEBUG] setting cookie ck_login_language_20 to en_us
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][DEBUG] current_language is: en_us
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][INFO] Found language file: en_us.lang.php
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][INFO] Found extended language file: en_us.lang.ext.php
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][INFO] Found custom language file: en_us.lang.php
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][DEBUG] rebuilding cache for Alerts
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][INFO] Query:SELECT * FROM fields_meta_data WHERE custom_module=‘Alerts’ AND deleted = 0
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][INFO] Query Execution Time:0.00032496452331543
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][DEBUG] Performing action: action_get MODULE: Alerts
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][DEBUG] get_full_list: order_by = ‘alerts.date_entered’ and where = ‘alerts.assigned_user_id = ‘2c83f554-9f0f-948c-acbd-5cd2fe8e01de’ AND is_read != ‘1’’
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][DEBUG] SugarBean[Alert].load_relationships, Loading relationship (modified_user_link).
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][DEBUG] SugarBean[Alert].load_relationships, Loading relationship (created_by_link).
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][DEBUG] SugarBean[Alert].load_relationships, Loading relationship (assigned_user_link).
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][DEBUG] process_order_by: (alerts.date_entered) does not have a vardef entry.
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][DEBUG] process_full_list_query: query is SELECT alerts.* , jt0.user_name modified_by_name , jt0.created_by modified_by_name_owner , ‘Users’ modified_by_name_mod , jt1.user_name created_by_name , jt1.created_by created_by_name_owner , ‘Users’ created_by_name_mod , jt2.user_name assigned_user_name , jt2.created_by assigned_user_name_owner , ‘Users’ assigned_user_name_mod FROM alerts LEFT JOIN users jt0 ON alerts.modified_user_id=jt0.id AND jt0.deleted=0
AND jt0.deleted=0 LEFT JOIN users jt1 ON alerts.created_by=jt1.id AND jt1.deleted=0
AND jt1.deleted=0 LEFT JOIN users jt2 ON alerts.assigned_user_id=jt2.id AND jt2.deleted=0
AND jt2.deleted=0 where (alerts.assigned_user_id = ‘2c83f554-9f0f-948c-acbd-5cd2fe8e01de’ AND is_read != ‘1’) AND alerts.deleted=0
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][INFO] Query: SELECT alerts.* , jt0.user_name modified_by_name , jt0.created_by modified_by_name_owner , ‘Users’ modified_by_name_mod , jt1.user_name created_by_name , jt1.created_by created_by_name_owner , ‘Users’ created_by_name_mod , jt2.user_name assigned_user_name , jt2.created_by assigned_user_name_owner , ‘Users’ assigned_user_name_mod FROM alerts LEFT JOIN users jt0 ON alerts.modified_user_id=jt0.id AND jt0.deleted=0
AND jt0.deleted=0 LEFT JOIN users jt1 ON alerts.created_by=jt1.id AND jt1.deleted=0
AND jt1.deleted=0 LEFT JOIN users jt2 ON alerts.assigned_user_id=jt2.id AND jt2.deleted=0
AND jt2.deleted=0 where (alerts.assigned_user_id = ‘2c83f554-9f0f-948c-acbd-5cd2fe8e01de’ AND is_read != ‘1’) AND alerts.deleted=0
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][INFO] Query Execution Time:0.00050711631774902
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][DEBUG] process_full_list_query: result is mysqli_result Object
(
[current_field] => 0
[field_count] => 23
[lengths] =>
[num_rows] => 0
[type] => 0
)
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][DEPRECATED] Array
(
)
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][DEBUG] Hook called: ::server_round_trip
Mon Sep 9 17:40:05 2019 [443213][2c83f554-9f0f-948c-acbd-5cd2fe8e01de][DEBUG] Calling MySQLi::disconnect()
Take a look into the indexing schedule. In my case it was getting stuck and using most of my server resources.
Thanks,
AlxGr
Which application hook do you have defined under custom/application? Please try disabling it.
I have Tabbed Subpanels in my application/ext/logichook. I will disable it and see what happens. But I have looked through the files and it doesn’t seem to touch the database.