Unmet expectations give way too much output

[linaori]

Whenever an expectation is not matched, the arguments are dumped, but they are dumped with so much information, that the error is nearly unreadable. I love prophecy, but the more I work with this, the more I dislike it because I can't properly see the differences.

Now I'm not sure if the outputting is done by PHPUnit or Prophecy, so if I'm at the wrong place here, I'll reopen this issue in the PHPUnit repo.

Example (Yes, I'm making you scroll down for the rest):

There was 1 error:

1) Hostnet\App\Form\Contract\Handler\EmailDeleteHandlerTypeTest::testOnSuccess
Prophecy\Exception\Call\UnexpectedCallException: Method call:
  - process(Hostnet\App\Component\ActionLog\Hosting\MailboxDeletedActionLog:000000002ea1f917000000000b229436 Object (
    'contract' => Hostnet\Contract\Entity\HostingContract:000000002ea1f9e2000000000b229436 Object (
        'id' => null
        'client' => Hostnet\Client\Entity\Client:000000002ea1f9d2000000000b229436 Object (
            'id' => null
            'contact_persons' => Doctrine\Common\Collections\ArrayCollection:000000002ea1f9d1000000000b229436 Object (
                'elements' => Array &0 (
                    0 => Hostnet\Client\Entity\ContactPerson:000000002ea1f9d8000000000b229436 Object (
                        'id' => null
                        'mutations' => Doctrine\Common\Collections\ArrayCollection:000000002ea1f9d6000000000b229436 Object (
                            'elements' => Array &1 ()
                        )
                        'params' => Doctrine\Common\Collections\ArrayCollection:000000002ea1f9d5000000000b229436 Object (
                            'elements' => Array &2 ()
                        )
                        'authentication' => null
                        'client' => Hostnet\Client\Entity\Client:000000002ea1f9d2000000000b229436 Object
                        'type' => 0
                        'gender' => 'M'
                        'company_name' => null
                        'email' => 'hdevries@hostnet.nl'
                        'telephone' => '0612345789'
                        'mobile' => null
                        'fax' => null
                        'country' => Hostnet\Client\Entity\Country:000000002ea081bd000000000b229436 Object (
                            'id' => 1984
                            'calling_code' => 31
                            'country_code' => 'NL'
                            'region_code' => null
                            'description' => 'Nederland'
                            'in_eu' => true
                            'vat_rate' => '21'
                            'deleted_at' => null
                            'language' => 0
                        )
                        'language' => 0
                        'incorrect_information' => 0
                        'email_status' => 0
                        'nature_type' => 1
                        'created_at' => DateTime:000000002ea1f9d4000000000b229436 Object (
                            'date' => '2018-02-13 08:36:21.141707'
                            'timezone_type' => 3
                            'timezone' => 'Europe/Amsterdam'
                        )
                        'updated_at' => DateTime:000000002ea1f9d3000000000b229436 Object (
                            'date' => '2018-02-13 08:36:21.141710'
                            'timezone_type' => 3
                            'timezone' => 'Europe/Amsterdam'
                        )
                        'updated_by' => null
                        'name' => Hostnet\Client\Entity\Name:000000002ea1f9e0000000000b229436 Object (
                            'initials' => null
                            'first_name' => 'Henk'
                            'middle_name' => 'de'
                            'last_name' => 'Vries'
                        )
                        'address' => Hostnet\Client\Entity\Address:000000002ea1f9db000000000b229436 Object (
                            'street' => 'De ruijterkade'
                            'house_number' => '6'
                            'zip_code' => '1013 AA'
                            'city' => 'Amsterdam'
                            'country' => Hostnet\Client\Entity\Country:000000002ea081bd000000000b229436 Object
                            'extra' => null
                        )
                        'revision' => null
                        'sms_notifications_enabled' => true
                        'disabled_at' => null
                    )
                )
            )
            'domain_contact_persons' => null
            'mutations' => Doctrine\Common\Collections\ArrayCollection:000000002ea1f9d0000000000b229436 Object (
                'elements' => Array &3 ()
            )
            'adyen_client' => null
            'bank_accounts' => null
            'discounts' => null
            'preferences' => null
            'contracts' => null
            'terminations' => null
            'dns_templates' => null
            'preferred_dns_template' => null
            'trade_proposals' => null
            'bank_account_mandates' => null
            'credit_card_mandates' => null
            'credit_requests' => null
            'invoice_delivery' => 1
            'invoices' => null
            'invoice_reference' => ''
            'jelastic_client' => null
            'blocks' => null
            'orders' => null
            'osa_login' => null
            'remarks' => null
            'zone_mutations' => null
            'removed' => false
            'private' => true
            'prospect' => false
            'kvk_number' => null
            'vat_number' => null
            'vat_number_status' => 0
            'legal_form' => null
            'created_at' => DateTime:000000002ea1f9cf000000000b229436 Object (
                'date' => '2018-02-13 08:36:21.141732'
                'timezone_type' => 3
                'timezone' => 'Europe/Amsterdam'
            )
            'updated_at' => DateTime:000000002ea1f9ce000000000b229436 Object (
                'date' => '2018-02-13 08:36:21.141734'
                'timezone_type' => 3
                'timezone' => 'Europe/Amsterdam'
            )
            'updated_by' => null
            'is_reseller' => false
            'invoicing_day' => null
            'general_contact_person' => null
            'technical_contact_person' => null
            'financial_contact_person' => null
        )
        'terminations' => Doctrine\Common\Collections\ArrayCollection:000000002ea1f9e3000000000b229436 Object (
            'elements' => Array &4 ()
        )
        'mutations' => Doctrine\Common\Collections\ArrayCollection:000000002ea1f9c0000000000b229436 Object (
            'elements' => Array &5 ()
        )
        'debit_balance_mutation_lines' => null
        'resources' => null
        'invoice_lines' => null
        'remarks' => null
        'identifier' => 'henk.nl'
        'parent_contract' => null
        'child_contracts' => null
        'product' => Hostnet\Product\Entity\Product:000000002ea1f9cd000000000b229436 Object (
            'id' => null
            'duration' => Hostnet\Product\Entity\Period:000000002ea081a1000000000b229436 Object (
                'id' => 868
                'culture' => Hostnet\Component\DoctrineExtension\Mapping\DefaultCulture:000000002ea081a3000000000b229436 Object (
                    'locale' => 'nl'
                )
                'deprecated_evil_months' => 12
                'one_time' => false
                'i18ns' => Doctrine\Common\Collections\ArrayCollection:000000002ea081a2000000000b229436 Object (
                    'elements' => Array &6 (
                        'nl' => Hostnet\Product\Entity\PeriodI18n:000000002ea081a0000000000b229436 Object (
                            'culture' => 'nl'
                            'period' => Hostnet\Product\Entity\Period:000000002ea081a1000000000b229436 Object
                            'name' => '12 months'
                            'description' => '12 months'
                            'short_description' => '12 months'
                        )
                    )
                )
            )
            'invoicing_period' => Hostnet\Product\Entity\Period:000000002ea08082000000000b229436 Object (
                'id' => 1091
                'culture' => Hostnet\Component\DoctrineExtension\Mapping\DefaultCulture:000000002ea08083000000000b229436 Object (
                    'locale' => 'nl'
                )
                'deprecated_evil_months' => 6
                'one_time' => false
                'i18ns' => Doctrine\Common\Collections\ArrayCollection:000000002ea08085000000000b229436 Object (
                    'elements' => Array &7 (
                        'nl' => Hostnet\Product\Entity\PeriodI18n:000000002ea08086000000000b229436 Object (
                            'culture' => 'nl'
                            'period' => Hostnet\Product\Entity\Period:000000002ea08082000000000b229436 Object
                            'name' => '6 months'
                            'description' => '6 months'
                            'short_description' => '6 months'
                        )
                    )
                )
            )
            'termination_period' => Hostnet\Product\Entity\Period:000000002ea0819f000000000b229436 Object (
                'id' => 3410
                'culture' => Hostnet\Component\DoctrineExtension\Mapping\DefaultCulture:000000002ea0819e000000000b229436 Object (
                    'locale' => 'nl'
                )
                'deprecated_evil_months' => 1
                'one_time' => false
                'i18ns' => Doctrine\Common\Collections\ArrayCollection:000000002ea08080000000000b229436 Object (
                    'elements' => Array &8 (
                        'nl' => Hostnet\Product\Entity\PeriodI18n:000000002ea08084000000000b229436 Object (
                            'culture' => 'nl'
                            'period' => Hostnet\Product\Entity\Period:000000002ea0819f000000000b229436 Object
                            'name' => '1 month'
                            'description' => '1 month'
                            'short_description' => '1 month'
                        )
                    )
                )
            )
            'display_period' => Hostnet\Product\Entity\Period:000000002ea0819f000000000b229436 Object
            'product_labels' => Doctrine\Common\Collections\ArrayCollection:000000002ea1f9c8000000000b229436 Object (
                'elements' => Array &9 ()
            )
            'price' => Hostnet\Product\Entity\Price:000000002ea081a7000000000b229436 Object (
                'id' => 1313
                'periodical_amount' => '30.0000'
                'initial_amount' => '0.00'
                'created_at' => DateTime:000000002ea081a4000000000b229436 Object (
                    'date' => '2018-02-13 08:36:12.806438'
                    'timezone_type' => 3
                    'timezone' => 'Europe/Amsterdam'
                )
            )
            'name' => 'VPS 1GB'
            'description' => 'VPS 1GB'
            'start_date' => DateTime:000000002ea1f9ca000000000b229436 Object (
                'date' => '2018-02-13 08:36:21.141768'
                'timezone_type' => 3
                'timezone' => 'Europe/Amsterdam'
            )
            'end_date' => null
            'system_name' => 'VPS-1GB-1MND'
            'visiblility_deprecated' => false
            'attributes' => Doctrine\Common\Collections\ArrayCollection:000000002ea1f9c9000000000b229436 Object (
                'elements' => Array &10 (
                    0 => Hostnet\Product\Entity\Attribute:000000002ea1f9c5000000000b229436 Object (
                        'id' => null
                        'product' => Hostnet\Product\Entity\Product:000000002ea1f9cd000000000b229436 Object
                        'attribute_type' => Hostnet\Product\Entity\AttributeType:000000002ea1f9c4000000000b229436 Object (
                            'id' => null
                            'system_name' => 'ACCOUNT_TYPE'
                            'deprecated_boolean_value' => false
                            'category' => 1
                            'name' => null
                            'attributes' => Doctrine\Common\Collections\ArrayCollection:000000002ea1f9c3000000000b229436 Object (
                                'elements' => Array &11 ()
                            )
                        )
                        'value' => 'unmanaged'
                        'is_visible' => false
                        'sequence' => 0
                        'created_at' => DateTime:000000002ea1f9c2000000000b229436 Object (
                            'date' => '2018-02-13 08:36:21.141776'
                            'timezone_type' => 3
                            'timezone' => 'Europe/Amsterdam'
                        )
                        'updated_at' => null
                    )
                )
            )
            'provider' => Hostnet\Product\Entity\Provider:000000002ea0897e000000000b229436 Object (
                'id' => 726
                'name' => 'Openstack'
                'max_simultaneous_processes' => null
            )
            'resulting_contract_type' => null
            'created_at' => DateTime:000000002ea1f9c7000000000b229436 Object (
                'date' => '2018-02-13 08:36:21.141769'
                'timezone_type' => 3
                'timezone' => 'Europe/Amsterdam'
            )
            'updated_at' => DateTime:000000002ea1f9c6000000000b229436 Object (
                'date' => '2018-02-13 08:36:21.141771'
                'timezone_type' => 3
                'timezone' => 'Europe/Amsterdam'
            )
            'updated_by' => null
            'front_category' => 0
            'front_sub_category' => 0
            'discount' => null
        )
        'status' => 2
        'renewal_status' => 1
        'start_date' => DateTime:000000002ea1f9cb000000000b229436 Object (
            'date' => '2018-02-13 08:36:21.141786'
            'timezone_type' => 3
            'timezone' => 'Europe/Amsterdam'
        )
        'end_date' => DateTime:000000002ea1f9d9000000000b229436 Object (
            'date' => '2019-02-13 00:00:00.000000'
            'timezone_type' => 3
            'timezone' => 'Europe/Amsterdam'
        )
        'termination_date' => null
        'deletion_date' => null
        'manually_disabled' => false
        'disabled_at' => null
        'invoiced_until' => null
        'next_invoice_at' => DateTime:000000002ea1f9dd000000000b229436 Object (
            'date' => '2018-02-13 08:36:21.141803'
            'timezone_type' => 3
            'timezone' => 'Europe/Amsterdam'
        )
        'initial_discount' => true
        'ticket_hours' => 0
        'being_invoiced' => true
        'domain_name_parked' => false
        'created_at' => DateTime:000000002ea1f9cc000000000b229436 Object (
            'date' => '2018-02-13 08:36:21.141787'
            'timezone_type' => 3
            'timezone' => 'Europe/Amsterdam'
        )
        'updated_by' => null
        'updated_at' => null
        'discount' => Hostnet\Contract\Entity\ContractDiscount:000000002ea1f9c1000000000b229436 Object (
            'description' => ''
            'periodical_percentage' => 0
            'periodical_amount' => '0.0000'
            'initial_amount' => '0.0000'
        )
        'subscription_id' => 13
        'login_name' => ''
        'plesk_password' => ''
        'server_id' => null
    )
    'mailbox' => 'henk'
))
on Double\ActionLogProcessorInterface\P4850 was not expected, expected calls were:
  - process(type(Hostnet\App\Component\ActionLog\Forward\MailboxDeletedActionLog))

