[interchange/gateway_log: 1/11] Vend::Payment::GatewayLog

Mark Johnson interchange-cvs at icdevgroup.org
Sat Nov 4 18:05:14 UTC 2017


commit c36681872e7333c15954b797c3990e8d51a952e5
Author: Mark Johnson <mark at endpoint.com>
Date:   Mon Sep 7 22:25:21 2009 -0400

    Vend::Payment::GatewayLog
    
    * New module facilitates adding logging support for all
      transactions through any of the standard gateway modules.
    
    * Introduce logging support to Vend::Payment::PayflowPro.
    
    * Fully sever database connections in Vend::Payment when
      global timeout is invoked. Code operating in production
      proved to behave unpredictably when parent and child shared
      the same database server.
    
    * Add gateway_log table to standard in expected format for each
      DBI database type.
    
    * Adjusted Vend::Table::DBI to support SQLite's AUTOINCREMENT
      in parallel to same support of MySQL's feature.

 dist/standard/dbconf/mysql/gateway_log.mysql |   16 ++
 dist/standard/dbconf/pgsql/gateway_log.pgsql |   11 +
 dist/standard/dbconf/sqlite/gateway_log.lite |   16 ++
 dist/standard/products/gateway_log.txt       |    1 +
 lib/Vend/Payment.pm                          |   47 +++--
 lib/Vend/Payment/GatewayLog.pm               |  296 ++++++++++++++++++++++++++
 lib/Vend/Payment/PayflowPro.pm               |  130 ++++++++++-
 lib/Vend/Table/DBI.pm                        |    7 +-
 8 files changed, 491 insertions(+), 33 deletions(-)
---
diff --git a/dist/standard/dbconf/mysql/gateway_log.mysql b/dist/standard/dbconf/mysql/gateway_log.mysql
new file mode 100644
index 0000000..e08f7e5
--- /dev/null
+++ b/dist/standard/dbconf/mysql/gateway_log.mysql
@@ -0,0 +1,16 @@
+Database  gateway_log  gateway_log.txt  __SQLDSN__
+
+Database  gateway_log  DEFAULT_TYPE   text not null default ''
+Database  gateway_log  AUTO_SEQUENCE  1
+Database  gateway_log  KEY            gateway_log_id
+Database  gateway_log  COLUMN_DEF     "order_md5=varchar(32) not null default ''"
+Database  gateway_log  COLUMN_DEF     "request_date=varchar(32) not null default ''"
+Database  gateway_log  COLUMN_DEF     "request_id=varchar(255) not null default ''"
+Database  gateway_log  COLUMN_DEF     "order_number=varchar(32) not null default ''"
+Database  gateway_log  COLUMN_DEF     "email=varchar(128) not null default ''"
+Database  gateway_log  INDEX          request_date
+Database  gateway_log  INDEX          request_id
+Database  gateway_log  INDEX          order_number
+Database  gateway_log  INDEX          email
+Database  gateway_log  INDEX          order_md5
+Database  gateway_log  NO_ASCII_INDEX 1
diff --git a/dist/standard/dbconf/pgsql/gateway_log.pgsql b/dist/standard/dbconf/pgsql/gateway_log.pgsql
new file mode 100644
index 0000000..3ca5f66
--- /dev/null
+++ b/dist/standard/dbconf/pgsql/gateway_log.pgsql
@@ -0,0 +1,11 @@
+Database  gateway_log  gateway_log.txt  __SQLDSN__
+
+Database  gateway_log  DEFAULT_TYPE   TEXT NOT NULL DEFAULT ''
+Database  gateway_log  AUTO_SEQUENCE  gateway_log_id_seq
+Database  gateway_log  KEY            gateway_log_id
+Database  gateway_log  COLUMN_DEF     "gateway_log_id=INTEGER PRIMARY KEY NOT NULL DEFAULT NEXTVAL('gateway_log_id_seq')"
+Database  gateway_log  INDEX          request_date
+Database  gateway_log  INDEX          request_id
+Database  gateway_log  INDEX          order_number
+Database  gateway_log  INDEX          email
+Database  gateway_log  NO_ASCII_INDEX 1
diff --git a/dist/standard/dbconf/sqlite/gateway_log.lite b/dist/standard/dbconf/sqlite/gateway_log.lite
new file mode 100644
index 0000000..e08f7e5
--- /dev/null
+++ b/dist/standard/dbconf/sqlite/gateway_log.lite
@@ -0,0 +1,16 @@
+Database  gateway_log  gateway_log.txt  __SQLDSN__
+
+Database  gateway_log  DEFAULT_TYPE   text not null default ''
+Database  gateway_log  AUTO_SEQUENCE  1
+Database  gateway_log  KEY            gateway_log_id
+Database  gateway_log  COLUMN_DEF     "order_md5=varchar(32) not null default ''"
+Database  gateway_log  COLUMN_DEF     "request_date=varchar(32) not null default ''"
+Database  gateway_log  COLUMN_DEF     "request_id=varchar(255) not null default ''"
+Database  gateway_log  COLUMN_DEF     "order_number=varchar(32) not null default ''"
+Database  gateway_log  COLUMN_DEF     "email=varchar(128) not null default ''"
+Database  gateway_log  INDEX          request_date
+Database  gateway_log  INDEX          request_id
+Database  gateway_log  INDEX          order_number
+Database  gateway_log  INDEX          email
+Database  gateway_log  INDEX          order_md5
+Database  gateway_log  NO_ASCII_INDEX 1
diff --git a/dist/standard/products/gateway_log.txt b/dist/standard/products/gateway_log.txt
new file mode 100644
index 0000000..ff58fba
--- /dev/null
+++ b/dist/standard/products/gateway_log.txt
@@ -0,0 +1 @@
+gateway_log_id	trans_type	processor	catalog	result_code	response_msg	request_id	order_number	email	session_id	request_source	request_date	request_duration	request	response
diff --git a/lib/Vend/Payment.pm b/lib/Vend/Payment.pm
index 9dd2642..61b2654 100644
--- a/lib/Vend/Payment.pm
+++ b/lib/Vend/Payment.pm
@@ -40,7 +40,7 @@ use Vend::Order;
 use IO::Pipe;
 use strict;
 
