Bad Server Constantly when updating Fields or Formulas - losing my mind!

[khopper]

When ever updating Field's or Formula's I constantly get "BAD SERVER" and in the logs it shows "uncaught exception" - i have my logs set to DEBUG mode and still am unable to determine what the cause is. I don't see anything the apache logs that are helpful either. It's so bad that I have to take a VM Snapshot before each small change.
This last time all I did specifically was update a formula for the Account's Entity, it flashed saying it was "unable to clear cache" and then started flashing "BAD SERVER" and this is the log below. CRM is Version 5.2.5 running on Ubuntu 14.04 with Apache2 and MySQL 5.6 (I did not yet get to install today's updated release to version 5.3.3)
Any help would be appreciated & thank you!


ESPOLOG 20180716
[2018-07-17 14:16:50] Espo.DEBUG: WorkflowManager: End workflow rule [5a396c0a7d1c49bc9]. [] []
[2018-07-17 14:16:50] Espo.DEBUG: WorkflowManager: Start workflow rule [5abb9547584be9993]. [] []
[2018-07-17 14:16:50] Espo.DEBUG: WorkflowManager: Condition result [] for workflow rule [5abb9547584be9993]. [] []
[2018-07-17 14:16:50] Espo.DEBUG: WorkflowManager: End workflow rule [5abb9547584be9993]. [] []
[2018-07-17 14:16:50] Espo.DEBUG: WorkflowManager: End workflow [afterRecordSaved] for Entity [Account, 5b1eabe4b70aa6330]. [] []
[2018-07-17 14:19:33] Espo.WARNING: E_WARNING: rmdir(data/cache/application): Directory not empty {"code":2,"message":"rmdir(data/cache/application): Directory not empty","file":"/var/www/espocrm/application/Espo/Core/Utils/File/Manager.php","line":529,"context":{"dirPaths":["data/cache/application"],"result":true,"dirPath":"data/cache/application"}} []
[2018-07-17 14:19:33] Espo.ERROR: API [POST]:/:controller/action/:action, Params:Array ( [controller] => EntityManager [action] => formula ) , InputData: {"data":{"beforeSaveCustomScript":"urlgensow = string\\concatenate('http://crm.teamamericom.com/phpexcel/test4.php?accountid1=',id);\nifThenElse(entity\\is AttributeChanged('orderstatus'), orderstatusdt = datetime\\now());\nifThenElse(entity\\isAttributeC hanged('orderstatusi'), orderstatusdt = datetime\\now());\nifThenElse(entity\\isAttributeC hanged('orderstatusv'), orderstatusdt = datetime\\now());\nifThen(discountvideo == null && client == 'COMCAST',discountvideo = 0);\nifThen(discountvoice == null && client == 'COMCAST',discountvoice = 0);\nifThen(discountinternet == null && client == 'COMCAST',discountinternet = 0);\nifThen(ccblmrc == null && client == 'COMCAST',ccblmrc = 0);\nifThen(ccfflmrc == null && client == 'COMCAST',ccfflmrc = 0);\nifThen(ccmlmrc == null && client == 'COMCAST',ccmlmrc = 0);\nifThen(ccimrc == null && client == 'COMCAST',ccimrc = 0);\nifThen(ccbl == null && client == 'COMCAST',ccbl = 0);\nifThen(ccffl == null && client == 'COMCAST',ccffl = 0);\nifThen(ccml == null && client == 'COMCAST',ccml = 0);\nifThen(client == 'COMCAST', mrc = ((ccblmrc+ccfflmrc+ccmlmrc+ccimrc+ccvmrc)-(discountinternet+discountvideo+discountvoice)));\ nifThenElse(client == 'COMCAST' && term = '36 Mo', commission = ifThenElse(voice == 'New', (ccblmrc+ccfflmrc+ccmlmrc) - discountvoice,0) + ifThenElse(internet == 'New', ccimrc - discountinternet,0) + ifThenElse(video == 'New', ccvmrc - discountvideo,0),0);\nifThenElse(client == 'COMCAST' && term = '24 Mo', commission = ifThenElse(voice == 'New', (ccblmrc+ccfflmrc+ccmlmrc-discountvoice) * 0.5,0) + ifThenElse(internet == 'New', ccimrc - discountinternet * 0.5,0) + ifThenElse(video == 'New', ccvmrc - discountvideo * 0.5,0),0);"},"scope":"Account"} - Error while clearing cache [] []
[2018-07-17 14:19:33] Espo.ERROR: Display Error: Error while clearing cache, Code: 500 URL: /espocrm/api/v1/EntityManager/action/formula [] []
[2018-07-17 14:19:34] Espo.WARNING: E_WARNING: Invalid argument supplied for foreach() {"code":2,"message":"Invalid argument supplied for foreach()","file":"/var/www/espocrm/application/Espo/Core/Utils/Database/Orm/Converter.php","line":171,"context":{"entityDefs": 1,"ormMetadata":[]}} []
[2018-07-17 14:19:34] Espo.WARNING: E_WARNING: Invalid argument supplied for foreach() {"code":2,"message":"Invalid argument supplied for foreach()","file":"/var/www/espocrm/application/Espo/Core/ORM/Repositories/RDB.php","line":129,"context":{"params":{"offset": 0,"limit":1,"whereClause":{"token":"d8ba0966c88292 76ae1855b14c264d8c"},"havingClause":[]},"entityType":"AuthToken","metadata":"[object] (Espo\\Core\\Utils\\Metadata: {})","defs":1}} []
[2018-07-17 14:19:34] Espo.ERROR: Uncaught Exception TypeError: "Argument 1 passed to Espo\ORM\DB\Mapper::select() must be an instance of Espo\ORM\IEntity, null given, called in /var/www/espocrm/application/Espo/ORM/Repositories/RDB.php on line 201" at /var/www/espocrm/application/Espo/ORM/DB/Mapper.php line 105 {"exception":"[object] (TypeError(code: 0): Argument 1 passed to Espo\\ORM\\DB\\Mapper::select() must be an instance of Espo\\ORM\\IEntity, null given, called in /var/www/espocrm/application/Espo/ORM/Repositories/RDB.php on line 201 at /var/www/espocrm/application/Espo/ORM/DB/Mapper.php:105)"} []
[2018-07-17 14:19:34] Espo.ERROR: Uncaught Exception TypeError: "Argument 1 passed to Espo\ORM\DB\Mapper::select() must implement interface Espo\ORM\IEntity, null given, called in /var/www/espocrm/application/Espo/ORM/Repositories/RDB.php on line 201" at /var/www/espocrm/application/Espo/ORM/DB/Mapper.php line 105 {"exception":"[object] (TypeError(code: 0): Argument 1 passed to Espo\\ORM\\DB\\Mapper::select() must implement interface Espo\\ORM\\IEntity, null given, called in /var/www/espocrm/application/Espo/ORM/Repositories/RDB.php on line 201 at /var/www/espocrm/application/Espo/ORM/DB/Mapper.php:105)"} []

