500 error on updating entity schema

[Zyles]

So I tried to make new entity, added field etc. and run "Update schema" and I get 500 error.

Which log file would this be saved to? I checked the logs for prod.log and dev.log and the apache log but I can't find any errors.

In fact this destroys the entire application. I can not go to any report view.

An urgent fix would be welcome as I need to test the entity system extensively.

[rgrebenchuk]

Hi,
Issue is in console commands and requirements verification, an urgent fix is set writable permissions for web server user for web folder or disable notices in php.ini error level option

[Zyles]

I have 777 on web/ already.

[astorm]

Zyles — do you have a screen shot of the 500 error (full browser window). A modern web application can throw a 500 in a variety of different ways — knowing which way will help others help you with your problem.

[Zyles]

Any browser. The error is server based.

The url is #url=/oro/web/entity/extend/update/27

[astorm]

Thanks Zyles, that's helpful. However, in the future if you can take a screenshot with the full browser window, including URL bar, that will be extra helpful to people trying to debug.

Looking at your screenshot, it's a stylized error which means the problem isn't with the web server, it's with the application itself. This is also the error page OroCRM shows when running in production mode. If you run it in development mode, you'll often get a more robust error. Can you try running the application with a development mode URL and posting the 500 error screen shots you see there?

http://orocrm.example.com/app_dev.php
http://orocrm.example.com/app_dev.php/path/to/whawtever

[Zyles]

I can't screenshot the entire URL since it is a public URL. I have now tested it with app_dev.php

The application is a fresh https://github.com/orocrm/platform-application

Now I get access to the error logs and stuff and this stands out:

http://example.com/oro/web/app_dev.php/entity/extend/update/27

[dxops]

Hi, @Zyles !

Can you run app /console oro:entity-extend:update-config --env=prod directly from console and post output here?

Urgent fix is to remove https://github.com/orocrm/platform/blob/1.2/src/Oro/Bundle/InstallerBundle/Resources/config/services.yml#L40 this definition.

The application is a fresh

Can you check this closely? This functionality was removed on master, so looks like you are suing 1.2 version

[Zyles]

Seems to work now. I can create new entities and update schema in dev mode.

But there is a new problem. Everything works with app_dev.php but if I login without it I get 500 errors everywhere I go.

[Zyles]

Now it spits this out in prod.log on ANY url I go to. Again I have no issues with app_dev.php