/home/ivanderberg/projects/mijn/www/src/App/Form/Contract/Handler/EmailDeleteHandlerType.php:89
/home/ivanderberg/projects/mijn/www/tests/App/Form/Contract/Handler/EmailDeleteHandlerTypeTest.php:80

My expectation:

$this->action_log_processor
    ->process(Argument::type(MailboxDeletedActionLog::class))
    ->shouldBeCalled();

I it took me a good 5 minutes to find out what was wrong here, with lots and lots of scrolling in my Terminal. I do not care for the contents of the arguments, like really, it's nearly useless (at least in this scenario. My matcher is a type match and it didn't match, I had the wrong import.

I believe it would be a lot more useful for this to display the differences between types:

Prophecy\Exception\Call\UnexpectedCallException: Method call:
  - process(type(Hostnet\App\Component\ActionLog\Hosting\MailboxDeletedActionLog))
on Double\ActionLogProcessorInterface\P4850 was not expected, expected calls were:
  - process(type(Hostnet\App\Component\ActionLog\Forward\MailboxDeletedActionLog))

Maybe it could even show a diff underneath it:

Failed expectation diff:
- Hostnet\App\Component\ActionLog\Hosting\MailboxDeletedActionLog
+ Hostnet\App\Component\ActionLog\Forward\MailboxDeletedActionLog