the error just continue repeating from here ................. for 1000's of lines if i let it!

[khopper]

I was able to restore the VM from last night 9 pm est, I still have the VM with BAD SERVER flashing still available for testing/diagnostic....
I would really like to get to the bottom of why a simple change to a formula or adjusting conditions on a field would cause this.

[tanya]

could you attach a screenshot of your formula in crm and custom/Espo/Custom/Resources/metadata/formula/Account.json (if it is about Account)?

[khopper]

Here is a Screen shot of the Account.json file you requested.
Also for reference, I was using Google Chrome Version 67.0.3396.99 (Official Build) (64-bit) on Win 7 Pro 64-Bit when adding/updating the formula.

[khopper]

FYI - I went to update the php file and update/insert the formula to Entity Accounts and it caused a "bad server" error but luckily did not crash this time.
I also upgraded to version 5.3.3 last night so its is up to date.
Thread: https://forum.espocrm.com/forum/gene...ns-commissions


[2018-07-18 13:39:25] Espo.WARNING: E_WARNING: Invalid argument supplied for foreach() {"code":2,"message":"Invalid argument supplied for foreach()","file":"/var/www/espocrm/application/Espo/Core/Utils/Database/Orm/Converter.php","line":171,"context":{"entityDefs": 1,"ormMetadata":[]}} []
[2018-07-18 13:39:25] Espo.ERROR: Uncaught Exception TypeError: "Argument 1 passed to Espo\ORM\DB\Mapper::select() must implement interface Espo\ORM\IEntity, null given, called in /var/www/espocrm/application/Espo/ORM/Repositories/RDB.php on line 201" at /var/www/espocrm/application/Espo/ORM/DB/Mapper.php line 105 {"exception":"[object] (TypeError(code: 0): Argument 1 passed to Espo\\ORM\\DB\\Mapper::select() must implement interface Espo\\ORM\\IEntity, null given, called in /var/www/espocrm/application/Espo/ORM/Repositories/RDB.php on line 201 at /var/www/espocrm/application/Espo/ORM/DB/Mapper.php:105)"} []
[2018-07-18 13:39:25] Espo.ERROR: Uncaught Exception TypeError: "Argument 1 passed to Espo\ORM\DB\Mapper::select() must implement interface Espo\ORM\IEntity, null given, called in /var/www/espocrm/application/Espo/ORM/Repositories/RDB.php on line 201" at /var/www/espocrm/application/Espo/ORM/DB/Mapper.php line 105 {"exception":"[object] (TypeError(code: 0): Argument 1 passed to Espo\\ORM\\DB\\Mapper::select() must implement interface Espo\\ORM\\IEntity, null given, called in /var/www/espocrm/application/Espo/ORM/Repositories/RDB.php on line 201 at /var/www/espocrm/application/Espo/ORM/DB/Mapper.php:105)"} []
[2018-07-18 13:39:25] Espo.ERROR: Uncaught Exception TypeError: "Argument 1 passed to Espo\ORM\DB\Mapper::select() must implement interface Espo\ORM\IEntity, null given, called in /var/www/espocrm/application/Espo/ORM/Repositories/RDB.php on line 201" at /var/www/espocrm/application/Espo/ORM/DB/Mapper.php line 105 {"exception":"[object] (TypeError(code: 0): Argument 1 passed to Espo\\ORM\\DB\\Mapper::select() must implement interface Espo\\ORM\\IEntity, null given, called in /var/www/espocrm/application/Espo/ORM/Repositories/RDB.php on line 201 at /var/www/espocrm/application/Espo/ORM/DB/Mapper.php:105)"} []
[2018-07-18 13:39:25] Espo.ERROR: Uncaught Exception TypeError: "Argument 1 passed to Espo\ORM\DB\Mapper::select() must implement interface Espo\ORM\IEntity, null given, called in /var/www/espocrm/application/Espo/ORM/Repositories/RDB.php on line 201" at /var/www/espocrm/application/Espo/ORM/DB/Mapper.php line 105 {"exception":"[object] (TypeError(code: 0): Argument 1 passed to Espo\\ORM\\DB\\Mapper::select() must implement interface Espo\\ORM\\IEntity, null given, called in /var/www/espocrm/application/Espo/ORM/Repositories/RDB.php on line 201 at /var/www/espocrm/application/Espo/ORM/DB/Mapper.php:105)"} []
[2018-07-18 13:39:25] Espo.ERROR: Uncaught Exception TypeError: "Argument 1 passed to Espo\ORM\DB\Mapper::select() must implement interface Espo\ORM\IEntity, null given, called in /var/www/espocrm/application/Espo/ORM/Repositories/RDB.php on line 201" at /var/www/espocrm/application/Espo/ORM/DB/Mapper.php line 105 {"exception":"[object] (TypeError(code: 0): Argument 1 passed to Espo\\ORM\\DB\\Mapper::select() must implement interface Espo\\ORM\\IEntity, null given, called in /var/www/espocrm/application/Espo/ORM/Repositories/RDB.php on line 201 at /var/www/espocrm/application/Espo/ORM/DB/Mapper.php:105)"} []
[2018-07-18 13:39:25] Espo.WARNING: E_WARNING: Invalid argument supplied for foreach() {"code":2,"message":"Invalid argument supplied for foreach()","file":"/var/www/espocrm/application/Espo/Core/ORM/Repositories/RDB.php","line":129,"context":{"params":[],"entityType":"AuthLogRecord","metadata":"[object] (Espo\\Core\\Utils\\Metadata: {})","defs":1}} []
[2018-07-18 13:39:25] Espo.ERROR: Uncaught Exception TypeError: "Argument 1 passed to Espo\ORM\DB\Mapper::count() must be an instance of Espo\ORM\IEntity, null given, called in /var/www/espocrm/application/Espo/ORM/Repositories/RDB.php on line 451" at /var/www/espocrm/application/Espo/ORM/DB/Mapper.php line 85 {"exception":"[object] (TypeError(code: 0): Argument 1 passed to Espo\\ORM\\DB\\Mapper::count() must be an instance of Espo\\ORM\\IEntity, null given, called in /var/www/espocrm/application/Espo/ORM/Repositories/RDB.php on line 451 at /var/www/espocrm/application/Espo/ORM/DB/Mapper.php:85)"} []
[2018-07-18 13:39:25] Espo.ERROR: Uncaught Exception TypeError: "Argument 1 passed to Espo\ORM\DB\Mapper::select() must implement interface Espo\ORM\IEntity, null given, called in /var/www/espocrm/application/Espo/ORM/Repositories/RDB.php on line 201" at /var/www/espocrm/application/Espo/ORM/DB/Mapper.php line 105 {"exception":"[object] (TypeError(code: 0): Argument 1 passed to Espo\\ORM\\DB\\Mapper::select() must implement interface Espo\\ORM\\IEntity, null given, called in /var/www/espocrm/application/Espo/ORM/Repositories/RDB.php on line 201 at /var/www/espocrm/application/Espo/ORM/DB/Mapper.php:105)"} []
[2018-07-18 13:39:25] Espo.ERROR: Uncaught Exception TypeError: "Argument 1 passed to Espo\ORM\DB\Mapper::count() must implement interface Espo\ORM\IEntity, null given, called in /var/www/espocrm/application/Espo/ORM/Repositories/RDB.php on line 451" at /var/www/espocrm/application/Espo/ORM/DB/Mapper.php line 85 {"exception":"[object] (TypeError(code: 0): Argument 1 passed to Espo\\ORM\\DB\\Mapper::count() must implement interface Espo\\ORM\\IEntity, null given, called in /var/www/espocrm/application/Espo/ORM/Repositories/RDB.php on line 451 at /var/www/espocrm/application/Espo/ORM/DB/Mapper.php:85)"} []
[2018-07-18 13:39:25] Espo.ERROR: Uncaught Exception TypeError: "Argument 1 passed to Espo\ORM\DB\Mapper::select() must implement interface Espo\ORM\IEntity, null given, called in /var/www/espocrm/application/Espo/ORM/Repositories/RDB.php on line 201" at /var/www/espocrm/application/Espo/ORM/DB/Mapper.php line 105 {"exception":"[object] (TypeError(code: 0): Argument 1 passed to Espo\\ORM\\DB\\Mapper::select() must implement interface Espo\\ORM\\IEntity, null given, called in /var/www/espocrm/application/Espo/ORM/Repositories/RDB.php on line 201 at /var/www/espocrm/application/Espo/ORM/DB/Mapper.php:105)"} []
[2018-07-18 13:39:25] Espo.ERROR: Uncaught Exception TypeError: "Argument 1 passed to Espo\ORM\DB\Mapper::select() must implement interface Espo\ORM\IEntity, null given, called in /var/www/espocrm/application/Espo/ORM/Repositories/RDB.php on line 201" at /var/www/espocrm/application/Espo/ORM/DB/Mapper.php line 105 {"exception":"[object] (TypeError(code: 0): Argument 1 passed to Espo\\ORM\\DB\\Mapper::select() must implement interface Espo\\ORM\\IEntity, null given, called in /var/www/espocrm/application/Espo/ORM/Repositories/RDB.php on line 201 at /var/www/espocrm/application/Espo/ORM/DB/Mapper.php:105)"} []
[2018-07-18 13:39:25] Espo.ERROR: Uncaught Exception TypeError: "Argument 1 passed to Espo\ORM\DB\Mapper::select() must implement interface Espo\ORM\IEntity, null given, called in /var/www/espocrm/application/Espo/ORM/Repositories/RDB.php on line 201" at /var/www/espocrm/application/Espo/ORM/DB/Mapper.php line 105 {"exception":"[object] (TypeError(code: 0): Argument 1 passed to Espo\\ORM\\DB\\Mapper::select() must implement interface Espo\\ORM\\IEntity, null given, called in /var/www/espocrm/application/Espo/ORM/Repositories/RDB.php on line 201 at /var/www/espocrm/application/Espo/ORM/DB/Mapper.php:105)"} []
[2018-07-18 13:39:26] Espo.ERROR: Uncaught Exception ParseError: "syntax error, unexpected end of file" at /var/www/espocrm/data/cache/application/ormMetadata.php line 15966 {"exception":"[object] (ParseError(code: 0): syntax error, unexpected end of file at /var/www/espocrm/data/cache/application/ormMetadata.php:15966)"} []
[2018-07-18 13:39:26] Espo.ERROR: Uncaught Exception TypeError: "Argument 1 passed to Espo\ORM\EntityManager::setMetadata() must be of the type array, integer given, called in /var/www/espocrm/application/Espo/ORM/EntityManager.php on line 76" at /var/www/espocrm/application/Espo/ORM/EntityManager.php line 194 {"exception":"[object] (TypeError(code: 0): Argument 1 passed to Espo\\ORM\\EntityManager::setMetadata() must be of the type array, integer given, called in /var/www/espocrm/application/Espo/ORM/EntityManager.php on line 76 at /var/www/espocrm/application/Espo/ORM/EntityManager.php:194)"} []
[2018-07-18 13:39:26] Espo.ERROR: Uncaught Exception TypeError: "Argument 1 passed to Espo\ORM\EntityManager::setMetadata() must be of the type array, integer given, called in /var/www/espocrm/application/Espo/ORM/EntityManager.php on line 76" at /var/www/espocrm/application/Espo/ORM/EntityManager.php line 194 {"exception":"[object] (TypeError(code: 0): Argument 1 passed to Espo\\ORM\\EntityManager::setMetadata() must be of the type array, integer given, called in /var/www/espocrm/application/Espo/ORM/EntityManager.php on line 76 at /var/www/espocrm/application/Espo/ORM/EntityManager.php:194)"} []
[2018-07-18 13:39:26] Espo.ERROR: Uncaught Exception TypeError: "Argument 1 passed to Espo\ORM\EntityManager::setMetadata() must be of the type array, integer given, called in /var/www/espocrm/application/Espo/ORM/EntityManager.php on line 76" at /var/www/espocrm/application/Espo/ORM/EntityManager.php line 194 {"exception":"[object] (TypeError(code: 0): Argument 1 passed to Espo\\ORM\\EntityManager::setMetadata() must be of the type array, integer given, called in /var/www/espocrm/application/Espo/ORM/EntityManager.php on line 76 at /var/www/espocrm/application/Espo/ORM/EntityManager.php:194)"} []

