Getting 500 Internal Server Error on "sonata_type_model"

[ManojBitx]

Hello

I have two entities ["Listing", "Emails"] and created the One To Many association of Listing with Emails. I used the "sonata_type_model" on the Sonata Admin of Listing Entity.

->add('emails', 'sonata_type_model',array(
    'multiple' => true,
))

When i adding the new data in Emails using "sonata_type_model" it gives an "500 Internal Server Error" but everything is working fine on app.php.

I tracked the some files of Sonata Admin and found the error is in below function.

   private function getFormRenderer()
    {
        try {
            $runtime = $this->twig->getRuntime('Symfony\Bridge\Twig\Form\TwigRenderer');
            dump($runtime);die;
            $runtime->setEnvironment($this->twig);
            return $runtime;
        } catch (\Twig_Error_Runtime $e) {
            // BC for Symfony < 3.2 where this runtime not exists
            $extension = $this->twig->getExtension('Symfony\Bridge\Twig\Extension\FormExtension');
            $extension->initRuntime($this->twig);

            return $extension->renderer;
        }
    }

[greg0ire]

When i adding the new data in Emails using "sonata_type_model" it gives an "500 Internal Server Error" but everything is working fine on app.php.

This means you are using app_dev.php, right? If yes, why are you not providing a stack trace?

[ManojBitx]

Hi @greg0ire

I am seeing the 500 Internal Server Error in Developer console. Its a ajax request. How i can get the stack trace for it.

Below are the logs of development env for this action.