-use vars qw/$Have_LWP $Have_Net_SSLeay/;
+use vars qw/$Have_LWP $Have_Net_SSLeay $Global_Timeout/;
 
 my $pay_opt;
 
@@ -399,17 +399,24 @@ sub charge {
                 my $pipe = IO::Pipe->new;
 
                 unless ($pid = fork) {
-                    Vend::Server::child_process_dbi_prep();
+
                     $pipe->writer;
+
+                    Vend::Server::sever_database();
+                    local $SIG{USR2} = sub {
+                        $Global_Timeout = 'Global Timeout on gateway request';
+                        exit;
+                    };  
+
                     my %rv = $sub->($pay_opt);
+
                     $pipe->print( ::uneval(\%rv) );
                     exit;
-                }
+                }   
 
                 $pipe->reader;
 
-                my $to_msg = $pay_opt->{global_timeout_msg}
-                    || charge_param('global_timeout_msg')
+                my $to_msg = charge_param('global_timeout_msg')
                     || 'Due to technical difficulties, your order could not be processed.';
                 local $SIG{ALRM} = sub { die "$to_msg\n" };
 
@@ -422,24 +429,24 @@ sub charge {
                 my $rv = eval join ('', $pipe->getlines);
 
                 return %$rv;
-            }
+            }   
 
             return $sub->($pay_opt);
