Warum wird ein Wert in s_order_attributes immer wieder mit einem alten überschrieben?

Shopware 5 Programmierung
1

Ich habe ein Plugin erstellt, welches im table s_order_attributes einen Wert (zusätzliche Spalte my_modified_date) bei gewissen Änderungen updaten soll - eine modified timestamp sozusagen.

Nun es ist aber leider so, dass kurz nachdem ich die aktuelle Zeit über ein UPDATE statement setze, aufgrund irgendeines anderen Vorgangs wieder ein alter Wert hineingeschrieben wird. D.h. nach ein paar Millisekunden sieht der Datensatz wieder aus wie früher, und man bemerkt eigentlich gar nicht, dass mein Plugin kurz die aktuellere Zeit gesetzt hatte.

Im general Log von MySQL finde ich dazu solche Einträge:

SELECT alias.* FROM s_order_attributes alias WHERE alias.orderid = '123' LIMIT 1 OFFSET 0
UPDATE s_order_attributes alias SET alias.my_modified_date = '2016-12-15 15:09:25' WHERE alias.orderid = '123'

Meine Vermutung war, dass dies mit dem DataPersister zusammenhängt, aber ich kann es leider nicht nachvollziehen.

Kann jemand etwas mit den Log-Einträgen oben anfangen?

Kann ich irgendwelche zusätzlichen Informationen liefern, um jemanden in die Lage zu versetzen, mir hier weiterzuhelfen?

Warum bzw. wodurch wird hier wieder eine alte Zeit in den Datensatz geschrieben?

Besten Dank im Voraus!

 

2

naja, dann wäre es sicher mal nicht schlecht, wenn du sagst, wann du wie diese query machst. ist es ein hook, before - after, welche funktion …

ich schätze mal, es handelt sich um die klasse sorders. für den rest habe ich gerade mal meine glaskugel nicht hier.

deine infos reichen dafür leider nicht aus, sollte dir eigentlich  auch klar sein, wenn du deine frage mal aus der sicht einer anderen person liest.

Gruß,

Alex

3

Das Event, zu welchem ich im Plugin subscribe, ist Shopware_Controllers_Backend_OrderState_Notify.

public static function getSubscribedEvents()
{
    return [
        'Shopware_Controllers_Backend_OrderState_Notify' => 'onChangedOrder'
    ];
}

In onChangedOrder habe ich bereits auf 3 verschiedenen Arten das Update durchgeführt, und jedes Mal sehe ich im SQL Log, dass das Update durchgeführt wird, aber kurze Zeit später wieder mit einem alten Wert überschrieben wird:

  1. mit dem dbal_connection QueryBuilder

  2. direkt mit dbal_connection

  3. mit shopware_attribute.data_persister

    public function onChangedOrder(\Enlight_Event_EventArgs $args)
    {
    $orderId = (int) $args->get(‘id’);

    // 1. Versuch
    $queryBuilder = $this->container->get(‘dbal_connection’)->createQueryBuilder();
    $queryBuilder
    ->update(‘s_order_attributes’, ‘a’)
    ->set(‘a.my_modified_date’, ‘:now’)
    ->where(‘a.orderID = :order_id’)
    ->setParameter(‘order_id’, $orderId)
    ->setParameter(‘now’, new \DateTime(), \Doctrine\DBAL\Types\Type::DATETIME);
    $result = $queryBuilder->execute();

    /* 2. Versuch
    $query = $this->container->get(‘dbal_connection’)
    ->prepare(‘UPDATE s_order_attributes SET my_modified_date = :now WHERE orderID = :order_id’);
    $query->bindValue(‘now’, new \DateTime(), \Doctrine\DBAL\Types\Type::DATETIME);
    $query->bindValue(‘order_id’, $orderId);
    $result = $query->execute();*/

    /* 3. Versuch
    $service = Shopware()->Container()->get(‘shopware_attribute.data_persister’);
    $service->persist(
    array(
    ‘my_modified_date’ => date(‘Y-m-d H:i:s’)
    ),
    ‘s_order_attributes’,
    $orderId
    );
    */
    }