[2017-06-10 17:23:25] request.INFO: Matched route "admin_project_listingemails_create". {"route":"admin_project_listingemails_create","route_parameters":{"_controller":"projectBundle\\Controller\\ListingEmailsAdminController::createAction","_sonata_admin":"my_city.admin.listing_emails","_sonata_name":"admin_project_listingemails_create","_route":"admin_project_listingemails_create"},"request_uri":"http://localhost/project/web/app_dev.php/admin/project/listingemails/create?code=my_city.admin.listing_emails&pcode=my_city.admin.listing&puniqid=s593bda4ccae49&uniqid=s593bda4d230d4","method":"GET"} [] [2017-06-10 17:23:25] security.DEBUG: Read existing security token from the session. {"key":"_security_main"} [] [2017-06-10 17:23:25] doctrine.DEBUG: SELECT t0.username AS username_1, t0.username_canonical AS username_canonical_2, t0.email AS email_3, t0.email_canonical AS email_canonical_4, t0.enabled AS enabled_5, t0.salt AS salt_6, t0.password AS password_7, t0.last_login AS last_login_8, t0.confirmation_token AS confirmation_token_9, t0.password_requested_at AS password_requested_at_10, t0.roles AS roles_11, t0.id AS id_12 FROM user t0 WHERE t0.id = ? LIMIT 1 [1] [] [2017-06-10 17:23:25] security.DEBUG: User was reloaded from a user provider. {"username":"admin","provider":"FOS\\UserBundle\\Security\\UserProvider"} [] [2017-06-10 17:23:25] php.INFO: User Deprecated: Twig loader "Sonata\FormatterBundle\Twig\Loader\LoaderSelector" should implement Twig_SourceContextLoaderInterface since version 1.27. {"exception":"[object] (Symfony\\Component\\Debug\\Exception\\ContextErrorException(code: 0): User Deprecated: Twig loader \"Sonata\\FormatterBundle\\Twig\\Loader\\LoaderSelector\" should implement Twig_SourceContextLoaderInterface since version 1.27. at /Users/manoj/Sites/project/var/cache/dev/classes.php:5641)"} [] [2017-06-10 17:23:25] php.INFO: User Deprecated: Twig loader "Sonata\FormatterBundle\Twig\Loader\LoaderSelector" should implement Twig_SourceContextLoaderInterface since version 1.27. {"exception":"[object] (Symfony\\Component\\Debug\\Exception\\ContextErrorException(code: 0): User Deprecated: Twig loader \"Sonata\\FormatterBundle\\Twig\\Loader\\LoaderSelector\" should implement Twig_SourceContextLoaderInterface since version 1.27. at /Users/manoj/Sites/project/var/cache/dev/classes.php:5641)"} [] [2017-06-10 17:23:26] php.INFO: User Deprecated: Twig loader "Sonata\FormatterBundle\Twig\Loader\LoaderSelector" should implement Twig_SourceContextLoaderInterface since version 1.27. {"exception":"[object] (Symfony\\Component\\Debug\\Exception\\ContextErrorException(code: 0): User Deprecated: Twig loader \"Sonata\\FormatterBundle\\Twig\\Loader\\LoaderSelector\" should implement Twig_SourceContextLoaderInterface since version 1.27. at /Users/manoj/Sites/project/var/cache/dev/classes.php:5641)"} [] [2017-06-10 17:23:26] php.INFO: User Deprecated: Twig loader "Sonata\FormatterBundle\Twig\Loader\LoaderSelector" should implement Twig_SourceContextLoaderInterface since version 1.27. {"exception":"[object] (Symfony\\Component\\Debug\\Exception\\ContextErrorException(code: 0): User Deprecated: Twig loader \"Sonata\\FormatterBundle\\Twig\\Loader\\LoaderSelector\" should implement Twig_SourceContextLoaderInterface since version 1.27. at /Users/manoj/Sites/project/var/cache/dev/classes.php:5641)"} [] [2017-06-10 17:23:26] translation.WARNING: Translation not found. {"id":"ListingEmails","domain":"messages","locale":"en"} [] [2017-06-10 17:23:26] translation.WARNING: Translation not found. {"id":"Label","domain":"messages","locale":"en"} [] [2017-06-10 17:23:26] translation.WARNING: Translation not found. {"id":"Official","domain":"messages","locale":"en"} [] [2017-06-10 17:23:26] translation.WARNING: Translation not found. {"id":"Personal","domain":"messages","locale":"en"} [] [2017-06-10 17:23:26] translation.WARNING: Translation not found. {"id":"Other","domain":"messages","locale":"en"} [] [2017-06-10 17:23:26] translation.WARNING: Translation not found. {"id":"Email","domain":"messages","locale":"en"} [] [2017-06-10 17:23:26] security.DEBUG: Stored the security token in the session. {"key":"_security_main"} [] [2017-06-10 17:23:29] request.INFO: Matched route "admin_project_listingemails_create". {"route":"admin_project_listingemails_create","route_parameters":{"_controller":"projectBundle\\Controller\\ListingEmailsAdminController::createAction","_sonata_admin":"my_city.admin.listing_emails","_sonata_name":"admin_project_listingemails_create","_route":"admin_project_listingemails_create"},"request_uri":"http://localhost/project/web/app_dev.php/admin/project/listingemails/create?uniqid=s593bda4d230d4","method":"POST"} [] [2017-06-10 17:23:30] security.DEBUG: Read existing security token from the session. {"key":"_security_main"} [] [2017-06-10 17:23:30] doctrine.DEBUG: SELECT t0.username AS username_1, t0.username_canonical AS username_canonical_2, t0.email AS email_3, t0.email_canonical AS email_canonical_4, t0.enabled AS enabled_5, t0.salt AS salt_6, t0.password AS password_7, t0.last_login AS last_login_8, t0.confirmation_token AS confirmation_token_9, t0.password_requested_at AS password_requested_at_10, t0.roles AS roles_11, t0.id AS id_12 FROM user t0 WHERE t0.id = ? LIMIT 1 [1] [] [2017-06-10 17:23:30] security.DEBUG: User was reloaded from a user provider. {"username":"admin","provider":"FOS\\UserBundle\\Security\\UserProvider"} [] [2017-06-10 17:23:30] doctrine.DEBUG: "START TRANSACTION" [] [] [2017-06-10 17:23:30] doctrine.DEBUG: INSERT INTO listing_emails (label, email, listing_id) VALUES (?, ?, ?) {"1":"Official","2":"Test","3":null} [] [2017-06-10 17:23:30] doctrine.DEBUG: "COMMIT" [] [] [2017-06-10 17:23:30] php.INFO: User Deprecated: Twig loader "Sonata\FormatterBundle\Twig\Loader\LoaderSelector" should implement Twig_SourceContextLoaderInterface since version 1.27. {"exception":"[object] (Symfony\\Component\\Debug\\Exception\\ContextErrorException(code: 0): User Deprecated: Twig loader \"Sonata\\FormatterBundle\\Twig\\Loader\\LoaderSelector\" should implement Twig_SourceContextLoaderInterface since version 1.27. at /Users/manoj/Sites/project/var/cache/dev/classes.php:5641)"} [] [2017-06-10 17:23:30] php.INFO: User Deprecated: Twig loader "Sonata\FormatterBundle\Twig\Loader\LoaderSelector" should implement Twig_SourceContextLoaderInterface since version 1.27. {"exception":"[object] (Symfony\\Component\\Debug\\Exception\\ContextErrorException(code: 0): User Deprecated: Twig loader \"Sonata\\FormatterBundle\\Twig\\Loader\\LoaderSelector\" should implement Twig_SourceContextLoaderInterface since version 1.27. at /Users/manoj/Sites/project/var/cache/dev/classes.php:5641)"} [] [2017-06-10 17:23:30] php.INFO: User Deprecated: Twig loader "Sonata\FormatterBundle\Twig\Loader\LoaderSelector" should implement Twig_SourceContextLoaderInterface since version 1.27. {"exception":"[object] (Symfony\\Component\\Debug\\Exception\\ContextErrorException(code: 0): User Deprecated: Twig loader \"Sonata\\FormatterBundle\\Twig\\Loader\\LoaderSelector\" should implement Twig_SourceContextLoaderInterface since version 1.27. at /Users/manoj/Sites/project/var/cache/dev/classes.php:5641)"} [] [2017-06-10 17:23:30] php.INFO: User Deprecated: Twig loader "Sonata\FormatterBundle\Twig\Loader\LoaderSelector" should implement Twig_SourceContextLoaderInterface since version 1.27. {"exception":"[object] (Symfony\\Component\\Debug\\Exception\\ContextErrorException(code: 0): User Deprecated: Twig loader \"Sonata\\FormatterBundle\\Twig\\Loader\\LoaderSelector\" should implement Twig_SourceContextLoaderInterface since version 1.27. at /Users/manoj/Sites/project/var/cache/dev/classes.php:5641)"} [] [2017-06-10 17:23:30] security.DEBUG: Stored the security token in the session. {"key":"_security_main"} [] [2017-06-10 17:23:30] request.INFO: Matched route "sonata_admin_retrieve_form_element". {"route":"sonata_admin_retrieve_form_element","route_parameters":{"_controller":"sonata.admin.controller.admin:retrieveFormFieldElementAction","_route":"sonata_admin_retrieve_form_element"},"request_uri":"http://localhost/project/web/app_dev.php/admin/core/get-form-field-element?code=my_city.admin.listing&elementId=s593bda4ccae49_emails&objectId=1&uniqid=s593bda4ccae49","method":"POST"} [] [2017-06-10 17:23:30] security.DEBUG: Read existing security token from the session. {"key":"_security_main"} [] [2017-06-10 17:23:30] doctrine.DEBUG: SELECT t0.username AS username_1, t0.username_canonical AS username_canonical_2, t0.email AS email_3, t0.email_canonical AS email_canonical_4, t0.enabled AS enabled_5, t0.salt AS salt_6, t0.password AS password_7, t0.last_login AS last_login_8, t0.confirmation_token AS confirmation_token_9, t0.password_requested_at AS password_requested_at_10, t0.roles AS roles_11, t0.id AS id_12 FROM user t0 WHERE t0.id = ? LIMIT 1 [1] [] [2017-06-10 17:23:30] security.DEBUG: User was reloaded from a user provider. {"username":"admin","provider":"FOS\\UserBundle\\Security\\UserProvider"} [] [2017-06-10 17:23:31] php.INFO: User Deprecated: Twig loader "Sonata\FormatterBundle\Twig\Loader\LoaderSelector" should implement Twig_SourceContextLoaderInterface since version 1.27. {"exception":"[object] (Symfony\\Component\\Debug\\Exception\\ContextErrorException(code: 0): User Deprecated: Twig loader \"Sonata\\FormatterBundle\\Twig\\Loader\\LoaderSelector\" should implement Twig_SourceContextLoaderInterface since version 1.27. at /Users/manoj/Sites/project/var/cache/dev/classes.php:5641)"} [] [2017-06-10 17:23:31] php.INFO: User Deprecated: Twig loader "Sonata\FormatterBundle\Twig\Loader\LoaderSelector" should implement Twig_SourceContextLoaderInterface since version 1.27. {"exception":"[object] (Symfony\\Component\\Debug\\Exception\\ContextErrorException(code: 0): User Deprecated: Twig loader \"Sonata\\FormatterBundle\\Twig\\Loader\\LoaderSelector\" should implement Twig_SourceContextLoaderInterface since version 1.27. at /Users/manoj/Sites/project/var/cache/dev/classes.php:5641)"} [] [2017-06-10 17:23:31] php.INFO: User Deprecated: Twig loader "Sonata\FormatterBundle\Twig\Loader\LoaderSelector" should implement Twig_SourceContextLoaderInterface since version 1.27. {"exception":"[object] (Symfony\\Component\\Debug\\Exception\\ContextErrorException(code: 0): User Deprecated: Twig loader \"Sonata\\FormatterBundle\\Twig\\Loader\\LoaderSelector\" should implement Twig_SourceContextLoaderInterface since version 1.27. at /Users/manoj/Sites/project/var/cache/dev/classes.php:5641)"} [] [2017-06-10 17:23:31] php.INFO: User Deprecated: Twig loader "Sonata\FormatterBundle\Twig\Loader\LoaderSelector" should implement Twig_SourceContextLoaderInterface since version 1.27. {"exception":"[object] (Symfony\\Component\\Debug\\Exception\\ContextErrorException(code: 0): User Deprecated: Twig loader \"Sonata\\FormatterBundle\\Twig\\Loader\\LoaderSelector\" should implement Twig_SourceContextLoaderInterface since version 1.27. at /Users/manoj/Sites/project/var/cache/dev/classes.php:5641)"} [] [2017-06-10 17:23:31] doctrine.DEBUG: SELECT t0.id AS id_1, t0.slug AS slug_2, t0.title AS title_3, t0.description AS description_4, t0.address AS address_5, t0.latitude AS latitude_6, t0.longitude AS longitude_7, t0.is_featured AS is_featured_8, t0.status AS status_9, t0.website AS website_10, t0.updated_at AS updated_at_11, t0.created_at AS created_at_12, t0.city_id AS city_id_13 FROM listing t0 WHERE t0.id = ? ["1"] [] [2017-06-10 17:23:31] doctrine.DEBUG: SELECT t0.id AS id_1, t0.label AS label_2, t0.email AS email_3, t0.listing_id AS listing_id_4 FROM listing_emails t0 [] [] [2017-06-10 17:23:31] doctrine.DEBUG: SELECT t0.id AS id_1, t0.label AS label_2, t0.phone AS phone_3, t0.listing_id AS listing_id_4 FROM listing_phone t0 [] [] [2017-06-10 17:23:31] doctrine.DEBUG: SELECT t0.id AS id_1, t0.label AS label_2, t0.email AS email_3, t0.listing_id AS listing_id_4 FROM listing_emails t0 WHERE t0.listing_id = ? [1] [] [2017-06-10 17:23:31] doctrine.DEBUG: SELECT t0.id AS id_1, t0.label AS label_2, t0.phone AS phone_3, t0.listing_id AS listing_id_4 FROM listing_phone t0 WHERE t0.listing_id = ? [1] [] [2017-06-10 17:23:31] doctrine.DEBUG: SELECT t0.id AS id_1, t0.domain_name AS domain_name_2, t0.name AS name_3, t0.city_code AS city_code_4, t0.pincode AS pincode_5, t0.telephone_code AS telephone_code_6, t0.vehicle_code AS vehicle_code_7, t0.type AS type_8, t0.population AS population_9, t0.male_population AS male_population_10, t0.female_population AS female_population_11, t0.literacy_rate AS literacy_rate_12, t0.latitude AS latitude_13, t0.longitude AS longitude_14, t0.is_domain_active AS is_domain_active_15, t0.status AS status_16, t0.state_id AS state_id_17 FROM city t0 WHERE t0.id = ? [1] [] [2017-06-10 17:23:31] doctrine.DEBUG: SELECT c0_.id AS id_0, c0_.domain_name AS domain_name_1, c0_.name AS name_2, c0_.city_code AS city_code_3, c0_.pincode AS pincode_4, c0_.telephone_code AS telephone_code_5, c0_.vehicle_code AS vehicle_code_6, c0_.type AS type_7, c0_.population AS population_8, c0_.male_population AS male_population_9, c0_.female_population AS female_population_10, c0_.literacy_rate AS literacy_rate_11, c0_.latitude AS latitude_12, c0_.longitude AS longitude_13, c0_.is_domain_active AS is_domain_active_14, c0_.status AS status_15, c0_.state_id AS state_id_16 FROM city c0_ WHERE c0_.id IN (?) [["1"]] [] [2017-06-10 17:23:31] doctrine.DEBUG: SELECT c0_.id AS id_0, c0_.domain_name AS domain_name_1, c0_.name AS name_2, c0_.city_code AS city_code_3, c0_.pincode AS pincode_4, c0_.telephone_code AS telephone_code_5, c0_.vehicle_code AS vehicle_code_6, c0_.type AS type_7, c0_.population AS population_8, c0_.male_population AS male_population_9, c0_.female_population AS female_population_10, c0_.literacy_rate AS literacy_rate_11, c0_.latitude AS latitude_12, c0_.longitude AS longitude_13, c0_.is_domain_active AS is_domain_active_14, c0_.status AS status_15, c0_.state_id AS state_id_16 FROM city c0_ [] [] [2017-06-10 17:23:31] php.INFO: User Deprecated: The "Symfony\Bridge\Twig\Form\TwigRendererEngine::setEnvironment()" method is deprecated since version 3.3 and will be removed in 4.0. Pass the Twig Environment as second argument of the constructor instead. {"exception":"[object] (Symfony\\Component\\Debug\\Exception\\ContextErrorException(code: 0): User Deprecated: The \"Symfony\\Bridge\\Twig\\Form\\TwigRendererEngine::setEnvironment()\" method is deprecated since version 3.3 and will be removed in 4.0. Pass the Twig Environment as second argument of the constructor instead. at /Users/manoj/Sites/project/vendor/symfony/symfony/src/Symfony/Bridge/Twig/Form/TwigRendererEngine.php:52)"} []

