OXID eFire Extension PayPal // IPN-Problem

Hallo zusammen,

wir haben schon länger das von Oxid zur Verfügung gestelle PayPal-Modul in Verwendung. Bisher auch ohne Probleme, Zahlungen laufen durch, Refunds funktionieren, …

Im Zusammenhang mit einer Zahlung, die seitens PayPal nicht direkt freigegeben wurde, ist uns nun aber etwas aufgefallen. Gezeigt hat sich das daran, dass PayPal die besagte Bestellung nach einigen Tagen zwar ausgeführt, Oxid aber nichts davon mitbekommen hat.

In den Modul-Logs unter /modules/oe/oepaypal/logs/ wird für jede Transaktion ein Fehler ausgegeben.

Hier mal ein Beispiel einer IPN von PayPal (anonymisiert):

======================= IPN VERIFICATION FAILURE BY PAYPAL [2015-04-15 12:49:37] ======================= #

SESS ID: d3fa98f14b3dc8e003cd7b94b329c57a
array (
  'Shop owner' => '[email protected]',
  'PayPal ID' => '[email protected]',
  'PayPal ACK' => 'NOT VERIFIED',
  'PayPal Full Request' => 'Array
(
    [handling_amount] => 0.00
    [discount] => 0.00
    [insurance_amount] => 0.00
    [payer_id] => SBLMJWYB5D34T
    [address_country_code] => DE
    [ipn_track_id] => 01dca3d5e374
    [address_zip] => 12345
    [shipping] => 0.00
    [charset] => windows-1252
    [payment_gross] => 
    [address_status] => confirmed
    [shipping_discount] => 0.00
    [address_street] => Test Straße 167
    [echeck_time_processed] => 18:25:45 Apr 13, 2015 PDT
    [verify_sign] => bYYYRAFcWxV21C7fd0v3CpSSRl31AueG4IYoZYgfH6eK3gZKroBVi92V
    [item_name] => Bestellnummer 2015000123
    [txn_type] => express_checkout
    [receiver_id] => WW9VA8C8JPQKK
    [payment_fee] => 
    [mc_currency] => EUR
    [transaction_subject] => 
    [shipping_method] => Default
    [custom] => Bestellnummer 2015000123
    [protection_eligibility] => Eligible
    [address_country] => Germany
    [payer_status] => verified
    [first_name] => Hubert
    [address_name] => Hubert Müller
    [mc_gross] => 709.70
    [payment_date] => 01:12:43 Apr 06, 2015 PDT
    [payment_status] => Completed
    [quantity] => 1
    [business] => [email protected]
    [item_number] => 
    [last_name] => Müller
    [address_state] => 
    [txn_id] => 00CD39762977G6135
    [mc_fee] => 13.83
    [resend] => true
    [payment_type] => echeck
    [notify_version] => 3.8
    [payer_email] => [email protected]
    [receiver_email] => [email protected]
    [address_city] => Teststadt
    [tax] => 0.00
    [residence_country] => DE
)
',
  'PayPal Full Response' => 'Array
(
    [<HTML><HEAD>
<TITLE>Service_Unavailable</TITLE>
</HEAD><BODY>
<H1>Service_Unavailable_-_DNS_failure</H1>
The_server_is_temporarily_unable_to_service_your_request___Please_try_again
later_<P>
Reference] => 
    [#32;] => 
    [#35;11] => 
    [#46;73959d50] => 
    [#46;1429094977] => 
    [#46;fe60210
</BODY></HTML>
] => 
)
',
)

Die Fehlermeldung ist dabei immer die selbe („IPN VERIFICATION FAILURE BY PAYPAL“) und im Bereich „PayPal Full Response“ taucht auch immer das selbe auf („Service_Unavailable_-_DNS_failure“).

Wir haben nun verschiedene Dinge überprüft/angepasst:
[ul]
[li]IPN im PayPal Backend aktiviert
[/li][li]Überprüft, ob der Server die APIs von PayPal erreichen kann (traceroute, wget, nslookup, ping …)
[/li][li]Diverse IPNs manuell noch mal aus dem PayPal-Backend versendet
[/li][li]Ds Encoding für Nachrichten seitens PayPal auf UTF-8 gesetzt
[/li][/ul]

Alles leider ohne das Problem damit zu lösen noch einen Hinweis darauf zu finden.

Tauchen diese Fehlermeldungen/das Verhalten auch bei anderen Installationen auf?
Hat jemand vielleicht eine Idee, wo und wie man hier am besten debuggen könnte?

Besten Dank und
-gruß

Habe in einem Projekt die gleiche Fehlermeldung. Da der Shop aber bisher noch nicht unter https läuft, hatte ich es darauf geschoben. Ist denn bei Dir eine https Adresse angegeben?
Findest Du weiter oben in der Log-Datei:

‘PAYMENTREQUEST_0_NOTIFYURL’ => ‘Domain.de - Seite nicht gefunden’,

Ahoj,

danke für Deine Antwort.

Die von dir angemerkte Zeile habe ich in meiner - doch schon recht großen - Logdatei nicht finden können.

Ich habe aber mal im PayPal-Backend ein paar IPNs im Detail angesehen und dort ist unter dem Punkt „Benachrichtigungs-URL“ immer eine HTTPS-Adresse angegeben. Daran liegt es also vermutlich/leider nicht.

So wie ich das Verstehe schickt

  1. PayPal eine IPN an OXID
  2. OXID prüft dann - wie auch immer - noch einmal gegen, ob die IPN tatsächlich von PayPal kam
  3. Abhängig von der daraus resultierenden Antwort wird dann der Inhalt der IPN von OXID verarbeitet, oder eben nicht

Für mich sieht es nun so aus, als würde bei Schritt 2 (also „Rückfrage bei PayPal“) ein Fehler auftreten … so als würde der PayPal-Server antworten „The_server_is_temporarily_unable_to_service_your_request___Please_try_again
later_“

Danke und -grüße

Die Meldungen tauchen bei mir auch im Log auf, allerdings laufen die dazugehörigen Transaktionen trotzdem fehlerfrei durch.
Ich habe aber keine Ahnung, was an der Stelle genau passiert. Ich tippe auf ein temporäres Kommunikationsproblem - möglicherweise kommt die Antwort nur zu spät und eine später eintreffende erfolgreiche Antwort wird nicht protokolliert.

Gleiches Problem hier.

[QUOTE=wolkenkrieger;158478]Gleiches Problem hier.[/QUOTE]

Hi,

Danke für’s Feedback!

Laufen denn bei dir alle Transaktionen/IPNs zur Zufriedenheit durch, oder wird - wie bei uns - die ein oder andere IPN von OXID ignoriert?

Danke und
-gruß

Zur Info:
IPN wird nur gebraucht bei Zahlungen des Kunden vom PayPal-Konto, die nicht direkt gedeckt sind!
Bei allen anderen Transaktionen wird über die Methode DoExpressCheckoutPayment der Status im Shop auf ‘bezahlt’ gesetzt (PayPal meldet ‘success’).
Nur bei 1 bis 3% der Transaktionen meldet PayPal ‘pending’ (zB über Bankeinzug). Nur dann kommt IPN zum Zug!

Nehme an, dass bei allen Transaktionen die im Beitrag #1 beschriebene Fehlermeldung kommt, aber bei 97 bis 99% sowieso schon die Bestellung als ‘bezahlt’ markiert ist!

Hoi patchwork :slight_smile:

Genau der Fall, das die Zahlung nicht instant ist, funktioniert bei mir eben nicht - Oxid meldet zwar “ausstehend” (oder was auch immer da dann genau steht - hab’s nicht im Kopf) aber gibt keinerlei Rückmeldung, wenn die Zahlung dann doch durchgeführt wurde (ich bekomme ja die Mail von Paypal wegen eines erfolgten Zahlungseinganges - also isses nicht wirklich ein Problem … nur aufwändiger^^). Die Meldungen bezüglich des DNS-Problems habe ich bei jeder Transaktion im Log … und mich deswegen nie wirklich darum gekümmert (in der Annahme, dass das ein generelles Problem von PP ist).

@bub

Deine Frage dürfte damit beantwortet sein: Transaktionen laufen trotz Fehlermeldung sauber durch. Nur eben die nachträgliche Zahlungsbenachrichtigung - wofür nach meinem Verständnis ja das IPN eigentlich gedacht ist - funktioniert nicht…

[QUOTE=wolkenkrieger;158503]Hoi patchwork :slight_smile:
Deine Frage dürfte damit beantwortet sein: Transaktionen laufen trotz Fehlermeldung sauber durch. Nur eben die nachträgliche Zahlungsbenachrichtigung - wofür nach meinem Verständnis ja das IPN eigentlich gedacht ist - funktioniert nicht…[/QUOTE]

Danke, das ist dann ja genau das von uns beobachtete Verhalten!
Habe das mal so an den OXID-Support weitergegeben.

-grüße

Scheint also ein Bug in PayPal-Modul zu sein!
habs mal in Bug-tracker eingetragen:
https://bugs.oxid-esales.com/view.php?id=6122

Habt ihr schon mal drauf geachtet, ob die [receiver_email] immer der des Shop-Owners entspricht?

Von wann sind denn diese Einträge? Tauchen die Einträge zufällig nur in dem Zeitraum 12. - 15. April auf? Gibt es in den letzten 24 Stunden noch Einträge? Und haben alle Einträge eine Tracking-ID wie 11.73959d50.1429094977.fe60210 (zu sehen zerhackt in der ‘PayPal Full Response’)? Wenn diese Einträge auch in den letzten 24 Stunden aufgetreten sind, könnt Ihr aktuelle Beispiel-IDs aufschreiben? Nach 24 Stunden werden diese nämlich verworfen.

Beachtet bitte, dass das nicht exakt dieselbe ID ist. Und der Parser zerhackt das ein wenig im Log. Diese ID aus meinem Beispiellog sieht z.B. so aus:

Reference] =>
[#32;] =>
[#35;11] =>
[#46;73959d50] =>
[#46;1429094977] =>
[#46;fe60210

diese ID finde ich in alten Log-Einträgen (ältester Eintrag: Dez. 2014)
der letzte Eintrag ist vom 15.04.2015 (dieser Shop läuft nicht produktiv / nur zum testen - deshalb ist das Datum nicht relevant). Bei diesem Eintrag gibt es jedoch eine andere ID:

======================= IPN VERIFICATION FAILURE BY PAYPAL [2015-04-15 22:43:54] ======================= #

SESS ID: caol012nsaersrofv75588rks6
array (
‘Shop owner’ => ‘[email protected]’,
‘PayPal ID’ => ‘’,
‘PayPal ACK’ => ‘NOT VERIFIED’,
‘PayPal Full Request’ => 'Array
(
)
',
‘PayPal Full Response’ => 'Array
(
[<HTML><HEAD>
<TITLE>Service_Unavailable</TITLE>
</HEAD><BODY>
<H1>Service_Unavailable_-DNS_failure</H1>
The_server_is_temporarily_unable_to_service_your_request___Please_try_again
later
<P>
Reference] =>
[#32;] =>
[#35;11] =>
[#46;e60b0ac3] =>
[#46;1429130634] =>
[#46;2c9e717
</BODY></HTML>
] =>
)
',
)

benutz doch einfach das von uns das geht

[QUOTE=patchwork.de;158688](ältester Eintrag: Dez. 2014)[/QUOTE]
Es kann natürlich sein, dass es zu dem Zeitpunkt schon einmal Probleme mit dem CDN bei PayPal gab.

[QUOTE=patchwork.de;158688]
der letzte Eintrag ist vom 15.04.2015 [/QUOTE]
das würde ja dafür sprechen, dass es sich nur um ein vorübergehendes Problem im CDN handelte. Trat es danach nicht nochmal auf?

[QUOTE=patchwork.de;158688](dieser Shop läuft nicht produktiv / nur zum testen - deshalb ist das Datum nicht relevant). [/QUOTE]
Ich verstehe nicht ganz, warum es dann nicht relevant ist? Verwendest du dort nur die Sandbox oder meinst du, dass dort eh nur selten bis nie Bestellungen gemacht werden und das Datum somit keine Aussagekraft hat, ob es danach nochmal auftrat?

[QUOTE=patchwork.de;158688]
Bei diesem Eintrag gibt es jedoch eine andere ID:[/QUOTE]
die IDs sind immer anders, weil sie von Akamai je nach “Route” generiert werden.

Wie Hendrik schon sagte: Ohne aktuelle Fehlermeldungen wird es schwierig der Ursache auf den Grund zu gehen.

[QUOTE=aggrosoft;158690]benutz doch einfach das von uns das geht[/QUOTE]

die von uns erstellten gehen auch.
Aber in diesem Thema geht es ja um das Oxid PayPay-Modul und die Ursachenfindung. Wenn Du also etwas konkretes beitragen kannst: hier posten. Ansonsten halte Dich bitte mit Werbung zurück.

@martin.wegele
der letzte Eintag in der log.txt ist vom 23.04. (Shop-Daten geändert):

======================= IPN VERIFICATION FAILURE BY PAYPAL [2015-04-23 15:05:19] ======================= #

SESS ID: 49uj5avgrveoggnfcko3im2k93
array (
‘Shop owner’ => ‘[email protected]’,
‘PayPal ID’ => ‘[email protected]’,
‘PayPal ACK’ => ‘NOT VERIFIED’,
‘PayPal Full Request’ => 'Array
(
[Shipping_calculation_mode] => FlatRate
[mc_gross] => 26.67
[protection_eligibility] => Eligible
[address_status] => confirmed
[payer_id] => 2LL7VN2QJEYJN
[tax] => 0.00
[address_street] => Im test 4
[payment_date] => 06:05:03 Apr 23, 2015 PDT
[payment_status] => Completed
[charset] => windows-1252
[shipping_option_name] => Paketversand mit DPD innerhalb Europa (ohne deutsche Inseln)
[address_zip] => 53639
[first_name] => test
[mc_fee] => 0.86
[address_country_code] => DE
[address_name] => test
[notify_version] => 3.8
[custom] => Bestellnummer 11497
[insurance_option_selected] => 0
[payer_status] => verified
[business] => [email protected]
[address_country] => Germany
[shipping_option_amount] => 6.90
[address_city] => test
[quantity] => 1
[verify_sign] => AuRlNZvMOhdn8iDWY5YoMB9iRTDzA-uUjtTfztggPkp.Ivyl.LQFEyQw
[payer_email] => [email protected]
[txn_id] => 8JU75372XG0226317
[payment_type] => instant
[last_name] => Strasser
[address_state] =>
[receiver_email] => [email protected]
[payment_fee] =>
[insurance_amount] => 0.00
[receiver_id] => JRKMUYM8677AA
[txn_type] => express_checkout
[item_name] => Bestellnummer 11497
[mc_currency] => EUR
[item_number] =>
[residence_country] => DE
[handling_amount] => 0.00
[transaction_subject] =>
[payment_gross] =>
[shipping] => 6.90
[shipping_is_default] => 1
[ipn_track_id] => dc599fc31c4d1
)
',
‘PayPal Full Response’ => 'Array
(
[<HTML><HEAD>
<TITLE>Service_Unavailable</TITLE>
</HEAD><BODY>
<H1>Service_Unavailable_-DNS_failure</H1>
The_server_is_temporarily_unable_to_service_your_request___Please_try_again
later
<P>
Reference] =>
[#32;] =>
[#35;11] =>
[#46;6d959d50] =>
[#46;1429794319] =>
[#46;2b33378
</BODY></HTML>
] =>
)
',
)

Der Fehler tritt also auch nach dem 15.04.2015 auf!

Soweit ich das jetzt überblicke, habe ich seit Oktober 2014 (da ging der Shop online) diesen Fehler bei jeder Transaktion im Log stehen. Und genau deswegen habe ich bis dato das ganze abgehakt unter “das muss so”^^

Dass die nachträgliche Zahlungsbenachrichtigung nicht funktioniert, habe ich dieser Tage erst gemerkt, da ich diesen Fall auch tatsächlich erst ein einziges Mal hatte (alle anderen Transaktionen waren instant).

Das Problem besteht weiterhin und ist offensichtlich nicht auf ein temporäres Erreichbarkeitsproblem des Paypal-CDN zurückzuführen.

Das Logfile ist inzwischen relativ umfangreich und enthält Kundendaten.
Deshalb können wir es leider nicht hier oder im Bugtracker posten. Wenn gewünscht, können wir es aber gerne der Entwicklung direkt zur Verfügung stellen - bitte einfach melden!

Danke und
-gruß