Trying to create new case results in 500 internal server error

[mwandelt]

After updating to v8.3.5 I cannot create new cases anymore. Every request results in an HTTP 500 status code and the following log entries:

[2024-07-19 16:59:47] DEBUG: API (0) Entity ID is not set.; POST /Case; Input data: {"status":"New","priority":"Normal","name":"TES T"} ; Route pattern: /{controller}; Route params: Array ( [controller] => Case [action] => create )
[2024-07-19 16:59:47] CRITICAL: (0) Entity ID is not set. :: POST /Case :: /var/www/crm.virthos.net/application/Espo/ORM/BaseEntity.php(106)

There are no problems creating other entities or updating existing cases. Manually creating new records in the `case` database table works flawlessly, too.

My system is Ubuntu 22.04.4 LTS with PHP 8.1.29 and MariaDB 10.5.23.

I ran several EspoCRM updates at once, so the problem might not be related to v8.3.5 specifically.

Any ideas?

[mwandelt]

That's a rather annoying error. I would really appreciate some advice, in which direction to look for a solution.

[lazovic]

Hi mwandelt,

Please tell me, do you have any formula scripts, workflows, or flowcharts that affect the Case entity in one way or another? Also, tell me, do you have any third-party extensions installed in your EspoCRM instance? Do you have some file customization (e.g., in the {ESPO_ROOT}/custom folder)?

[mwandelt]

Thanks for the response. I have no formular scripts, no workflows or flowcharts that affect the Case entity, and there are no third-party extensions installed and no file customizations.

[mwandelt]

Hi lazovic, do you have any idea where to look for the cause of this odd behaviour?

[lazovic]

Hi mwandelt,

Perhaps something went wrong during the upgrades. This is a very rare error.

Please tell me if you have the ability to reinstall your EspoCRM instance? You can use the following instructions: https://docs.espocrm.com/administrat...another-server.

[yuri]

Hi,

Try enabling "printTrace" https://docs.espocrm.com/administration/log/ and then check that is printed to the log. It may be helpful.

[mwandelt]

When I try to create a new case with "printTrace" enabled, I get following log entries:

2024-07-29 09:16:12] DEBUG: API (0) Entity ID is not set.; POST /Case; Input data: {"status":"New","priority":"Normal","assignedUserId":"1","assignedUserName":"Martin Wandelt","name":"TEST","accountName":null,"accountId":null,"type":null,"contactsIds":[],"contactsNames":{},"invoicesIds":[],"invoicesNames":{},"confidentialInfo":null,"attachmentsIds":[],"descriptionHtml":null,"teamsIds":[],"teamsNames":{}}; Route pattern: /{controller}; Route params: Array
(
    [controller] => Case
    [action] => cre[ate
)
[2024-07-29 09:16:12] INFO: SQL: INSERT INTO `app_log_record` (`id`, `deleted`, `created_at`, `message`, `level`, `code`, `exception_class`, `file`, `line`, `request_method`, `request_resource_path`) VALUES ('66a75ddca1862cb04', 0, '2024-07-29 09:16:12', 'Entity ID is not set.', 'Critical', 0, 'RuntimeException', '/var/www/crm.virthos.net/application/Espo/ORM/BaseEntity.php', 106, 'POST', '/Case')
[2024-07-29 09:16:12] CRITICAL: (0) Entity ID is not set. :: POST /Case :: /var/www/crm.virthos.net/application/Espo/ORM/BaseEntity.php(106)
[object] (RuntimeException(code: 0): Entity ID is not set. at /var/www/crm.virthos.net/application/Espo/ORM/BaseEntity.php:106)
[stacktrace]
#0 /var/www/crm.virthos.net/application/Espo/Core/Formula/Functions/EntityGroup/SumRelatedType.php(127): Espo\ORM\BaseEntity->getId()
#1 /var/www/crm.virthos.net/application/Espo/Core/Formula/Processor.php(102): Espo\Core\Formula\Functions\EntityGroup\SumRelatedType->process()
#2 /var/www/crm.virthos.net/application/Espo/Core/Formula/Functions/BaseFunction.php(97): Espo\Core\Formula\Processor->process()
#3 /var/www/crm.virthos.net/application/Espo/Core/Formula/Functions/NumericGroup/DivisionType.php(45): Espo\Core\Formula\Functions\BaseFunction->evaluate()
#4 /var/www/crm.virthos.net/application/Espo/Core/Formula/Processor.php(105): Espo\Core\Formula\Functions\NumericGroup\DivisionType->process()
#5 /var/www/crm.virthos.net/application/Espo/Core/Formula/Functions/BaseFunction.php(97): Espo\Core\Formula\Processor->process()
#6 /var/www/crm.virthos.net/application/Espo/Core/Formula/Functions/NumberGroup/RoundType.php(45): Espo\Core\Formula\Functions\BaseFunction->evaluate()
#7 /var/www/crm.virthos.net/application/Espo/Core/Formula/Processor.php(105): Espo\Core\Formula\Functions\NumberGroup\RoundType->process()
#8 /var/www/crm.virthos.net/application/Espo/Core/Formula/Functions/Base.php(144): Espo\Core\Formula\Processor->process()
#9 /var/www/crm.virthos.net/application/Espo/Core/Formula/Functions/SetAttributeType.php(56): Espo\Core\Formula\Functions\Base->evaluate()
#10 /var/www/crm.virthos.net/application/Espo/Core/Formula/Processor.php(102): Espo\Core\Formula\Functions\SetAttributeType->process()
#11 /var/www/crm.virthos.net/application/Espo/Core/Formula/Evaluator.php(122): Espo\Core\Formula\Processor->process()
#12 /var/www/crm.virthos.net/application/Espo/Core/Formula/Evaluator.php(82): Espo\Core\Formula\Evaluator->processInternal()
#13 /var/www/crm.virthos.net/application/Espo/Core/Formula/Manager.php(61): Espo\Core\Formula\Evaluator->process()
#14 /var/www/crm.virthos.net/application/Espo/Core/Record/Formula/Processor.php(92): Espo\Core\Formula\Manager->run()
#15 /var/www/crm.virthos.net/application/Espo/Core/Record/Formula/Processor.php(67): Espo\Core\Record\Formula\Processor->run()
#16 /var/www/crm.virthos.net/application/Espo/Core/Record/Service.php(1991): Espo\Core\Record\Formula\Processor->processBeforeCreate()
#17 /var/www/crm.virthos.net/application/Espo/Core/Record/Service.php(857): Espo\Core\Record\Service->processApiBeforeCreateApiScript()
#18 /var/www/crm.virthos.net/application/Espo/Core/Controllers/RecordBase.php(183): Espo\Core\Record\Service->create()
#19 /var/www/crm.virthos.net/application/Espo/Core/Api/ControllerActionProcessor.php(87): Espo\Core\Controllers\RecordBase->postActionCreate()
#20 /var/www/crm.virthos.net/application/Espo/Core/Api/ControllerActionHandler.php(69): Espo\Core\Api\ControllerActionProcessor->process()
#21 /var/www/crm.virthos.net/vendor/slim/slim/Slim/MiddlewareDispatcher.php(65): Espo\Core\Api\ControllerActionHandler->handle()
#22 /var/www/crm.virthos.net/application/Espo/Core/Api/RouteProcessor.php(222): Slim\MiddlewareDispatcher->handle()
#23 /var/www/crm.virthos.net/application/Espo/Core/Api/RouteProcessor.php(149): Espo\Core\Api\RouteProcessor->processControllerAction()
#24 /var/www/crm.virthos.net/application/Espo/Core/Api/RouteProcessor.php(127): Espo\Core\Api\RouteProcessor->processAfterAuth()
#25 /var/www/crm.virthos.net/application/Espo/Core/Api/RouteProcessor.php(79): Espo\Core\Api\RouteProcessor->processInternal()
#26 /var/www/crm.virthos.net/application/Espo/Core/Api/Starter.php(109): Espo\Core\Api\RouteProcessor->process()
#27 /var/www/crm.virthos.net/vendor/slim/slim/Slim/Handlers/Strategies/RequestResponse.php(38): Espo\Core\Api\Starter->Espo\Core\Api\{closure}()
#28 /var/www/crm.virthos.net/vendor/slim/slim/Slim/Routing/Route.php(358): Slim\Handlers\Strategies\RequestResponse->__invoke()
#29 /var/www/crm.virthos.net/vendor/slim/slim/Slim/MiddlewareDispatcher.php(65): Slim\Routing\Route->handle()
#30 /var/www/crm.virthos.net/vendor/slim/slim/Slim/MiddlewareDispatcher.php(65): Slim\MiddlewareDispatcher->handle()
#31 /var/www/crm.virthos.net/vendor/slim/slim/Slim/Routing/Route.php(315): Slim\MiddlewareDispatcher->handle()
#32 /var/www/crm.virthos.net/vendor/slim/slim/Slim/Routing/RouteRunner.php(68): Slim\Routing\Route->run()
#33 /var/www/crm.virthos.net/vendor/slim/slim/Slim/Middleware/RoutingMiddleware.php(45): Slim\Routing\RouteRunner->handle()
#34 /var/www/crm.virthos.net/vendor/slim/slim/Slim/MiddlewareDispatcher.php(121): Slim\Middleware\RoutingMiddleware->process()
#35 /var/www/crm.virthos.net/vendor/slim/slim/Slim/Middleware/ErrorMiddleware.php(76): Psr\Http\Server\RequestHandlerInterface@anonymous->handle()
#36 /var/www/crm.virthos.net/vendor/slim/slim/Slim/MiddlewareDispatcher.php(121): Slim\Middleware\ErrorMiddleware->process()
#37 /var/www/crm.virthos.net/vendor/slim/slim/Slim/MiddlewareDispatcher.php(65): Psr\Http\Server\RequestHandlerInterface@anonymous->handle()
#38 /var/www/crm.virthos.net/vendor/slim/slim/Slim/App.php(199): Slim\MiddlewareDispatcher->handle()
#39 /var/www/crm.virthos.net/vendor/slim/slim/Slim/App.php(183): Slim\App->handle()
#40 /var/www/crm.virthos.net/application/Espo/Core/Api/Starter.php(76): Slim\App->run()
#41 /var/www/crm.virthos.net/application/Espo/Core/ApplicationRunners/Api.php(45): Espo\Core\Api\Starter->start()
#42 /var/www/crm.virthos.net/application/Espo/Core/Application/RunnerRunner.php(84): Espo\Core\ApplicationRunners\Api->run()
#43 /var/www/crm.virthos.net/application/Espo/Core/Application.php(78): Espo\Core\Application\RunnerRunner->run()
#44 /var/www/crm.virthos.net/public/api/v1/index.php(35): Espo\Core\Application->run()
#45 {main}​

I could do a reinstall, but when I follow the instructions for moving to another server I would get an exact copy of the current system, wouldn't I? Are you sure, that would solve the issue?

[yuri]

The trace tells that you actually have a formula script that fails. API Before Safe script for the Case entity type.

[mwandelt]

That's strange. When the 500 error occured for the first time, I removed the formula, but that didn't change anything. So I restored it. Today I removed the formula again, and now the error disappears. Really strange. But the main thing is that it works again. Thanks for the support!

Do you have an idea, why the formula, which had been worked for years, makes trouble now? Here is the code:

workTimeSum = number\round( entity\sumRelated( 'workTimes', 'minutes' )/60, 2 );

I guess, in the current EspoCRM version the sumRelated function may not be applied when creating records. On updates it works flawlessly. But how can I distinguish between those two cases in a formula?

[mwandelt]

workTime => Event
workTimeSum => Float
minutes => Float
script type => API Before Save Script

[victor]

And what type of relationship between case and workTime?

[mwandelt]

case : workTime = 1 : n

[victor]

I reproduced this error.
If you use Before Save Custom Script instead of API Before Save Script, the error does not occur.

[mwandelt]

Thank you very much for your excellent support! When storing the formula in Before Custom Save Script there is no error anymore.

[yuri]

The formula failed because when API before-save script is executed for a new record, there's no yet record ID set in the entity. The function entity\sumRelated requires the record ID.