[ic] Verisign, double, tripe charges, orders not going through IC

Orko interchange-users@interchange.redhat.com
Sat Feb 23 17:50:02 2002


I agree that error checks and handling are *always* a good idea :-)  

In most of the IC site flow itself, I do have (I think) decent error
handling in place for weird cases.  Not that this totally relates, but
we used to do high volume banner advertisements (I was part of the Stats
team back then), so I know all about the "we'll give you garbage in, you
give us pretty stuff out" frustrations :)  Makes you really appreciate
input filters, data quality checks and error handling.  

Tweaking on the core code of IC however, I have tried to avoid if at all
possible.  I don't fully understand a lot of the Legacy code that is in
there, so don't feel too comfortable yet at making logic changes in the
Payment module.

This might be a good time to mention this fact:  

When I set up payflowpro on this server, I couldn't get the pfpro-file
binary to work running as the interchange user.  I was getting the
following error and couldn't get around it:

<Result>-100</Result><Message>Failed to open XML file</Message>

So I used the pfpro binary instead.  That means that instead of
payflowpro using an XML temp file for it's Verisign data, it is
accepting the data from STDIN from within the Vend::Payment::Signio
module.

Ron, I noticed in your example that you are also using the pfpro vs. the
pfpro-file binary.  Could there be a link here? hmmm.

I suppose that I could write in an error handling hook into the
Vend::Payment module.  I was hoping that the cause of the error could be
found, since usually when you find one bug there is more lurking behind
it.  The sendmail and payflowpro errors that we are seeing both seem to
be linked by a call to an external binary from within IC, only under
load, and from what Ron says, it did not happen with IC 4.7.x.  That
isn't saying, of course, that it is IC's problem.  It could be that
there is just an error case that only happens when X, Y, Z, and Q are
all in place, and the planets align just right. ;-)  Without full
insight to what is going on, though, we can't make the determination of
what is causing it final.

Crossing my fingers,

-- orko

On Sat, 2002-02-23 at 08:02, cfm@maine.com wrote:
> On Fri, Feb 22, 2002 at 08:32:08PM -0800, Orko wrote:
> > 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.
> 
> Whether or not that is a high failure rate is not really the issue.
> 
> **ASSUME** that failures in parts of your process will be a regular part
> of your operation.  Build in checks.  If confirmation mail is an issue
> you need 1) a way to resend it, 2) a way to know if it fails/succeeds,
> 3) a regular process for checking.  FWIW, 3 in 3500 is way less than what
> we see for bad addresses, but still, a failure to put the message into
> the queue is bad - if that is what it means.
> 
> **ASSUME** that many credit cards will need human verification for
> one reason or another.  That is why most of our merchants have gone
> back to batch processing.  If enough of them need an eyeball, there is
> no point in processing some online.  Better to make the batch part of
> their order process.  Batch, submit, force that one, oh - cancel that
> one, etc....
> 
> If you don't assume failures and build in regular ways to handle them
> you will die handling the exceptions.  :-)
> 
> cfm
> 
> 
> > 
> > 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
> > 
> > _______________________________________________
> > interchange-users mailing list
> > interchange-users@interchange.redhat.com
> > http://interchange.redhat.com/mailman/listinfo/interchange-users
> 
> -- 
> 
> Christopher F. Miller, Publisher                               cfm@maine.com
> MaineStreet Communications, Inc           208 Portland Road, Gray, ME  04039
> 1.207.657.5078                                         http://www.maine.com/
> Content/site management, online commerce, internet integration, Debian linux
> _______________________________________________
> interchange-users mailing list
> interchange-users@interchange.redhat.com
> http://interchange.redhat.com/mailman/listinfo/interchange-users
> 
> 
> 
> 
> 
> 
> 
-- 
Office: (360)697-1603
  Cell: (360)271-0796