Falls noch mehr Informationen benötigt werden, liefere ich sie gerne schnellstmöglich nach. Vielen Dank vorerst einmal!

4

Kannst Du zum MySQL Log noch mehr Einzelheiten geben? Steht Dein Update denn vor den beiden von Dir genannten Einträgen?

Ggf. hilft das hier Shopware models weiter

5

Ja, das gewollte Update, mit der aktuelleren Zeit, steht definitiv vor den beiden oben genannten Einträgen:

883 Query    UPDATE s_order_attributes alias SET alias.my_modified_date = ‚2016-12-15 16:49:51‘ WHERE alias.orderid = ‚123‘

734 Zeilen Logeinträge später kommen dann unmittelbar aufeinanderfolgend diese beiden Zeilen:

887 Query    SELECT alias.* FROM s_order_attributes alias WHERE alias.orderid = ‚123‘ LIMIT 1 OFFSET 0
887 Query    UPDATE s_order_attributes alias SET alias.my_modified_date = ‚2016-12-15 15:09:25‘ WHERE alias.orderid = ‚123‘

Ich hab alle Logeinträge, die mit 887 beginnen, herausgefiltert. Ich muss allerdings einige Zeilen hier weglassen, weil das Forum nur eine beschränkte Zeichenanzahl zulässt. Die vollständige Version habe ich auf pastebin hochgeladen. 