[greg0ire]

I am seeing the 500 Internal Server Error in Developer console. Its a ajax request. How i can get the stack trace for it.

Open the symfony profiler, that will give you the profile for the current, non-ajax request. Then, on the left, you should see a form or links to other requests, I don't remember exactly how it looks like, but the thing is, you can find the profile for your AJAX request in there, and with it, the desired stack trace.

[ManojBitx]

Hi @greg0ire I checked the all tabs in Profiler and didn't found any stack trace option for ajax request. Please check the below image of my profiler.

I can share the screen if you want. My Email address: smanojsaini@gmail.com

[greg0ire]

See the Last 10, Latest and Search thingy top left? Find the profile of your AJAX request with it first, and worry about the stack trace later.

[ManojBitx]

Here are the screenshot from Last 10.

This the screenshot of console.

This is the ajax call code written

But i don't see the failed request in Last 10 tab.

[greg0ire]

See that Status field? Input 500 in it, you should get better results.

[greg0ire]

You can also input get-form-field in the URL filter.

[greg0ire]

If there is still no profile, it means symfony is not involved in answering this 500, which I doubt. In the second screenshot of the console, there is a "response" tab. Have you clicked it?

[ManojBitx]

I searched using URL field and found the result in profiler. Below is the screenshot of that

I also checked the response tab that is showing blank. Also this thing i working fine on production the issue is only at development environment.