-        };
-
-		if($@) {
-			my $msg = errmsg(
-						"payment routine '%s' returned error: %s",
-						$charge_type,
-						$@,
-			);
-            kill (KILL => $pid)
+        };  
+
+        if($@) {
+            my $msg = errmsg(
+                        "payment routine '%s' returned error: %s",
+                        $charge_type,
+                        $@, 
+            );  
+            kill (USR2 => $pid)
                 if $pid && kill (0 => $pid);
-			::logError($msg);
-			$result{MStatus} = 'died';
-			$result{MErrMsg} = $msg;
-		}
-	}
+            ::logError($msg);
+            $result{MStatus} = 'died';
+            $result{MErrMsg} = $msg;
+        }   
+    }
 	elsif($charge_type =~ /^\s*custom\s+(\w+)(?:\s+(.*))?/si) {
 #::logDebug("Charge custom");
 		# MV4 and IC4.6.x methods
diff --git a/lib/Vend/Payment/GatewayLog.pm b/lib/Vend/Payment/GatewayLog.pm
new file mode 100644
index 0000000..f0bb49c
--- /dev/null
+++ b/lib/Vend/Payment/GatewayLog.pm
@@ -0,0 +1,296 @@
+package Vend::Payment::GatewayLog;
+
+use strict;
+use warnings;
+
+use Time::HiRes;
+
+sub new {
+    my ($class, $self) = @_;
+    $self = {} unless ref ($self) eq 'HASH';
+    $self->{_log_table} = $self->{LogTable} || 'gateway_log';
+    $self->{_enabled} = $self->{Enabled} || '';
+    $Vend::Payment::Global_Timeout = undef;
+    bless ($self, $class);
+}
+
+sub start {
+    my $self = shift;
+    return unless $self->_enabled;
+    my $override = shift;
+    $self->{__start} = Time::HiRes::clock_gettime()
+        if $override || !$self->{__start};
+    return $self->{__start};
+}
+
+sub stop {
+    my $self = shift;
+    return unless $self->_enabled;
+    my $override = shift;
+    $self->{__stop} = Time::HiRes::clock_gettime()
+        if $override || !$self->{__stop};
+    return $self->{__stop};
+}
+
+sub duration {
+    my $self = shift;
+    return unless $self->_enabled;
+    my $fmt = shift || '%0.3f';
+    return sprintf ($fmt, $self->stop - $self->start);
+}
+
+sub timestamp {
+    my $self = shift;
+    return unless $self->_enabled;
+    my $fmt = shift || '%Y-%m-%d %T';
+    return POSIX::strftime($fmt, localtime($self->start));
+}
+
+sub request {
+    my $self = shift;
+    return unless $self->_enabled;
+    my $request = shift;
+    return $self->{__request}
+        unless $request;
+    unless (ref ($request) eq 'HASH') {
+        ::logDebug(
+            'Skipping non-HASH request set: received %s (unevals to %s)',
+            $request,
+            ::uneval($request)
+        );
+        return;
+    }
+    $self->{__request} = { %$request };
+}
+
+sub response {
+    my $self = shift;
+    return unless $self->_enabled;
+    my $response = shift;
+    return $self->{__response}
+        unless $response;
+    unless (ref ($response) eq 'HASH') {
+        ::logDebug(
+            'Skipping non-HASH response set: received %s (unevals to %s)',
+            $response,
+            ::uneval($response)
+        );
+        return;
+    }
+    $self->{__response} = { %$response };
+}
+
+sub clean {
+    my $self = shift;
+    return unless $self->_enabled;
+    delete $self->{$_}
+        for grep { /^__/ } keys %$self;
+    return 1;
+}
+
+sub log_it {
+    die 'Must override log_it() in subclass';
+}
+
+sub table {
+    return shift()->{_log_table};
+}
+
+sub _enabled {
+    return shift()->{_enabled};
+}
+
+sub DESTROY {
+    my $self = shift;
+    return 1 unless $self->_enabled;
+    $self->log_it;
+    1;
+}
+
+1;
+
+__END__
+
+=head1 NAME
+
+Vend::Payment::GatewayLog - Basic package and methods for enabling full
+transaction logging in any of the gateways within the Vend::Payment::*
+namespace.
+
+=head1 VERSION
+
+1.00
+
+=head1 USAGE
+
+From within the normally unused namespace of the payment gateway:
+
+    package Vend::Payment::WhizBang;
+ 
+    use Vend::Payment::GatewayLog
+    use base qw/Vend::Payment::GatewayLog/;
+ 
+    sub log_it {
+        # Override log_it() with gateway-dependent mapping to a logging table,
+        # by default gateway_log
+    ...
+    }
+
+Then from inside the gateway sub itself:
+
+    ...
+    my $gwl =
+        Vend::Payment::WhizBang
+            -> new({
+                Enabled => charge_param('gwl_enabled'),
+            });
+ 
+    $gwl->request(\%scrubbed_request_hash);
+    $gwl->start;
+    ... Code that calls out to gateway's API ...
+    $gwl->stop;
+    ...
+    $gwl->response(\%response_hash);
+
+=head1 DESCRIPTION
+
+Module sets up an object with some utility methods to facilitate full database
+logging of all transaction attempts executed through the gateway. Often these
+data are either missing or insufficient for proper evaluation of problem events
+or general reporting.
+
+It's important to scrub all sensitive data appropriate for permanent storage.
+Minimally, this is recommended to include credit card numbers and CVV2 values,
+any senstitive gateway credentials (passwords or secret keys), or any personal
+data that can be used to exploit a customer's identity (SSN, date of birth,
+etc.).
+
+You do not want to call log_it() yourself. It is set up to execute
+automatically on destruction to help ensure that unexpected exits or aborts are
+still logged.
+
+=head2 Options
+
+Pass hashref to the constructor to include the following options:
+
+=over 4
+
+=item Enabled
+
+Boolean to indicate that actual logging should be performed. Default is false;
+thus logging must be explicitly requested. Route indicator should be
+"gwl_enabled" for consistency and so that global logging can be enabled by
+setting MV_PAYMENT_GWL_ENABLED in catalog.cfg.
+
+=item LogTable
+
+Name of table to which logging should be directed. Default is gateway_log.
+Route indicator should be "gwl_table" for consistency and so that a global
+target table can be set through MV_PAYMENT_GWL_TABLE in catalog.cfg.
+
+=back
+
+=head1 METHODS
+
+=over 4
+
+=item new()
+
+Constructor with optional hash ref indicating any of the above Options. Note
+that when Enabled, it will trigger a log write as soon as it goes out of scope,
+so consider when and where you want to call the constructor.
+
+=item start()
+
+Return, and optionally set, the Time::HiRes::clock_gettime() of the beginning
+of the call to the gateway's API. When called for the first time, it will set
+the value in the object and return said value; otherwise, it simply returns the
+previously set value. The set can be overridden by calling the method with a
+perly true arg.
+
+=item stop()
+
+Return, and optionally set, the Time::HiRes::clock_gettime() of the end of the
+call to the gateway's API. Same conditions apply as do for start()
+
+=item duration()
+
+Returns the delta of stop() - start(). Be aware that calling this method
+prior to calling either start() or stop() will cause the current time to
+be used for each and frozen.
+
+Default format is '%0.3f', but can be overriden passed as an arg.
+
+=item timestamp()
+
+Returns the timestamp of the value of start(). Again, calling this method
+prior to calling start() will cause the current time to be used and frozen.
+
+Default format is '%Y-%m-%d %T', but can be overriden passed as an arg.
+
+=item request()
+
+Freeze the hash request sent to the payment gateway if passed as an arg. Code
+will freeze a copy of the hash (though not a deep copy, if that impacts your
+particular gateway's request structure) so that any post-request processing on
+the original hash will not affect the stored request.
+
+Method only accepts a hash reference and will skip any other data structure
+that is attempted to be saved and logs the issue to the debug log, along with
+an ::uneval() of whatever was passed in.
+
+Calling with no args will only return the currently stored request hash
+reference.
+
+=item response()
+
+Freeze the hash response from the payment gateway if passed as an arg. Code
+will freeze a copy of the hash (though not a deep copy, if that impacts your
+particular gateway's response structure) so that any post-response processing
+on the original hash will not affect the stored response.
+
+Method only accepts a hash reference and will skip any other data structure
+that is attempted to be saved and logs the issue to the debug log, along with
+an ::uneval() of whatever was passed in.
+
+Calling with no args will only return the currently stored response hash
+reference.
+
+=item clean()
+
+Will purge all stored data from the object.
+
+=item log_it()
+
+Stub that must be overridden in the subclass. Invoking the object when
+log_it() has failed to be overridden will cause the code to die.
+
+=item table()
+
+Returns the name of the table against which the database update is to be
+performed. Default is 'gateway_log', but can be overridden in the constructor
+using the LogTable option.
+
+=back
+
+=head1 AUTHOR
+
+Mark Johnson (mark at endpoint.com), End Point Corp.
+
+=head1 LICENSE AND COPYRIGHT
+
+Copyright (C) 2009 Interchange Development Group and others
+
+This program is free software; you can redistribute it and/or modify it under
+the terms of the GNU General Public License as published by the Free Software
+Foundation; either version 2 of the License, or (at your option) any later
+version.
+
+This program is distributed in the hope that it will be useful, but WITHOUT ANY
+WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS FOR A
+PARTICULAR PURPOSE.  See the GNU General Public License for more details.
+
+You should have received a copy of the GNU General Public License along with
+this program; if not, see: http://www.gnu.org/licenses/
+
+=cut
diff --git a/lib/Vend/Payment/PayflowPro.pm b/lib/Vend/Payment/PayflowPro.pm
index 6f5ff16..085a61b 100644
--- a/lib/Vend/Payment/PayflowPro.pm
+++ b/lib/Vend/Payment/PayflowPro.pm
@@ -673,18 +673,23 @@ sub payflowpro {
         }
     }
 
-# Uncomment all the following block to use the debug statement. It strips
-# the arg of any sensitive credit card information and is safe
-# (and recommended) to enable in production.
-#
-#    {
-#        my %munged_query = %query;
-#        $munged_query{PWD} = 'X';
-#        $munged_query{ACCT} =~ s/^(\d{4})(.*)/$1 . ('X' x length($2))/e;
-#        $munged_query{CVV2} =~ s/./X/g;
-#        $munged_query{EXPDATE} =~ s/./X/g;
+    my $gwl =
+        Vend::Payment::PayflowPro
+            -> new({
+                Enabled => charge_param('gwl_enabled'),
+                LogTable => charge_param('gwl_table'),
+            })
+    ;
+
+    {
+        my %munged_query = %query;
+        $munged_query{PWD} = 'X';
+        $munged_query{ACCT} =~ s/^(\d{4})(.*)/$1 . ('X' x length($2))/e;
+        $munged_query{CVV2} =~ s/./X/g;
+        $munged_query{EXPDATE} =~ s/./X/g;
 #::logDebug("payflowpro query: " . ::uneval(\%munged_query));
-#    }
+        $gwl->request(\%munged_query);
+    }
 
     my $timeout = $opt->{timeout} || 45;
     die "Bad timeout value, security violation." unless $timeout && $timeout !~ /\D/;
@@ -732,18 +737,22 @@ sub payflowpro {
     my $request = HTTP::Request->new('POST', $uri, $headers, $string);
     my $ua = LWP::UserAgent->new(timeout => $timeout);
     $ua->agent('Vend::Payment::PayflowPro');
+    $gwl->start;
     my $response = $ua->request($request);
+    $gwl->stop;
     my $resultstr = $response->content;
 #::logDebug(qq{PayflowPro response:\n\t$resultstr\n--------------------});
 
     unless ( $response->is_success ) {
-        return (
+        my %return = (
             RESULT => -1,
             RESPMSG => 'System Error',
             MStatus => 'failure-hard',
             MErrMsg => 'System Error',
             lwp_response => $resultstr,
         );
+        $gwl->response(\%return);
+        return %return;
     }
 
     %$result = split /[&=]/, $resultstr;
@@ -757,6 +766,7 @@ sub payflowpro {
     }
 
     my $decline = $result->{RESULT};
+    $gwl->response($result);
 
     if (
         $result->{RESULT} =~ /^0|12[67]$/
@@ -849,4 +859,100 @@ sub payflowpro {
 
 package Vend::Payment::PayflowPro;
 
+use Vend::Payment::GatewayLog;
+use base qw/Vend::Payment::GatewayLog/;
+
+# log_it() must be overridden.
+sub log_it {
+    my $self = shift;
+    my $request = $self->request
+        or ::logDebug('Cannot write to %s: no request present', $self->table),
+            return;
+
+    my $response = $self->response;
+    unless ($response) {
+
+        if ($Vend::Payment::Global_Timeout) {
+            my $msg = errmsg('No response. Global timeout triggered');
+            ::logDebug($msg);
+            $response = {
+                RESULT => -2,
+                RESPMSG => $Vend::Payment::Global_Timeout,
+            };
+        }
+        else {
+            my $msg = errmsg('No response. Reason unknown');
+            ::logDebug($msg);
+            $response = {
+                RESULT => -3,
+                RESPMSG => $msg,
+            };
+        }
+    }
+
+    eval {
+        my $table = $self->table;
+        my $db = ::database_exists_ref($table)
+            or die "'$table' not a valid Interchange table";
+        $db = $db->ref;
+
+        my %fields = (
+            trans_type => $request->{TRXTYPE} || 'x',
+            processor => 'payflowpro',
+            catalog => $Vend::Cfg->{CatalogName},
+            result_code =>
+                defined ($response->{RESULT})
+                && $response->{RESULT} =~ /^-?\d+$/
+                    ? $response->{RESULT}
+                    : undef,
+            response_msg => $response->{RESPMSG} || '',
+            request_id => $response->{PNREF} || '',
+            order_number => $request->{COMMENT1} || '',
+            request_duration => $self->duration,
+            request_date => $self->timestamp,
+            email => $request->{EMAIL} || '',
+            request => ::uneval($request) || '',
+            response => ::uneval($response) || '',
+            session_id => $::Session->{id},
+        );
+
+        my $hostname = `hostname -s`;
+        chomp $hostname;
+        $fields{request_source} = $hostname;
+
+        $fields{order_md5} =
+            Digest::MD5::md5_hex(
+                $request->{EMAIL},
+                $request->{TRXTYPE},
+                $request->{ORIGID},
+                $request->{AMT},
+                $::Session->{id},
+                map { ($_->{code}, $_->{quantity}) } @$Vend::Items
+            )
+        ;
+
+        $db->set_slice(
+            [ { dml => 'insert' } ],
+            \%fields
+        )
+            or die "set_slice for $table failed";
+    }; # End eval
+
+    if ($@) {
+        my $err = $@;
+        ::logDebug(
+            q{Couldn't write to %s: %s -- request: %s -- response: %s},
+            $self->table,
+            $err,
+            ::uneval($request),
+            ::uneval($response)
+        );
+    }
+    else {
+        $self->clean;
+    }
+
+    return 1;
+}
+
 1;
diff --git a/lib/Vend/Table/DBI.pm b/lib/Vend/Table/DBI.pm
index 95f35b1..217932b 100644
--- a/lib/Vend/Table/DBI.pm
+++ b/lib/Vend/Table/DBI.pm
@@ -157,6 +157,7 @@ my %known_capability = (
 		DB2		=> 1,
 		Pg		=> 1,
 		Oracle	=> 1,
+		SQLite	=> 1,
 	},
 	HAS_DESCRIBE => {
 		mysql	=> 1,
@@ -185,6 +186,7 @@ my %known_capability = (
 	HAS_LIMIT => {
 		mysql	=> 1,
 		Pg		=> 1,
+		SQLite	=> 1,
 	},
 	ALTER_DELETE => { 
 		mysql => 'ALTER TABLE _TABLE_ DROP _COLUMN_',
@@ -225,12 +227,14 @@ my %known_capability = (
 		Pg => "SELECT nextval(_SEQUENCE_NAME_V_)",
 	},
 	SEQUENCE_VAL	 => { 
-		mysql => undef,
+		mysql	=> undef,
+		SQLite	=> undef,
 	},
 	SEQUENCE_KEY	 => { 
 		mysql	=> 'INT PRIMARY KEY AUTO_INCREMENT',
 		Pg	=> 'INT NOT NULL PRIMARY KEY',
 		Oracle	=> 'INT NOT NULL PRIMARY KEY',
+		SQLite	=> 'INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL',
 	},
 	SEQUENCE_VALUE_FUNCTION	 => { 
 		Pg => "SELECT currval(_SEQUENCE_NAME_V_)",
@@ -238,6 +242,7 @@ my %known_capability = (
 	},
 	SEQUENCE_LAST_FUNCTION	 => { 
 		mysql => 'select last_insert_id()',
+		SQLite => 'select last_insert_rowid()',
 		## These use explicit
 		Pg => undef,
 		Oracle => undef,



More information about the interchange-cvs mailing list