[ic] Verisign, double, tripe charges, orders not going through
IC
Orko
interchange-users@interchange.redhat.com
Fri Feb 22 23:33:00 2002
Emailing Ron directly, asking a few questions about his problems and
filling him in on what I have been seeing on my own site, it is apparent
that the Interchange that I am running is having the same exact issues.
Here are my specs. Notice that I have the latest Perl and am running on
a RH7.1 machine with only one processor:
=====
SPECS
=====
- Linux version 2.4.9-12 (bhcompile@stripples.devel.redhat.com) (gcc
version 2.96 20000731 (Red Hat Linux 7.1 2.96-85)) #1 Tue Oct 30
18:33:49 EST 2001
- Perl v5.6.0 built for i386-linux
- Single CPU Pentium III 800
- Perl Compile Information - ( At the bottom of this post for who wants
to look at it )
- Interchange v4.8.3
- Catalog Name: secure
========
Problems
========
#1. (minor) sendmail fails every once in a while (I've had 3 instances
in ~3500 orders)
Logs
----
from <CATALOG_DIR>/error.log:
-------------------
secure /cgi-bin/cgiwrap/vsslcgi/lcgi-bin/secure/process.html Unable to
send mail using /usr/sbin/sendmail
> <copy of message that failed...>
-------------------
#2. (major) Verisign transactions are being reported for ~10% of my
transactions every day as having an "Unknown Status". The email is the
same email that Ron described, stating that they approved the
transactions, but did not receive an acknowledgement from our system
(the pfpro binary). They won't settle the transactions until we verify
that the order was actually processed for the customer (none of them
ever have been).
Logs:
----
I have not been able to capture much of anything but logs similar to the
icdebug logs that Ron has posted earlier in the thread. Here are his
again(as an example):
from icdebug log:
-------------------
Timed out transaction:
Vend::Payment:debug: signio query: {
'TRXTYPE' => 'S',
'TENDER' => 'C',
'AMT' => '22.69',
'ZIP' => 97520,
'STREET' => '500 A Road',
'SHIPTOZIP' => 97520,
'ACCT' => '4719xxxxxxxxxxxx',
'EXPDATE' => '0104',
'PWD' => 'xxx',
'PARTNER' => 'Verisign',
'VENDOR' => undef,
'ORIGID' => '01091921534730830',
'USER' => 'xxx'
}
Vend::Payment:debug: signio call: /usr/local/ic/lib/pfpro
payflow.verisign.com 443
"TRXTYPE=S&TENDER=C&AMT=22.69&ZIP=97520&STREET=500 A
Road&SHIPTOZIP=97520&ACCT=4719xxxxxxxxxxxx
&EXPDATE=0104&PWD=xxx&PARTNER=Verisign&VENDOR=&ORIGID=01091921534730830&
USER=xxx" 10 > /home/store/store/tmp/signio.01091921534730830
Vend::Payment:debug: signio decline=12 result: [no result string]
Vend::Payment:debug: signio decline=0 result: {
'ICSTATUS' => 'failed',
'MStatus' => 'failed',
'pop.status' => 'failed',
'pop.error-message' => 'Charge error: Reason: . Please call in your
order or try again.',
'MErrMsg' => 'Charge error: Reason: . Please call in your order or
try again.'
}
Complete transaction seconds later with same information:
Vend::Payment:debug: signio query: {
'TRXTYPE' => 'S',
'TENDER' => 'C',
'AMT' => '22.69',
'ZIP' => 97520,
'STREET' => '500 A Road',
'SHIPTOZIP' => 97520,
'ACCT' => '4719xxxxxxxxxxxx',
'EXPDATE' => '0104',
'PWD' => 'xxx',
'PARTNER' => 'Verisign',
'VENDOR' => undef,
'ORIGID' => '01091921534730830',
'USER' => 'xxx'
}
Vend::Payment:debug: signio call: /usr/local/ic/lib/pfpro
payflow.verisign.com 443
"TRXTYPE=S&TENDER=C&AMT=22.69&ZIP=97520&STREET=500 A
Road&SHIPTOZIP=97520&ACCT=4719xxxxxxxxxxxx
&EXPDATE=0104&PWD=xxx&PARTNER=Verisign&VENDOR=&ORIGID=01091921534730830&
USER=xxx" 10 > /home/store/store/tmp/signio.01091921534730830
Vend::Payment:debug: signio decline=0 result:
RESULT=0&PNREF=xxx&RESPMSG=Approved&AUTHCODE=018564&AVSADDR=N&AVSZIP=Y
Vend::Payment:debug: signio decline=0 result: {
'ICSTATUS' => 'success',
'MStatus' => 'success',
'pop.status' => 'success',
'pop.avs_code' => 'Y
',
'pop.avs_addr' => 'N',
'RESPMSG' => 'Approved',
'pop.order-id' => 'xxx',
'AVSADDR' => 'N',
'order-id' => 'VPNA03831778',
'pop.auth-code' => 'xxx',
'pop.avs_zip' => 'Y
',
'PNREF' => 'xxxx',
'AUTHCODE' => 'xxx',
'AVSZIP' => 'Y
',
'RESULT' => '0'
}
--------------------
I have been able to take it a little further and look at the contents of
the tmp/signio.<timestamp> files for Approved, Declined, and these weird
timeout transactions. For Approved and Declined transactions, the
content was the result string from Verisign. For the "Timed out"
transactions, there was a zero byte file (no content).
I included my Perl compile information at the bottom of this post
because I have a sneaky suspicion that this has to do with the way the
Perl was compiled. We always do a stock compile from source when it
comes to Perl, but I noticed something strange when I looked at the
output from Config::myconfig. Specifically, the kernel that was used at
compile time of Perl, if I'm reading this correctly, is not the same as
the kernel that is being used now.
>From /proc/version:
Linux version 2.4.9-12
>From Config::myconfig:
osname=linux, osvers=2.2.17-8smp, archname=i386-linux
Could this be the whole problem right there?? Is it that easy? Even if
this is not the cause of this, I'm going to recompile the Perl on this
machine anyways. It can't hurt. ;-)
Thank you for your time and input on this.
-- orko
And here is the full Config::myconfig output....
(if you're reading this and have not heard of this, check out
'perldoc <PERLLIB_DIR>/Config.pm')
=====================================================
PERL COMPILE INFO(using Config.pm):
=====================================================
Summary of my perl5 (revision 5.0 version 6 subversion 0) configuration:
Platform:
osname=linux, osvers=2.2.17-8smp, archname=i386-linux
uname='linux porky.devel.redhat.com 2.2.17-8smp #1 smp fri nov 17
16:12:17 est 2000 i686 unknown '
config_args='-des -Doptimize=-O2 -march=i386 -mcpu=i686 -Dcc=gcc
-Dcccdlflags=-fPIC -Dinstallprefix=/usr -Dprefix=/usr
-Darchname=i386-linux -Dd_dosuid -Dd_semctl_semun -Di_db -Di_ndbm
-Di_gdbm -Di_shadow -Di_syslog -Dman3ext=3pm -Uuselargefiles'
hint=recommended, useposix=true, d_sigaction=define
usethreads=undef use5005threads=undef useithreads=undef
usemultiplicity=undef
useperlio=undef d_sfio=undef uselargefiles=undef
use64bitint=undef use64bitall=undef uselongdouble=undef
usesocks=undef
Compiler:
cc='gcc', optimize='-O2 -march=i386 -mcpu=i686', gccversion=2.96
20000731 (Red Hat Linux 7.1 2.96-79)
cppflags='-fno-strict-aliasing'
ccflags ='-fno-strict-aliasing'
stdchar='char', d_stdstdio=define, usevfork=false
intsize=4, longsize=4, ptrsize=4, doublesize=8
d_longlong=define, longlongsize=8, d_longdbl=define, longdblsize=12
ivtype='long', ivsize=4, nvtype='double', nvsize=8, Off_t='off_t',
lseeksize=4
alignbytes=4, usemymalloc=n, prototype=define
Linker and Libraries:
ld='gcc', ldflags =' -L/usr/local/lib'
libpth=/usr/local/lib /lib /usr/lib
libs=-lnsl -ldl -lm -lc -lcrypt
libc=/lib/libc-2.2.2.so, so=so, useshrplib=false, libperl=libperl.a
Dynamic Linking:
dlsrc=dl_dlopen.xs, dlext=so, d_dlsymun=undef, ccdlflags='-rdynamic'
cccdlflags='-fPIC', lddlflags='-shared -L/usr/local/lib'
=========================================================
=========ORIGINAL MESSAGE===========
> From: interchange-users-admin@interchange.redhat.com
[mailto:interchange-
> users-admin@interchange.redhat.com] On Behalf Of mheins@redhat.com
>
> Quoting Ron Phipps (rphipps@reliant-solutions.com):
> > > [snip]
> > > Remember all bugs are not Interchange. 8-\ If you didn't know,
> > > thousands of bugs have been fixed in Perl and Linux in the last
two
> > > years.
> >
> > I know this :) And once again I apologize if you took my message as
an
> > attack on IC. You know that I'm very thankful for the software that
you
> > have provided and do not take it for granted. I got tied up in the
> > moment of finding a quick fix instead of looking at the situation
from
> > further away. Those things happen when a launch goes bad and sales
are
> > being lost ;)
> >
>
> I didn't see it as an attack -- but it is easy to lose site of how
much
> a system depends on all its parts. I was trying to bring that out, and
> trying to emphasize how much Interchange depends on its underlying
> platform. Did you mention a multi-CPU system? I am not sure. If you
have
> a multi-CPU system, then that applies 10 times over.
And I did lose site of the underlying system which IC relies on. We
actually are running on two cpus which definitely complicates matters
more.
> All that being said, I am certainly not asserting that there could
> not possibly be a problem with Interchange 4.8. I know better than
> that. I just think it is more likely to be the kernel or Perl.
I agree with your assessment and I appreciate the time you put into this
problem. I went looking for a 'whatsnew' for the newest Perl and while
searching I found this about the version we are using
"For the faint of heart, the previous version of Perl is the 5.005_03
release. Timid souls who are afraid to upgrade to the current release
might want this."
I guess it's time to upgrade :)
> After racking my brain, the only thing I can think of, is that
> Interchange 4.8.x does that 4.6 didn't that might conceivably affect
> this is to use the reset() function in Perl. There may have been some
> bugs with that function fixed in Perl 5.6.
By the way I did not see any messages in /var/log/messages so it seems
that these processes are dying quietly. After the upgrade to 5.6 we
will again try IC 4.8.x and verify if it was a perl issue or not, I can
then alert other people to the problem if they run into this situation.
> >
> > > The fact that the problem only appears at busy times means it can
> > > be anything, and that it is less likely to be Interchange than it
> > > is overall system.
> >
> > Point noted, we will be testing and deploying the new perl and will
then
> > readdress IC 4.8.x and see if the problem is tied to the old perl.
I
> > have watched the load averages and memory usage when the problem
occurs
> > and it is independent of how busy the site is.
> >
>
> [snip]
>
> > I hope you see my true intentions (to resolve the situation quickly)
and
> > look over my frustration which was expressed in my message.
> >
>
> Good luck. I understand the frustration, believe me. I still remember
> flaky problems from my days of bringing high-volume sites online.
Thanks, I get to relax a little bit today... I'm sure next week I'll
want to go at it again to get to the bottom of the problem.
Take it easy,
-Ron
-- orko