array_diff in log

[bradaks]

Hello,

I just updated EspoCRM and advanced pack to the most recent version (was only one version behind on each) and my CPU usage jumped from 2% to 50-60%. I am not sure what caused this.

I am getting this error but highly doubt it could be the culprit:

[2022-02-03 03:34:02] WARNING: E_WARNING: array_diff(): Expected parameter 1 to be an array, null given {"code":2,"message":"array_diff(): Expected parameter 1 to be an array, null given","file":"/opt/bitnami/espocrm/application/Espo/Core/HookManager.php","line":205} [] [2022-02-03 03:34:02] WARNING: E_WARNING: array_filter() expects parameter 1 to be array, null given {"code":2,"message":"array_filter() expects parameter 1 to be array, null given","file":"/opt/bitnami/espocrm/application/Espo/Core/HookManager.php","line":213} [] [2022-02-03 03:34:02] WARNING: E_WARNING: Invalid argument supplied for foreach() {"code":2,"message":"Invalid argument supplied for foreach()","file":"/opt/bitnami/espocrm/application/Espo/Core/HookManager.php","line":215} []

Any ideas?

Thanks all!

[emillod]

It's look like one of hooks in your EspoCRM have error. Do you have any hooks in Custom directory?

[bradaks]

Good call. Found an old hook I was no longer using.

Here is the real issue I have right now.

CPU usage went up dramatically since I updated to the most recent versions of Advanced Pack and EspoCRM (both were only one version behind). Here is a visual representation. Has anyone else experienced this or know what I can do? I did try a fresh install with a copy and paste of the SQL table and it was still moving slow:

[emillod]

Could you give us specification of your machine? How long you're using EspoCRM? How big is your instance?

[bradaks]

Hello,

I am using AWS EC2 t3.xLarge. 4 CPUs - 16 GiB

Only using 32% of the storage. All uploads are being maintained on an S3 bucket.

Ive had a functioning system since 2017.

Brad

[bradaks]

Seems it may be an SQL problem:

[bradaks]

Few more errors I am getting in my log:

[2022-02-03 23:11:18] ERROR: Uncaught Exception PDOException: "SQLSTATE[HY000] [1040] Too many connections" at /opt/bitnami/espocrm/application/Espo/ORM/PDO/DefaultPDOProvider.php line 95 {"exception":"[object] (PDOException(code: 1040): SQLSTATE[HY000] [1040] Too many connections at /opt/bitnami/espocrm/application/Espo/ORM/PDO/DefaultPDOProvider.php:95)"} []
[2022-02-03 23:11:18] ERROR: Uncaught Exception PDOException: "SQLSTATE[HY000] [2006] MySQL server has gone away" at /opt/bitnami/espocrm/application/Espo/ORM/PDO/DefaultPDOProvider.php line 95 {"exception":"[object] (PDOException(code: 2006): SQLSTATE[HY000] [2006] MySQL server has gone away at /opt/bitnami/espocrm/application/Espo/ORM/PDO/DefaultPDOProvider.php:95)\n[previous exception] [object] (PDOException(code: 0): Packets out of order. Expected 0 received 1. Packet size=23 at /opt/bitnami/espocrm/application/Espo/ORM/PDO/DefaultPDOProvider.php:95)"} []
[2022-02-03 23:11:18] ERROR: Uncaught Exception PDOException: "SQLSTATE[HY000] [2006] MySQL server has gone away" at /opt/bitnami/espocrm/application/Espo/ORM/PDO/DefaultPDOProvider.php line 95 {"exception":"[object] (PDOException(code: 2006): SQLSTATE[HY000] [2006] MySQL server has gone away at /opt/bitnami/espocrm/application/Espo/ORM/PDO/DefaultPDOProvider.php:95)\n[previous exception] [object] (PDOException(code: 0): Packets out of order. Expected 0 received 1. Packet size=23 at /opt/bitnami/espocrm/application/Espo/ORM/PDO/DefaultPDOProvider.php:95)"} []
[2022-02-03 23:11:18] ERROR: Uncaught Exception PDOException: "SQLSTATE[HY000] [1040] Too many connections" at /opt/bitnami/espocrm/application/Espo/ORM/PDO/DefaultPDOProvider.php line 95 {"exception":"[object] (PDOException(code: 1040): SQLSTATE[HY000] [1040] Too many connections at /opt/bitnami/espocrm/application/Espo/ORM/PDO/DefaultPDOProvider.php:95)"} []
[2022-02-03 23:11:18] ERROR: Uncaught Exception PDOException: "SQLSTATE[HY000] [2006] MySQL server has gone away" at /opt/bitnami/espocrm/application/Espo/ORM/PDO/DefaultPDOProvider.php line 95 {"exception":"[object] (PDOException(code: 2006): SQLSTATE[HY000] [2006] MySQL server has gone away at /opt/bitnami/espocrm/application/Espo/ORM/PDO/DefaultPDOProvider.php:95)\n[previous exception] [object] (PDOException(code: 0): Packets out of order. Expected 0 received 1. Packet size=23 at /opt/bitnami/espocrm/application/Espo/ORM/PDO/DefaultPDOProvider.php:95)"} []
[2022-02-03 23:11:18] ERROR: Uncaught Exception PDOException: "SQLSTATE[HY000] [1040] Too many connections" at /opt/bitnami/espocrm/application/Espo/ORM/PDO/DefaultPDOProvider.php line 95 {"exception":"[object] (PDOException(code: 1040): SQLSTATE[HY000] [1040] Too many connections at /opt/bitnami/espocrm/application/Espo/ORM/PDO/DefaultPDOProvider.php:95)"} []
[2022-02-03 23:11:18] ERROR: Uncaught Exception PDOException: "SQLSTATE[HY000] [2006] MySQL server has gone away" at /opt/bitnami/espocrm/application/Espo/ORM/PDO/DefaultPDOProvider.php line 95 {"exception":"[object] (PDOException(code: 2006): SQLSTATE[HY000] [2006] MySQL server has gone away at /opt/bitnami/espocrm/application/Espo/ORM/PDO/DefaultPDOProvider.php:95)\n[previous exception] [object] (PDOException(code: 0): Packets out of order. Expected 0 received 1. Packet size=23 at /opt/bitnami/espocrm/application/Espo/ORM/PDO/DefaultPDOProvider.php:95)"} []
[2022-02-03 23:11:18] ERROR: Uncaught Exception PDOException: "SQLSTATE[HY000] [2006] MySQL server has gone away" at /opt/bitnami/espocrm/application/Espo/ORM/PDO/DefaultPDOProvider.php line 95 {"exception":"[object] (PDOException(code: 2006): SQLSTATE[HY000] [2006] MySQL server has gone away at /opt/bitnami/espocrm/application/Espo/ORM/PDO/DefaultPDOProvider.php:95)\n[previous exception] [object] (PDOException(code: 0): Packets out of order. Expected 0 received 1. Packet size=23 at /opt/bitnami/espocrm/application/Espo/ORM/PDO/DefaultPDOProvider.php:95)"} []
[2022-02-03 23:11:18] ERROR: Uncaught Exception PDOException: "SQLSTATE[HY000] [2006] MySQL server has gone away" at /opt/bitnami/espocrm/application/Espo/ORM/PDO/DefaultPDOProvider.php line 95 {"exception":"[object] (PDOException(code: 2006): SQLSTATE[HY000] [2006] MySQL server has gone away at /opt/bitnami/espocrm/application/Espo/ORM/PDO/DefaultPDOProvider.php:95)\n[previous exception] [object] (PDOException(code: 0): Packets out of order. Expected 0 received 1. Packet size=23 at /opt/bitnami/espocrm/application/Espo/ORM/PDO/DefaultPDOProvider.php:95)"} []
[2022-02-03 23:11:18] ERROR: Uncaught Exception PDOException: "SQLSTATE[HY000] [2006] MySQL server has gone away" at /opt/bitnami/espocrm/application/Espo/ORM/PDO/DefaultPDOProvider.php line 95 {"exception":"[object] (PDOException(code: 2006): SQLSTATE[HY000] [2006] MySQL server has gone away at /opt/bitnami/espocrm/application/Espo/ORM/PDO/DefaultPDOProvider.php:95)\n[previous exception] [object] (PDOException(code: 0): Packets out of order. Expected 0 received 1. Packet size=23 at /opt/bitnami/espocrm/application/Espo/ORM/PDO/DefaultPDOProvider.php:95)"} []
[2022-02-03 23:11:18] ERROR: (2006) SQLSTATE[HY000] [2006] MySQL server has gone away; GET /EmailTemplate; line: 95, file: /opt/bitnami/espocrm/application/Espo/ORM/PDO/DefaultPDOProvider.php [] []
[2022-02-04 00:08:56] ERROR: Uncaught Exception Espo\Core\Exceptions\Error: "Only GET request is allowed." at /opt/bitnami/espocrm/application/Espo/Core/ApplicationRunners/PortalClient.php line 92 {"exception":"[object] (Espo\\Core\\Exceptions\\Error(code: 500): Only GET request is allowed. at /opt/bitnami/espocrm/application/Espo/Core/ApplicationRunners/PortalClient.php:92)"} []
[2022-02-04 00:08:56] ERROR: Uncaught Exception Espo\Core\Exceptions\Error: "Only GET request is allowed." at /opt/bitnami/espocrm/application/Espo/Core/ApplicationRunners/PortalClient.php line 92 {"exception":"[object] (Espo\\Core\\Exceptions\\Error(code: 500): Only GET request is allowed. at /opt/bitnami/espocrm/application/Espo/Core/ApplicationRunners/PortalClient.php:92)"} []
[2022-02-04 00:09:11] ERROR: (403) GET /599a2d60e473396df/Report/action/run; line: 284, file: /opt/bitnami/espocrm/application/Espo/Modules/Advanced/Services/Report.php [] []
[2022-02-04 00:11:00] ERROR: (403) GET /599a2d60e473396df/Report/action/run; line: 284, file: /opt/bitnami/espocrm/application/Espo/Modules/Advanced/Services/Report.php [] []
[2022-02-04 00:11:22] ERROR: (403) GET /599a2d60e473396df/Report/action/run; line: 284, file: /opt/bitnami/espocrm/application/Espo/Modules/Advanced/Services/Report.php [] []
[2022-02-04 00:12:19] ERROR: (403) GET /599a2d60e473396df/Report/action/run; line: 284, file: /opt/bitnami/espocrm/application/Espo/Modules/Advanced/Services/Report.php [] []
[2022-02-04 00:17:05] ERROR: (403) GET /599a2d60e473396df/Report/action/run; line: 284, file: /opt/bitnami/espocrm/application/Espo/Modules/Advanced/Services/Report.php [] []
[2022-02-04 01:57:27] ERROR: (403) GET /Report/action/runList; line: 284, file: /opt/bitnami/espocrm/application/Espo/Modules/Advanced/Services/Report.php [] []
[2022-02-04 01:57:27] ERROR: (403) GET /Report/action/runList; line: 284, file: /opt/bitnami/espocrm/application/Espo/Modules/Advanced/Services/Report.php [] []
[2022-02-04 01:57:27] ERROR: (403) GET /Report/action/runList; line: 284, file: /opt/bitnami/espocrm/application/Espo/Modules/Advanced/Services/Report.php [] []