In case of actual argument matching, I'm still not interested in the object contents. Let's say I have 2 different objects of the same type, it should be sufficient to show that the hashes do not match (or if loosely checked, which properties). I can manually debug the values if needed and dump stuff.

[sstok]

Actually I find this to be really helpful :) but I agree this is very verbose 🤔 maybe the diff could be limited to what actually is different (when the object types match).

PHPUnit assertions are really readable when using PHPStorm because I can open a visual diff 😋 maybe this is an option also.

[jon-acker]

Part of the problem lies with prophecy itself, e.g. the classname that it reports is the name of the double rather than the original class: Double\ActionLogProcessorInterface\P4850 <- prophecy could theoretically figure out the name of the original class from this and pass it along with the rest of the error payload. There's an open issue relating to this: https://github.com/phpspec/prophecy/issues/154

The readability, as is with the case with PhpSpec, is down to PHPUnit. The error thrown by Prophecy contains this whole diff that you see above but the test framework (PHPUnit or Spec) can choose what to show from this. I commented a while ago on PhpSpecs repo about this: https://github.com/phpspec/phpspec/issues/1121.

[dbalabka]

I'm using Prophecy with PHPStorm and experiencing a similar problem with argument assertion. It would be very useful to get assertions diffs with PHPStorm support.

As a workaround, I did the following assertion using PHPUnit method:

$double->someMethod(Argument::that(function ($value) use ($expectedValue) {
    $this->assertEquals($expectedValue, $value);
}))

with such approach I'm getting PHPStorm diffs support as well:

[stof]

@dbalabka your workaround makes it impossible to configure multiple calls on the double though, because your callable does not respect the signature of the argument matcher (you throw an exception when it does not match instead of returning false)

[stof]

The hard thing about doing this output are that multiple calls can be allowed (with different kinds of matchers) and that the matchers are an extension point so formatters might not know about them to provide a shorter output.