Possible bug - IPN item handling since 221028?

A new member tried to register on our site this morning. We use Paypal Standard buttons - they were directed to Paypal to complete their transaction but had an issue during the auto-return to our site.

Normally an email would be dispatched to the user following their Paypal payment, including a registration link. However in this case the user didn’t receive an email - this is confirmed by the user and also checking our GMail Sent Items as we use GMail SMTP.

We have both IPN and PDT settings configured in S2Member and have plenty of successful registrations to prove this has been working correctly. We had debug logs turned off as this is a live Production service. The IPN log on the Paypal Developer site shows that an IPN notification was successfully sent as part of this transaction.

Following the issue, we enabled debug logs and re-sent the IPN notification from the Paypal Developer console. The S2Member IPN logging shows the following summary for this retry:

[s2member_log] => Array
(
    [0] => IPN received on: Sat Oct 29, 2022 1:20:25 pm UTC
    [1] => s2Member POST vars verified through a POST back to PayPal.
    [2] => s2Member originating domain (`$_SERVER["HTTP_HOST"]`) validated.
    [3] => Ignoring this IPN request. The `txn_type/status` does NOT require any action on the part of s2Member.
)

This is interesting as it hasn’t discarded the notification as a duplicate, but instead determined it doesn’t require any action.

I then noticed that a recent plugin update had been applied since our last registration (successful) went through, so I had a look at the diff. This seems to include a change to $paypal[item_number] appending an additional colon before the conditional processing is applied to determine how to handle the notification. This can be confirmed in the logging output in the IPN logs, which now includes the following:

[txn_type] => web_accept
[item_number] => 2::6 M:

(note the trailing colon - the Paypal transaction has an item number of just 2::6 M)

Looking at the subsequent conditional code for handling these IPNs, this additional character appears to mean the item_number no longer matches any of the item_number regexes in syscon.inc.php

Happy to be proven/told this is incorrect and the issue lies elswhere, but as I’ve spent a couple of hours digging into this already I thought I’d share and see if any developers can comment. This issue is preventing us from signing up new users at the moment so keen to help find a resolution if it’s a general issue, or go back to the drawing board if it’s something specific to our installation.

Cheers.

1 Like

Hi clamb3r,

Great catch! I changed it, here’s the new zip file. Please install it and test the IPN again. See if it fixes it for you and tell me, please, so I make it public.

s2member-v221030.zip (1.4 MB)

The 221030 update helped because before that S2 did not do any automatic upgrades after Paypal Payments anymore. Now the payments are recognized by S2 again. But there is another issue with 221030 now: The membership duration of 1 month is only 1 day…

1 Like

Thanks for the update! I’ll look into that other one now! So weird…

:slight_smile:

Please do so. This currently “breaks” all payments causing a lot of trouble for sites with lots of payments and users get their EOT -1 email just after making payments… Endless pain since 221028…

If you have the core-ipn, core-rtn, and paypal-api log files, could I have a look? Wp Admin > s2Member > Log Files

You can message me to send me a zip with them, or a link to it… Click on my name and then the blue “message” button.

:slight_smile:

Sure. As an urgent fix: Is there a way to downgrade to the latest Framework and Pro before 221028?

I’m very sorry about the inconvenience…

Absolutely. You can find them here: https://s2member.com/release-archive/

Could you show me the button/pro-form shortcode you’re using? So I use the same details to reproduce it in my setup.

Thanks! :slight_smile:

[s2Member-Pro-PayPal-Form level="2" ccaps="books,magazines,gifts" desc="$15 USD / One Time (for 1 month access, non-recurring, no trial)" ps="paypal" lc="" cc="USD" dg="0" ns="1" custom="booksmagazinesgifts.com" ta="0" tp="0" tt="D" ra="15" rp="1" rt="M" rr="BN" rrt="" rra="2" accept="paypal,visa,mastercard,amex,discover,maestro,solo" accept_via_paypal="paypal" coupon="" accept_coupons="0" default_country_code="" captcha="0" /]
1 Like

Thank you!

Downgrading to 220925 both Framework and Pro solved the problem for me as a workaround. You should consider recalling the 221028 and 221030 update to spare your users the pain…

1 Like

Thanks for the update.

I’m trying to reproduce what you reported with 221030, using the details from your shortcode, and didn’t have that problem. The user was created, got access for one month, and the EOT time was set correctly for Nov 30th.

Could you send me the log files with the entries where you saw that happen so I can review them? Thanks!

with 221030 now: The membership duration of 1 month is only 1 day
users get their EOT -1 email just after making payments

The EOT -1 email would be because the user got 1 Day, so today was the day before already. But I’m still not sure how the 1 Day thing happened, couldn’t reproduce it yet. My tests are fine so far with v221030… Was that a new signup, or a resent IPN of a signup done with v221028?

I realized I did not have the logfiles on but I signed up various new test accounts with 221030 and paid for a 1 month membership via PayPal (real payment, no sandbox!) and the users had an EOT of Oct 31st 2022.

When I downgraded and went through the same exercise again (new user signup, payment through PayPal), the EOT was correct.

So it should not be the shortcode but something else…

And the EOT -1 Email was only sent out in version 221028, not in the ones I tried in 221030…

Thanks for the additional details.

Thanks for clarifying that.

Ah ok, got it.

Thanks for confirming the version for that behavior. It’s strange, I still can’t reproduce it. Been doing several tests since we started talking about this, and the EOT is set correctly for me. Would have loved to see your log files for those. If you feel like reproducing the behavior with logging enabled, please send me the logs.

And again, I’m really sorry about the inconvenience that caused you.

Hi

We’re running Version 221031 + s2Member Pro v220421 and can report a similar problem.
The renewing members appear to be demoted 5 to 10mins or so after paying (rather than 365 days) - examples below.

The last successful EOT set appears to be Fri Oct 27th, 2022

Successful payment at: 1 Nov 2022 12:29:04 GMT
Demoted by s2Member: Tue Nov 1, 2022 12:38 pm UTC
Paid Subscr. ID @ time of demotion: paypal → 20Y248*********

Transaction date
31 Oct 2022 21:54:22 GMT
Demoted by s2Member: Mon Oct 31, 2022 9:59 pm UTC
Paid Subscr. ID @ time of demotion: paypal → 6AS2***********

Hi P,

I see. I would like to have a look at your logs. If you haven’t yet, could you enable logging, and reproduce the behavior, so we get some entries to look at, please? WP Admin > s2Member > Log Files

Because I haven’t been able to reproduce that behavior in my tests, and I need to see what’s going on in your setup, please.

If you can show me also the shortcode you’re using. if you’re using the Paypal pro-form, could you tell me the kind of PayPal account you have?

Are these new signups, or existing user upgrades?

I look forward to the new details, to attempt reproducing it on my side.

:slight_smile:

Thanks for getting back so promptly Christian

I’ll need to clone the site and run some test transactions with the logs enabled - please bear with me.

Here is an example: [s2Member-PayPal-Button level=“2” ccaps="" desc="(Category L) Student Membership" ps=“paypal” lc="" cc=“GBP” dg=“0” ns=“1” custom=“ourdomain.uk.com” ta=“0” tp=“0” tt=“D” ra=“35.00” rp=“1” rt=“Y” rr=“BN” rrt="" rra=“1” image=“default” output=“button” /]

We’re using the Button Code Generator - not the Paypal pro-form.

And these are membership renewals.

Thanks for your help.