[emillod]

I think you should look into mysql log/syslog, because EspoCRM log shows that EspoCRM couldn't connect to database. I have this error on one of servers when mysql server is too busy and there is a timeout.

[item]

Maybe check this script by Yuri :

https://forum.espocrm.com/forum/installation-and-upgrade-help/60558-id-collation-changed-after-upgrade#post61212

[bradaks]

emillod Thanks so much for trying to help me with this probem.

Here is the only log I have:

2022-02-04 4:44:03 0 [Note] InnoDB: Using Linux native AIO
2022-02-04 4:44:03 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2022-02-04 4:44:03 0 [Note] InnoDB: Uses event mutexes
2022-02-04 4:44:03 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
2022-02-04 4:44:03 0 [Note] InnoDB: Number of pools: 1
2022-02-04 4:44:03 0 [Note] InnoDB: Using SSE2 crc32 instructions
2022-02-04 4:44:03 0 [Note] InnoDB: Initializing buffer pool, total size = 11G, instances = 8, chunk size = 128M
2022-02-04 4:44:03 0 [Note] InnoDB: Completed initialization of buffer pool
2022-02-04 4:44:03 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2022-02-04 4:44:03 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
2022-02-04 4:44:03 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2022-02-04 4:44:03 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2022-02-04 4:44:03 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2022-02-04 4:44:03 0 [Note] InnoDB: 10.3.32 started; log sequence number 88585859752; transaction id 49347551
2022-02-04 4:44:03 0 [Note] InnoDB: Loading buffer pool(s) from /bitnami/mariadb/data/ib_buffer_pool
2022-02-04 4:44:03 0 [Note] Plugin 'FEEDBACK' is disabled.
2022-02-04 4:44:03 0 [Note] Server socket created on IP: '127.0.0.1'.
2022-02-04 4:44:04 0 [Warning] 'proxies_priv' entry '@% root@ip-' ignored in --skip-name-resolve mode.
2022-02-04 4:44:04 0 [Note] Reading of all Master_info entries succeeded
2022-02-04 4:44:04 0 [Note] Added new Master_info '' to hash table
2022-02-04 4:44:04 0 [Note] /opt/bitnami/mariadb/sbin/mysqld: ready for connections.
Version: '10.3.32-MariaDB' socket: '/opt/bitnami/mariadb/tmp/mysql.sock' port: 3306 Source distribution
2022-02-04 4:44:47 0 [Note] InnoDB: Buffer pool(s) load completed at 220204 4:44:47
2022-02-04 13:46:07 0 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table `espocrm_bitnami`.`email`
2022-02-04 15:41:47 0 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table `espocrm_bitnami`.`email`
2022-02-04 16:52:06 0 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table `espocrm_bitnami`.`email`
2022-02-04 18:26:13 0 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table `espocrm_bitnami`.`email`
2022-02-04 19:51:04 0 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table `espocrm_bitnami`.`email`

[bradaks]

Might anyone have any ideas? I will pay for any support that can fix this issue. I have tried migrating the database with a fresh install, going back a version on the advanced pack, updating to the most recent version. I have upped the memory for the instance. Nothing is working.

Desperation is starting to kick in.

[emillod]

bradaks it's not always easy to debug something through chat. We can try directly on server if you want, it should be easier. You can contact me directly through email. Here you have address: https://devcrm.it/#contact2
If you want, we can speak through MS Teams.I can see notifications related to many posts, so not always i have time to response to everythig

[bradaks]

Hello,

To fix this problem I installed a fresh EspoCRM, installed the extensions, and then copied ALL the phpmyadmin tables in CSV format and uploaded them back into the new instances phpmyadmin panel.

Works great now!