[2014-06-27 16:13:47] request.INFO: Matched route "oro_config_configuration_system" (parameters: "activeGroup": "null", "activeSubGroup": "null", "_controller": "Oro\Bundle\ConfigBundle\Controller\ConfigurationController::systemAction", "_route": "oro_config_configuration_system") [] []
[2014-06-27 16:13:47] security.DEBUG: Read SecurityContext from the session [] []
[2014-06-27 16:13:47] security.DEBUG: Reloading user from user provider. [] []
[2014-06-27 16:13:47] security.DEBUG: Username "admin" was reloaded from user provider. [] []
[2014-06-27 16:13:47] security.DEBUG: Invoked controller "Oro\Bundle\ConfigBundle\Controller\ConfigurationController::systemAction". (MASTER_REQUEST) [] []
[2014-06-27 16:13:47] security.DEBUG: Check an access using "oro_config_system" ACL annotation. [] []
[2014-06-27 16:13:47] security.DEBUG: ACL found, permission granted. Voting to grant access [] []
[2014-06-27 16:13:47] security.DEBUG: Check an access using "oro_user_user_create" ACL annotation. [] []
[2014-06-27 16:13:47] security.DEBUG: ACL found, permission granted. Voting to grant access [] []
[2014-06-27 16:13:47] security.DEBUG: Check an access using "oro_user_user_view" ACL annotation. [] []
[2014-06-27 16:13:47] security.DEBUG: ACL found, permission granted. Voting to grant access [] []
[2014-06-27 16:13:47] security.DEBUG: Check an access using "oro_user_role_create" ACL annotation. [] []
[2014-06-27 16:13:47] security.DEBUG: ACL found, permission granted. Voting to grant access [] []
[2014-06-27 16:13:47] security.DEBUG: Check an access using "oro_user_group_create" ACL annotation. [] []
[2014-06-27 16:13:47] security.DEBUG: ACL found, permission granted. Voting to grant access [] []
[2014-06-27 16:13:47] security.DEBUG: Check an access using "oro_jobs" ACL annotation. [] []
[2014-06-27 16:13:47] security.DEBUG: ACL found, permission granted. Voting to grant access [] []
[2014-06-27 16:13:47] security.DEBUG: Check an access using "oro_tag_create" ACL annotation. [] []
[2014-06-27 16:13:47] security.DEBUG: ACL found, permission granted. Voting to grant access [] []
[2014-06-27 16:13:47] security.DEBUG: Invoked controller "Oro\Bundle\SearchBundle\Controller\SearchController::searchBarAction". (SUB_REQUEST) [] []
[2014-06-27 16:13:47] security.DEBUG: Check an access using "oro_search" ACL annotation. [] []
[2014-06-27 16:13:47] security.DEBUG: ACL found, permission granted. Voting to grant access [] []
[2014-06-27 16:13:47] security.DEBUG: ACL found, permission granted. Voting to grant access [] []
[2014-06-27 16:13:47] security.DEBUG: ACL found, permission granted. Voting to grant access [] []
[2014-06-27 16:13:47] security.DEBUG: ACL found, permission granted. Voting to grant access [] []
[2014-06-27 16:13:47] security.DEBUG: Check class based an access using "oro_search" ACL annotation. [] []
[2014-06-27 16:13:47] security.DEBUG: ACL found, permission granted. Voting to grant access [] []
[2014-06-27 16:13:47] security.DEBUG: Check an access using "oro_business_unit_view" ACL annotation. [] []
[2014-06-27 16:13:47] security.DEBUG: ACL found, permission granted. Voting to grant access [] []
[2014-06-27 16:13:47] security.DEBUG: Check an access using "oro_user_role_view" ACL annotation. [] []
[2014-06-27 16:13:47] security.DEBUG: ACL found, permission granted. Voting to grant access [] []
[2014-06-27 16:13:47] security.DEBUG: Check an access using "oro_user_group_view" ACL annotation. [] []
[2014-06-27 16:13:47] security.DEBUG: ACL found, permission granted. Voting to grant access [] []
[2014-06-27 16:13:47] security.DEBUG: Check an access using "oro_email_emailtemplate_index" ACL annotation. [] []
[2014-06-27 16:13:47] security.DEBUG: ACL found, permission granted. Voting to grant access [] []
[2014-06-27 16:13:47] security.DEBUG: Check an access using "oro_notification_emailnotification_view" ACL annotation. [] []
[2014-06-27 16:13:47] security.DEBUG: ACL found, permission granted. Voting to grant access [] []
[2014-06-27 16:13:47] security.DEBUG: Check an access using "oro_integration_channel_index" ACL annotation. [] []
[2014-06-27 16:13:47] security.DEBUG: ACL found, permission granted. Voting to grant access [] []
[2014-06-27 16:13:47] security.DEBUG: Check an access using "oro_embedded_form_view" ACL annotation. [] []
[2014-06-27 16:13:47] security.DEBUG: ACL found, permission granted. Voting to grant access [] []
[2014-06-27 16:13:47] security.DEBUG: Check an access using "oro_config_system" ACL annotation. [] []
[2014-06-27 16:13:47] security.DEBUG: ACL found, permission granted. Voting to grant access [] []
[2014-06-27 16:13:47] security.DEBUG: Check an access using "oro_dataaudit_history" ACL annotation. [] []
[2014-06-27 16:13:47] security.DEBUG: ACL found, permission granted. Voting to grant access [] []
[2014-06-27 16:13:47] security.DEBUG: Check an access using "oro_entityconfig_manage" ACL annotation. [] []
[2014-06-27 16:13:47] security.DEBUG: ACL found, permission granted. Voting to grant access [] []
[2014-06-27 16:13:47] security.DEBUG: Check an access using "oro_platform_system_info" ACL annotation. [] []
[2014-06-27 16:13:47] security.DEBUG: ACL found, permission granted. Voting to grant access [] []
[2014-06-27 16:13:47] security.DEBUG: Check an access using "oro_tag_view" ACL annotation. [] []
[2014-06-27 16:13:47] security.DEBUG: ACL found, permission granted. Voting to grant access [] []
[2014-06-27 16:13:47] security.DEBUG: Check an access using "oro_workflow_definition_view" ACL annotation. [] []
[2014-06-27 16:13:47] security.DEBUG: ACL found, permission granted. Voting to grant access [] []
[2014-06-27 16:13:47] security.DEBUG: Check an access using "oro_dashboard_view" ACL annotation. [] []
[2014-06-27 16:13:47] security.DEBUG: ACL found, permission granted. Voting to grant access [] []
[2014-06-27 16:13:47] security.DEBUG: Check an access using "oro_report_view" ACL annotation. [] []
[2014-06-27 16:13:47] security.DEBUG: ACL found, permission granted. Voting to grant access [] []
[2014-06-27 16:13:47] security.DEBUG: Check an access using "oro_segment_view" ACL annotation. [] []
[2014-06-27 16:13:47] security.DEBUG: ACL found, permission granted. Voting to grant access [] []
[2014-06-27 16:13:47] security.DEBUG: ACL found, permission granted. Voting to grant access [] []
[2014-06-27 16:13:47] request.CRITICAL: Uncaught PHP Exception Twig_Error_Runtime: "An exception has been thrown during the rendering of a template ("Class Extend\Entity\TestEntity does not exist") in "/home/httpd/public_html/oro/vendor/oro/platform/src/Oro/Bundle/NavigationBundle/Resources/views/ApplicationMenu/applicationMenu.html.twig" at line 2." at /home/httpd/public_html/oro/app/cache/prod/classes.php line 4813 {"exception":"[object] (Twig_Error_Runtime: An exception has been thrown during the rendering of a template (\"Class Extend\\Entity\\TestEntity does not exist\") in \"/home/httpd/public_html/oro/vendor/oro/platform/src/Oro/Bundle/NavigationBundle/Resources/views/ApplicationMenu/applicationMenu.html.twig\" at line 2. at /home/httpd/public_html/oro/app/cache/prod/classes.php:4813, ReflectionException: Class Extend\\Entity\\TestEntity does not exist at /home/httpd/public_html/oro/vendor/doctrine/common/lib/Doctrine/Common/Persistence/AbstractManagerRegistry.php:199)"} []
[2014-06-27 16:13:47] security.DEBUG: Invoked controller "FOS\RestBundle\Controller\ExceptionController::showAction". (SUB_REQUEST) [] []
[2014-06-27 16:13:47] security.DEBUG: Check an access using "oro_calendar_view" ACL annotation. [] []
[2014-06-27 16:13:47] security.DEBUG: ACL found, permission granted. Voting to grant access [] []
[2014-06-27 16:13:47] security.DEBUG: Write SecurityContext in the session [] []