[greg0ire]

You found the correct profile! Great! You also found a preview of the exception, with a clear error message.

See that "Exception" menu entry? click it if you want something even more beautiful, but I think the solution is already clear: you must implement ListingPhone::__toString(), or at least tell sonata which field to use to represent ListingPhone, by using the property option. Closing this this is not a bug.

[ManojBitx]

@greg0ire The code to covert the Phone into string is already there in entity file.

Also, i checked the timestamp of the profiler. It is from 13:35 but the new profiler timestamps are 19:30. That one from 13:35 timestamp i was able to fine in profiler. The new requests are not logged in the profiler.

I don't how it is working fine on Production without changing anything.

[ManojBitx]

Also the some deprecations showing. See below

[greg0ire]

Deprecation are something else completely. Make sure sonata is up to date before trying to fix them. For your issue, you can do step by step debugging with xdebug to find out what is going on. I suggest you clear your cache, try reproducing the issue in as few http requests as possible, and have a look at the profiler to see if the 500 still does not show up in it.

[ManojBitx]

@greg0ire I tried everything that i can do. I tried clearing cache, checked all the logs, profilers but i didn't able to find why this is causing only on development environment. If you need any logs or any access from my side i will provide you.

[greg0ire]

I tried everything that i can do.

Really?

For your issue, you can do step by step debugging with xdebug to find out what is going on.

Did you even try this?

[OskarStark]

any news @cipherm ?

[ManojBitx]

@OskarStark Still, this issue is pending

[fracsi]

I just ran into this issue with Symfony 3.3 with the default configuration, the error came from the logger configuration (config_dev.yml):

    server_log:
        type: server_log
        process_psr_3_messages: false
        host: 127.0.0.1:9911

For me removing this section solved the problem.

[LMSzor]

Have You actually tried the solution given in exception message? Setting the "property" value for admin FormMapper?

->add('emails', 'sonata_type_model',array(
    'multiple' => true,
    'property' => 'phone'
))

Also try to provide some kind of default value for your field in __toString(), like...

public function __toString() {
    return $this->getPhone() ?? '9876543210';
}

[jordisala1991]

Error is clear, toString method missing somehow. Closing. If this is relevant still with newer versions, please ping to reopen