[khopper]

Am I the only one and all alone in having these issues? Anyone?

[tanya]

The reason could be in your customization.
For testing back up and clear custom/Espo/Custom folder
Rebuild Espocrm in Administration, clear local cache, refresh the page.
All the data in the database will be saved, don't worry about it.
Also check the speed of list loading.
Check the log as well. Any new records?

[khopper]

I have cloned the VM and will try this Monday!

[khopper]

I found time today and went a head and tried this.

1. I did as you suggested, seemed fine and I was able to make changes repeatedly without issue.
2. I tried it again with the customizations in place with myself as the only user logged in and had no issues making changes.

Could it be I have to many uses in making changes (updating and creating records) while I'm trying to make changes?
The error always starts out with "Unable to clear cache" (Directory not empty) before crashing....

Suggestions?

[khopper]

As long as I am not making changes to Fields or Formula's everything else is flawless!
I repeated the test today to verify the previous results with a new image for testing today.

Any suggestions?

[tanya]

If you know, what entity is problematic, please attach entityDefs and formula of this entity

[khopper]

It happens in both Opportunities and Accounts, see attached.
I also included the workflow formulas that you originally helped me with.

[tanya]

ifThen (
client == 'COMCAST' && term == '36 Mo',
commission = ifThenElse (
voice == 'New',
(
ccblmrc + ccfflmrc + ccmlmrc - discountvoice
) * 1.0,
0
) + ifThenElse (
internet == 'New',
(ccimrc - discountinternet) * 1.0,
0
) + ifThenElse (
video == 'New' && (
string \ CONTAINS (
string \ lowerCase (ccbcvideo),
'private'
)
),
(ccvmrc - discountvideo) * 1.0,
0
) + ifThenElse (
video == 'New' && (
string \ CONTAINS (
string \ lowerCase (ccbcvideo),
'public'
)
),
(ccvmrc - discountvideo) * 1.5,
0
) + ifThenElse (
phonesystemcommission != NULL,
phonesystemcommission,
0
)
);