887 Connect	root@localhost on devshop
887 Query	SET @@session.sql_mode = ""
887 Query	SELECT name FROM s_core_plugins WHERE namespace LIKE "ShopwarePlugins" AND active = 1 AND installation_date IS NOT NULL
887 Query	SELECT name, id, name, label, description, source, active, installation_date as installationDate, update_date as updateDate, versionFROM s_core_pluginsWHERE namespace='Core'
887 Query	SELECT ce.subscribe as name, ce.listener, ce.position, cp.name as plugin FROM s_core_subscribes ce JOIN s_core_plugins cp ON cp.id=ce.pluginID AND cp.active=1 AND cp.namespace='Core' WHERE ce.type=0 ORDER BY name, position
887 Query	SELECT name, id, name, label, description, source, active, installation_date as installationDate, update_date as updateDate, versionFROM s_core_pluginsWHERE namespace='Backend'
887 Query	SELECT ce.subscribe as name, ce.listener, ce.position, cp.name as plugin FROM s_core_subscribes ce JOIN s_core_plugins cp ON cp.id=ce.pluginID AND cp.active=1 AND cp.namespace='Backend' WHERE ce.type=0 ORDER BY name, position
887 Query	SELECT name, namespace, sourceFROM s_core_plugins
887 Query	SELECT t0.id AS id_1, t0.name AS name_2, t0.label AS label_3, t0.namespace AS namespace_4, t0.source AS source_5, t0.description AS description_6, t0.active AS active_7, t0.added AS added_8, t0.installation_date AS installation_date_9, t0.update_date AS update_date_10, t0.refresh_date AS refresh_date_11, t0.author AS author_12, t0.copyright AS copyright_13, t0.license AS license_14, t0.version AS version_15, t0.support AS support_16, t0.changes AS changes_17, t0.link AS link_18, t0.update_version AS update_version_19, t0.update_source AS update_source_20, t0.capability_update AS capability_update_21, t0.capability_install AS capability_install_22, t0.capability_enable AS capability_enable_23, t0.capability_secure_uninstall AS capability_secure_uninstall_24 FROM s_core_plugins t0 WHERE t0.id = '59' LIMIT 1
887 Query	SELECT module, host, license FROM s_core_licenses WHERE active=1
887 Query	SELECT host FROM s_core_shops WHERE `default`=1
887 Query	SELECT t0.id AS id_1, t0.name AS name_2, t0.label AS label_3, t0.namespace AS namespace_4, t0.source AS source_5, t0.description AS description_6, t0.active AS active_7, t0.added AS added_8, t0.installation_date AS installation_date_9, t0.update_date AS update_date_10, t0.refresh_date AS refresh_date_11, t0.author AS author_12, t0.copyright AS copyright_13, t0.license AS license_14, t0.version AS version_15, t0.support AS support_16, t0.changes AS changes_17, t0.link AS link_18, t0.update_version AS update_version_19, t0.update_source AS update_source_20, t0.capability_update AS capability_update_21, t0.capability_install AS capability_install_22, t0.capability_enable AS capability_enable_23, t0.capability_secure_uninstall AS capability_secure_uninstall_24 FROM s_core_plugins t0 WHERE t0.id = '73' LIMIT 1
887 Query	SELECT t0.id AS id_1, t0.table_name AS table_name_2, t0.column_name AS column_name_3, t0.column_type AS column_type_4, t0.default_value AS default_value_5, t0.entity AS entity_6, t0.label AS label_7, t0.help_text AS help_text_8, t0.support_text AS support_text_9, t0.translatable AS translatable_10, t0.display_in_backend AS display_in_backend_11, t0.custom AS custom_12, t0.position AS position_13, t0.array_store AS array_store_14 FROM s_attribute_configuration t0 WHERE t0.column_name = 'viisonCustomsTariffNumber' LIMIT 1
887 Query	SELECT ce.name, COALESCE(currentShop.value, parentShop.value, fallbackShop.value, ce.value) as value FROM s_core_plugins p INNER JOIN s_core_config_forms cf ON cf.plugin_id = p.id INNER JOIN s_core_config_elements ce ON ce.form_id = cf.id LEFT JOIN s_core_config_values currentShop ON currentShop.element_id = ce.id AND currentShop.shop_id = NULL LEFT JOIN s_core_config_values parentShop ON parentShop.element_id = ce.id AND parentShop.shop_id = '1' LEFT JOIN s_core_config_values fallbackShop ON fallbackShop.element_id = ce.id AND fallbackShop.shop_id = '1' WHERE p.name='ErrorHandler'
887 Query	SELECT `s_core_sessions_backend`.* FROM `s_core_sessions_backend` WHERE (((`s_core_sessions_backend`.`id` = '57d31blablablablabla81e4')))
887 Query	SELECT t0.id AS id_1, t0.name AS name_2, t0.pluginID AS pluginID_3 FROM s_core_acl_resources t0
887 Query	SELECT t0.id AS id_1, t0.parentID AS parentID_2, t0.name AS name_3, t0.description AS description_4, t0.source AS source_5, t0.enabled AS enabled_6, t0.admin AS admin_7, t0.parentID AS parentID_8 FROM s_core_auth_roles t0
887 Query	SELECT `s_core_auth`.* FROM `s_core_auth` WHERE (active=1) AND (lockeduntil <= NOW()) AND (`sessionID` = '57d31blablablablabla81e4')
887 Query	UPDATE `s_core_auth` SET `lastlogin` = '2016-12-15 16:49:53' WHERE (`username` = 'blaexampleuser')
887 Query	SELECT COLUMN_NAME AS Field, COLUMN_TYPE AS Type, IS_NULLABLE AS `Null`, COLUMN_KEY AS `Key`, COLUMN_DEFAULT AS `Default`, EXTRA AS Extra, COLUMN_COMMENT AS Comment, CHARACTER_SET_NAME AS CharacterSet, COLLATION_NAME AS Collation FROM information_schema.COLUMNS WHERE TABLE_SCHEMA = 'devshop' AND TABLE_NAME = 's_order_attributes'
887 Query	SELECT alias.* FROM s_order_attributes alias WHERE alias.orderid = '123' LIMIT 1 OFFSET 0
887 Query	UPDATE s_order_attributes alias SET alias.my_modified_date = '2016-12-15 15:09:25' WHERE alias.orderid = '123'
887 Query	SELECT `s_core_sessions_backend`.* FROM `s_core_sessions_backend` WHERE (((`s_core_sessions_backend`.`id` = '57d31blablablablabla81e4')))
887 Query	UPDATE `s_core_sessions_backend` SET `modified` = '1481816993', `data` = 'ShopwareBackend|a:2:{s:12:\"X-CSRF-Token\";s:30:\"qwvrblablablablabla9Xj\";s:13:\"sbp_available\";i:1;}Shopware|a:1:{s:4:\"Auth\";O:8:\"stdClass\":18:{s:2:\"id\";s:2:\"50\";s:6:\"roleID\";s:1:\"1\";s:8:\"username\";s:6:\"blaexampleuser\";s:8:\"password\";s:60:\"$2b$la$AAblablablaYJf/blablablablabla/v2PZxblablablablabla0W\";s:7:\"encoder\";s:6:\"bcrypt\";s:6:\"apiKey\";N;s:8:\"localeID\";s:1:\"1\";s:9:\"sessionID\";s:32:\"d56ec1blablablablablac3d6\";s:9:\"lastlogin\";s:19:\"2016-12-15 13:38:12\";s:4:\"name\";s:5:\"Admin\";s:5:\"email\";s:20:\"shop@exampleblabla.com\";s:6:\"active\";s:1:\"1\";s:12:\"failedlogins\";s:1:\"0\";s:11:\"lockeduntil\";s:19:\"0000-00-00 00:00:00\";s:15:\"extended_editor\";s:1:\"0\";s:14:\"disabled_cache\";s:1:\"0\";s:4:\"role\";O:25:\"Shopware\\Models\\User\\Role\":11:{s:29:\"\0Shopware\\Models\\User\\Role\0id\";i:1;s:35:\"\0Shopware\\Models\\User\\Role\0parentId\";N;s:31:\"\0Shopware\\Models\\User\\Role\0name\";s:12:\"local_admins\";s:38:\"\0Shopware\\Models\\User\\Role\0description\";s:53:\"Default group that gains access to all shop functions\";s:33:\"\0Shopware\\Models\\User\\Role\0source\";s:8:\"build-in\";s:34:\"\0Shopware\\Models\\User\\Role\0enabled\";i:1;s:32:\"\0Shopware\\Models\\User\\Role\0admin\";i:1;s:32:\"\0Shopware\\Models\\User\\Role\0users\";O:33:\"Doctrine\\ORM\\PersistentCollection\":2:{s:13:\"\0*\0collection\";O:43:\"Doctrine\\Common\\Collections\\ArrayCollection\":1:{s:53:\"\0Doctrine\\Common\\Collections\\ArrayCollection\0elements\";a:0:{}}s:14:\"\0*\0initialized\";b:0;}s:32:\"\0Shopware\\Models\\User\\Role\0rules\";O:33:\"Doctrine\\ORM\\PersistentCollection\":2:{s:13:\"\0*\0collection\";O:43:\"Doctrine\\Common\\Collections\\ArrayCollection\":1:{s:53:\"\0Doctrine\\Common\\Collections\\ArrayCollection\0elements\";a:0:{}}s:14:\"\0*\0initialized\";b:0;}s:35:\"\0Shopware\\Models\\User\\Role\0children\";O:33:\"Doctrine\\ORM\\PersistentCollection\":2:{s:13:\"\0*\0collection\";O:43:\"Doctrine\\Common\\Collections\\ArrayCollection\":1:{s:53:\"\0Doctrine\\Common\\Collections\\ArrayCollection\0elements\";a:0:{}}s:14:\"\0*\0initialized\";b:0;}s:33:\"\0Shopware\\Models\\User\\Role\0parent\";N;}s:6:\"locale\";O:27:\"Shopware\\Models\\Shop\\Locale\":4:{s:31:\"\0Shopware\\Models\\Shop\\Locale\0id\";i:1;s:35:\"\0Shopware\\Models\\Shop\\Locale\0locale\";s:5:\"de_DE\";s:37:\"\0Shopware\\Models\\Shop\\Locale\0language\";s:7:\"Deutsch\";s:38:\"\0Shopware\\Models\\Shop\\Locale\0territory\";s:11:\"Deutschland\";}}}', `expiry` = '7200' WHERE (`id` = '57d31blablablablabla81e4')
887 Quit

 