[astorm]

Zyles, you might have more luck on the OroCRM forums — these are starting to sound more like development questions that issues with the framework/application itself (I know, there's a fine line between the two).

Oro uses Symfony's logger (Monologger, I think). This logger will hold all logged content until an error of a certain level happens (DEBUG, INFO, MESSAGE,CRITICAL) That's why you're seeing so many logged lines. However, if you look for theCRITICAL` error

[2014-06-27 16:13:47] request.CRITICAL: Uncaught PHP Exception Twig_Error_Runtime: "An exception has been thrown during the rendering of a template ("Class Extend\Entity\TestEntity does not exist") in "/home/httpd/public_html/oro/vendor/oro/platform/src/Oro/Bundle/NavigationBundle/Resources/views/ApplicationMenu/applicationMenu.html.twig" at line 2." at /home/httpd/public_html/oro/app/cache/prod/classes.php line 4813 {"exception":"[object](Twig_Error_Runtime: An exception has been thrown during the rendering of a template %28"Class Extend\Entity\TestEntity does not exist"%29 in "/home/httpd/public_html/oro/vendor/oro/platform/src/Oro/Bundle/NavigationBundle/Resources/views/ApplicationMenu/applicationMenu.html.twig" at line 2. at /home/httpd/public_html/oro/app/cache/prod/classes.php:4813, ReflectionException: Class Extend\Entity\TestEntity does not exist at /home/httpd/public_html/oro/vendor/doctrine/common/lib/Doctrine/Common/Persistence/AbstractManagerRegistry.php:199)"} []

It sounds like PHP/Symfony/Oro are looking for a custom class Extend\Entity\TestEntity. This is either because you configured something to use this class, added some template code to use this class, or Oro was supposed to generate the class but didn't.

[dxops]

But there is a new problem. Everything works with app_dev.php but if I login without it I get 500 errors everywhere I go.

try app/console cache:clear --env=prod

if error still be there then you need to run schema update in dev mode

[Zyles]

@astorm

It is not a development issue since I have written ZERO code. Like I stated before I used the skeleton platform installation. If I use the interface provided by the default Oro platform to create custom entities and it throws errors this is obviously a problem somewhere else.

@SergeyZ

Thanks now it works. What is the source problem of this issue? Is it cache write/delete permissions? I am pretty sure when I installed the application that I fixed them or else I would not even be able to run the application in the first place.

I once again ran chmod 777 -R app/cache/ so I will see if I run into this again.

When you update the schema does it clear the cache etc. by itself?

[dxops]

@Zyles

This listener supposed to be wide-case but its hard to cover all cases(sometimes permissions must be removed after installation), so we decided to use check on setup only. It was removed in master. Will be in our next release.

[Zyles]

This problem still persists. Pretty annoying.

[dxops]

Provide detailed steps to reproduce please.

[Zyles]

This seems to be tied to the field type "Text".

1. Create new field, select "Text" field type
2. Update schema = 500 error

Other field types seem to work.

SQLSTATE[42000]: Syntax error or access violation: 1170 BLOB/TEXT column 'source_data' used in key specification without a key length

[Zyles]

Just updated to the latest Oro and it seems to have been fixed now.

Thanks.