ifThen and ifThenElse don't return values.....

[khopper]

They shouldn't return anything if the criteria is not met. I'm not sure what your trying to point out. I have had these BAD SERVER issues since before creating these formula's you pointed out less than 2 weeks ago.

[tanya]

we told about string \ contains (string \ lowerCase (ccbcvideo),'public') (and why do you use CONTAINS in upper case)
I've never told you that ifThen returns some value.

and you have one extra + symbol

[khopper]

"CONTAINS" is actually lowercase - I just put the sql through a beautifier to make it more readable per Yurikuzn's previous request on other post.

[khopper]

ifThen is not supposed to return anything if the condition is not met, correct. I agree with you. I don't see this extra + symbol you are referring too.
Are you suggesting this very formula with calculation is causing the bad server error? Keep in mind that this has been an issue `Bad Server - updating formulas or fields` before these new formula's where ever created and is not a new thing.

[tanya]

You can use vars for this

$part1 = 0;
ifThen(voice == 'New', $part1 = (ccblmrc + ccfflmrc + ccmlmrc - discountvoice) * 1.0) ;

$part2 = 0;
ifThen (internet == 'New', $part2 = (ccimrc - discountinternet) * 1.0) ;

$part3 = 0;
ifThen(video == 'New' && ( string\contains (string\lowerCase (ccbcvideo),'private')), $part3 = (ccvmrc - discountvideo) * 1.0) ;

$part4 = 0;
ifThen(video == 'New' && ( string\contains (string\lowerCase (ccbcvideo),'private')), (ccvmrc - discountvideo) * 1.0) ;

and other parts

ifThen (client == 'COMCAST' && term == '36 Mo', commission = $part1 + $part2 + $part3 + $part4 + $partN);

[khopper]

This is nice to know, I had not yet tried using vars in this system. Thanks!

[khopper]

Got "BAD SERVER and Error Cleaning Cache" simply creating 1 field "tollfreemrc" - here are the attached system logs.
Error starts at [2018-07-31 14:39:03] through [2018-07-31 14:39:21]
Shows Uncaught Exception