Danke für den Hinweis auf die Model-Events! Vielleicht ist das die richtige Spur. In diese Richtung werde ich als nächstes weiterschauen.

6

Ich habe es jetzt mit dem Model-Event postUpdate umgesetzt, aber so ganz sauber läuft es noch immer nicht. Falls mir jemand sagen kann, wo ich falsch liege, bzw. was der richtige Lösungsansatz ist, wäre ich sehr dankbar. Was ich erreichen möchte, kann wohl nicht so kompliziert sein: Bei jeder Änderung einer Order möchte ich den Modifizierungszeitpunkt speichern.

Momentan erreiche ich dieses Ziel mit folgendem 5.2 Plugin Code (welcher jedoch zu unbeabsichtigten Nebeneffekten führen könnte):

public static function getSubscribedEvents()
{
    return [
        'Shopware\Models\Order\Order::postUpdate' => 'onChangedOrder'
    ];
}

public function onChangedOrder(\Enlight_Event_EventArgs $args)
{
  $entityManager = $args->get('entityManager');
  $model = $args->get('entity');
  $orderId = (int) $model->getId();
  $orderAttributeModel = $entityManager->getRepository('Shopware\Models\Attribute\Order')->findOneBy(
      array('orderId' => $orderId)
  );
  $orderAttributeModel->setMyModifiedDate(date('Y-m-d H:i:s'));
  $entityManager->flush();
  $entityManager->getConnection()->commit();
}

Wenn ich die letzte Zeile weglasse ($entityManager->getConnection()->commit();), dann habe ich das gleiche Verhalten wie vorher: das UPDATE auf das neue Datum findet zwar statt, aber wird kurz danach wieder überschrieben.

Wenn diese Zeile präsent ist, dann bleibt das aktualisierte Datum bestehen und wird nicht mehr überschrieben. Um das Event _Shopware\Models\Order\Order::postUpdate _herbeizuführen, ändere ich den Status einer Bestellung im Backend, woraufhin rechts oben eine Fehlermeldung erscheint:

Fehler
Beim Speichern der Bestellung 20064 ist ein Fehler aufgetreten.
There is no active transaction.

Aufgrund dieser Fehlermeldung befürchte ich, dass es durch die obige Lösung zu Problemen an anderen Stellen kommen könnte, die mir bisher noch nicht aufgefallen sind.

Wie würdet ihr einen „modifed“-Zeitstempel für eine Bestellung einbauen? Ich habe in Zusammenhang mit Doctrine von der Extension Timestampable gelesen, aber mir scheint es nicht möglich zu sein, diese in Shopware zu integrieren. Oder wäre das ein gangbarer Weg?

7

Da ich genau das gleiche Problem hatte und lange nach einer Lösung gesucht habe, hier nun meine Lösung.

Es wird nach dem Abspeichern der Order noch einmal die AttributeData abgespeichert. Dies erfolgt nach erfolgreichen Abspeichern der Order, deshalb hats auch funktioniert, wenn der Fehler kam, der anschließende Ajax Request fürs speichern der AttributeData wurde dann nicht ausgeführt und hat das somit nicht überschrieben.

Für mich ist die Sinnhaftigkeit des erneuten Abspeicherns der Attribute nicht ganz nachvollziehbar, andere Infos werden ja auch direkt mit der Order abgespeichert.

 Um die Attribute vorm speichern zu ändern zB hier einhacken und modifizieren: 'Shopware\_Controllers\_Backend\_AttributeData::saveDataAction::before'