diff --git a/extend/application/controllers/fcPayOneOrderView.php b/extend/application/controllers/fcPayOneOrderView.php index 767edc0..c8df8a5 100755 --- a/extend/application/controllers/fcPayOneOrderView.php +++ b/extend/application/controllers/fcPayOneOrderView.php @@ -83,10 +83,18 @@ public function __construct() */ public function execute() { + $this->_oFcpoHelper->debugGlobalVariables('(' . __CLASS__ . '::' . __FUNCTION__ . ')'); $sFcpoMandateCheckbox = $this->_oFcpoHelper->fcpoGetRequestParameter('fcpoMandateCheckbox'); $sPaymentId = $this->_oFcpoHelper->fcpoGetSessionVariable('paymentid'); $blIsRedirectPayment = fcPayOnePayment::fcIsPayOneRedirectType($sPaymentId); + $this->_oFcpoHelper->debugLog('Executing payment : ' . $sPaymentId, '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); + if($blIsRedirectPayment) { + $this->_oFcpoHelper->debugLog('Payment is redirected' , '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); + } else { + $this->_oFcpoHelper->debugLog('Payment is NOT redirected' , '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); + } + $blConfirmMandateError = ( (!$sFcpoMandateCheckbox || $sFcpoMandateCheckbox == 'false') && $this->_fcpoMandateAcceptanceNeeded() diff --git a/extend/application/controllers/fcPayOnePaymentView.php b/extend/application/controllers/fcPayOnePaymentView.php index 09ae651..e3970b7 100755 --- a/extend/application/controllers/fcPayOnePaymentView.php +++ b/extend/application/controllers/fcPayOnePaymentView.php @@ -955,10 +955,13 @@ public function validateAmazonPayment() { */ public function validatePayment() { + $this->_oFcpoHelper->debugGlobalVariables('(' . __CLASS__ . '::' . __FUNCTION__ . ')'); $sPaymentId = $this->_fcpoGetPaymentId(); + $this->_oFcpoHelper->debugLog('Payment chosen : ' . $sPaymentId, '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); $this->_fcpoCheckKlarnaUpdateUser($sPaymentId); $mReturn = parent::validatePayment(); + $this->_oFcpoHelper->debugLog('Payment validation result : ' . $mReturn, '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); $mReturn = $this->_processParentReturnValue($mReturn); $mReturn = $this->_fcpoProcessValidation($mReturn, $sPaymentId); @@ -1453,6 +1456,7 @@ protected function _fcpoKlarnaUpdateUser() } if ($blUserChanged === true) { + $this->_oFcpoHelper->debugLog('Klarna User updated : ' . $oUser->oxuser__oxid, '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); $oUser->save(); } } @@ -1521,24 +1525,33 @@ protected function _fcpoProcessValidation($mReturn, $sPaymentId) $oPayment = $this->_oFcpoHelper->getFactoryObject('oxpayment'); $oPayment->load($sPaymentId); $mReturn = $this->_fcpoSecInvoiceSaveRequestedValues($mReturn, $sPaymentId); + $this->_oFcpoHelper->debugLog('Secinvoice validation result : ' . $mReturn, '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); $blContinue = $this->_fcpoCheckBoniMoment($oPayment); if ($blContinue !== true) { $this->_fcpoSetBoniErrorValues($sPaymentId); + $this->_oFcpoHelper->debugLog('Boni validation failed', '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); $mReturn = 'basket'; } else { $this->_fcpoSetMandateParams($oPayment); + $this->_oFcpoHelper->debugLog('Boni validated', '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); } $this->_fcCleanupSessionFragments($oPayment); + $this->_oFcpoHelper->debugLog('Session variables cleaned', '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); $mReturn = $this->_fcpoKlarnaCombinedValidate($mReturn, $sPaymentId); + $this->_oFcpoHelper->debugLog('Klarna validation result : ' . $mReturn, '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); $mReturn = $this->_fcpoPayolutionPreCheck($mReturn, $sPaymentId); + $this->_oFcpoHelper->debugLog('Unzer validation result : ' . $mReturn, '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); + if (in_array($sPaymentId, array('fcporp_bill', 'fcporp_debitnote'))) { $mReturn = $this->_fcpoCheckRatePayBillMandatoryUserData($mReturn, $sPaymentId); + $this->_oFcpoHelper->debugLog('Ratepay validation result : ' . $mReturn, '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); } $mReturn = $this->_fcpoAdultCheck($mReturn, $sPaymentId); + $this->_oFcpoHelper->debugLog('Adult check validation result : ' . $mReturn, '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); } return $mReturn; diff --git a/extend/application/controllers/fcPayOneThankyouView.php b/extend/application/controllers/fcPayOneThankyouView.php index a52b1e3..cc300d3 100755 --- a/extend/application/controllers/fcPayOneThankyouView.php +++ b/extend/application/controllers/fcPayOneThankyouView.php @@ -145,6 +145,7 @@ public function fcpoOrderHasProblems() */ public function render() { + $this->_oFcpoHelper->debugGlobalVariables('(' . __CLASS__ . '::' . __FUNCTION__ . ')'); $oUser = $this->getUser(); if($oUser) { $this->_oFcpoHelper->fcpoSetSessionVariable('sFcpoUserId', $oUser->getId()); @@ -166,6 +167,7 @@ public function render() */ protected function _fcpoDeleteSessionVariablesOnOrderFinish() { + $this->_oFcpoHelper->debugLog('Delete session variables on order finish', '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); $this->_oFcpoHelper->fcpoDeleteSessionVariable('fcpoRefNr'); $this->_oFcpoHelper->fcpoDeleteSessionVariable('klarna_authorization_token'); $this->_oFcpoHelper->fcpoDeleteSessionVariable('klarna_client_token'); diff --git a/extend/application/models/fcPayOneOrder.php b/extend/application/models/fcPayOneOrder.php index 3d98ca8..00a0c7c 100755 --- a/extend/application/models/fcPayOneOrder.php +++ b/extend/application/models/fcPayOneOrder.php @@ -471,12 +471,15 @@ protected function _fcpoFinalizeOrder($oBasket, $oUser, $blRecalculatingOrder) { // copies user info $this->_setUser($oUser); + $this->_oFcpoHelper->debugLog('Finalize order : copy user info', '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); // copies basket info if no basket injection or presave order is inactive $this->_fcpoHandleBasket($blSaveAfterRedirect, $oBasket); + $this->_oFcpoHelper->debugLog('Finalize order : handle basket', '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); // payment information $oUserPayment = $this->_setPayment($oBasket->getPaymentId()); + $this->_oFcpoHelper->debugLog('Finalize order : set payment info', '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); // set folder information, if order is new // #M575 in recalcualting order case folder must be the same as it was @@ -485,12 +488,14 @@ protected function _fcpoFinalizeOrder($oBasket, $oUser, $blRecalculatingOrder) { } $mRet = $this->_fcpoExecutePayment($blSaveAfterRedirect, $oBasket, $oUserPayment, $blRecalculatingOrder); + $this->_oFcpoHelper->debugLog('Finalize order : execute payment : ' . $mRet, '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); if ($mRet !== null) { return $mRet; } //saving all order data to DB $this->_blFinishingSave = true; + $this->_oFcpoHelper->debugLog('Finalize order : saving order to DB', '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); $this->save(); $this->_fcpoSaveAfterRedirect($blSaveAfterRedirect); @@ -505,6 +510,7 @@ protected function _fcpoFinalizeOrder($oBasket, $oUser, $blRecalculatingOrder) { } $this->_fcpoSetOrderStatus(); + $this->_oFcpoHelper->debugLog('Finalize order : set order status', '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); // store orderid $oBasket->setOrderId($this->getId()); @@ -521,10 +527,12 @@ protected function _fcpoFinalizeOrder($oBasket, $oUser, $blRecalculatingOrder) { $this->_fcpoMarkVouchers($blRecalculatingOrder, $oUser, $oBasket); if (!$this->oxorder__oxordernr->value) { + $this->_oFcpoHelper->debugLog('Finalize order : assign missing order nr', '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); $this->_setNumber(); } else { oxNew(\OxidEsales\Eshop\Core\Counter::class)->update($this->_getCounterIdent(), $this->oxorder__oxordernr->value); } + $this->_oFcpoHelper->debugLog('Finalize order : order nr = ' . $this->oxorder__oxordernr->value, '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); $this->_oFcpoHelper->fcpoDeleteSessionVariable('fcpoordernotchecked'); $this->_oFcpoHelper->fcpoDeleteSessionVariable('fcpoWorkorderId'); @@ -532,6 +540,7 @@ protected function _fcpoFinalizeOrder($oBasket, $oUser, $blRecalculatingOrder) { // send order by email to shop owner and current user // skipping this action in case of order recalculation $iRet = $this->_fcpoFinishOrder($blRecalculatingOrder, $oUser, $oBasket, $oUserPayment); + $this->_oFcpoHelper->debugLog('Finalize order : finish order result : ' . $iRet, '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); // OXID-233 : handle amazon different login $this->_fcpoAdjustAmazonPayUserDetails($oUserPayment); @@ -593,6 +602,7 @@ protected function _fcpoExecutePayment($blSaveAfterRedirect, $oBasket, $oUserPay { if ($blSaveAfterRedirect === true) { $sRefNrCheckResult = $this->_fcpoCheckRefNr(); + $this->_oFcpoHelper->debugLog('Ref nr check result (empty = ok) : ' . $sRefNrCheckResult, '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); $sTxid = $this->_oFcpoHelper->fcpoGetSessionVariable('fcpoTxid'); if ($sRefNrCheckResult != '') { @@ -751,6 +761,7 @@ protected function _fcpoEarlyValidation($blSaveAfterRedirect, $oBasket, $oUser, $oUtils = $this->_oFcpoHelper->fcpoGetUtils(); $oUtils->logger('BLOCKER'); // we might use this later, this means that somebody klicked like mad on order button + $this->_oFcpoHelper->debugLog('Order validation failed : order already exists', '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); return self::ORDER_STATE_ORDEREXISTS; } @@ -766,6 +777,7 @@ protected function _fcpoEarlyValidation($blSaveAfterRedirect, $oBasket, $oUser, // validating various order/basket parameters before finalizing if (($iOrderState = $this->validateOrder($oBasket, $oUser))) { + $this->_oFcpoHelper->debugLog('Order validation failed : misc. order/basket parameters', '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); return $iOrderState; } } @@ -783,6 +795,7 @@ protected function _fcCompareBasketAgainstShadowBasket($oBasket) { $oShadowBasket = $this->fcpoGetShadowBasket(); $blIsValid = $this->_fcpoCompareBaskets($oBasket, $oShadowBasket); if ($blIsValid === false) { + $this->_oFcpoHelper->debugLog('Order validation failed : non-matching shadow basket', '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); $this->_fcpoMarkOrderAsProblematic(); $this->_fcpoAddShadowBasketCheckDate(); } else { @@ -959,6 +972,7 @@ protected function _fcpoFinishOrder($blRecalculatingOrder, $oUser, $oBasket, $oU protected function _fcpoSaveAfterRedirect($blSaveAfterRedirect) { if ($blSaveAfterRedirect === true) { + $this->_oFcpoHelper->debugLog('Finalize order : save after redirect order nr', '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); $sQuery = "UPDATE fcpotransactionstatus SET fcpo_ordernr = '{$this->oxorder__oxordernr->value}' WHERE fcpo_txid = '" . $this->_oFcpoHelper->fcpoGetSessionVariable('fcpoTxid') . "'"; $this->_oFcpoDb->Execute($sQuery); } @@ -1088,6 +1102,10 @@ protected function _fcpoCheckTxid() } $this->_fcpoSetAppointedError($blAppointedError); + if ($blAppointedError) { + $this->_oFcpoHelper->debugLog('Order moved to error folder : Txid check failed', '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); + } + return $blAppointedError; } @@ -1521,6 +1539,7 @@ public function validateStock($oBasket) ) ? false : true; if ($blCheckProduct) { + $this->_oFcpoHelper->debugLog('Finalize order : check stocks', '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); parent::validateStock($oBasket); } @@ -1643,6 +1662,7 @@ public function fcIsPayPalOrder() */ public function fcHandleAuthorization($blReturnRedirectUrl = false, $oPayGateway = null) { + $this->_oFcpoHelper->debugLog('Finalize order : handle authorization', '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); $oConfig = $this->_oFcpoHelper->fcpoGetConfig(); $aDynvalueForm = $this->_oFcpoHelper->fcpoGetRequestParameter('dynvalue'); if ($this->oxorder__oxpaymenttype->value === 'fcpoklarna_directdebit' && $this->_oFcpoHelper->fcpoGetSessionVariable('klarna_authorization_token') === '' ) { @@ -1813,6 +1833,7 @@ protected function _fcpoFlagOrderPaymentAsRedirect($blFlaggedAsRedirect = true) */ protected function _fcpoHandleAuthorizationRedirect($aResponse, $sRefNr, $sAuthorizationType, $sMode, $blReturnRedirectUrl) { + $this->_oFcpoHelper->debugLog('Finalize order : handle redirect authorization', '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); $this->_fcpoFlagOrderPaymentAsRedirect(); $oConfig = $this->_oFcpoHelper->fcpoGetConfig(); $oUtils = $this->_oFcpoHelper->fcpoGetUtils(); diff --git a/lib/fcpodebuglogger.php b/lib/fcpodebuglogger.php new file mode 100644 index 0000000..aee47e8 --- /dev/null +++ b/lib/fcpodebuglogger.php @@ -0,0 +1,70 @@ +_oFcpoHelper = oxNew('fcpohelper'); + $this->sLogDirPath = $this->_oFcpoHelper->fcpoGetConfig()->getLogsDir() . self::LOG_DIR_SUFFIX; + } + + /** + * @param string $message + * @param string $location + */ + public function writeEntry($message = '', $location = '') + { + $sTimestamp = $this->getDate()->format('[Y-m-d H:i:s]'); + $sLogEntry = $sTimestamp . ' ' . $location . ' ' . $message . PHP_EOL; + + file_put_contents($this->getCurrentLogFile(), $sLogEntry, FILE_APPEND); + } + + protected function getCurrentLogFile() + { + $sToday = $this->getDate()->format('Y-m-d'); + $sDailyLogFile = $this->getLogDir() . '' . $sToday . '_debug_log.log'; + + return $sDailyLogFile; + } + + /** + * @return string + */ + protected function getLogDir() + { + if (!is_dir($this->sLogDirPath)) { + mkdir($this->sLogDirPath,0755, true); + } + + return $this->sLogDirPath; + } + + /** + * @return DateTimeImmutable + */ + private function getDate() + { + return new DateTimeImmutable('now', new DateTimeZone('Europe/Berlin')); + } + +} diff --git a/lib/fcpohelper.php b/lib/fcpohelper.php index dd294b6..38f18f8 100644 --- a/lib/fcpohelper.php +++ b/lib/fcpohelper.php @@ -21,6 +21,11 @@ class fcpohelper extends oxBase { + /** @var bool Log or not the various steps of payment checkout */ + protected static $_blDebugLogEntries = true; + /** @var bool Log or not the php GLOBALs (SERVER, SESSION, GET, POST, FcpoSession) when call a controller */ + protected static $_blDebugLogGlobals = true; + /** * Flags if shop uses registry * @@ -622,4 +627,35 @@ protected static function _useRegistry() return self::$_blUseRegistry; } + /** + * @param string $message + * @param string $location + */ + public function debugLog($message, $location = '') + { + if (self::$_blDebugLogEntries) { + $oLogger = oxNew('fcpodebuglogger'); + $oLogger->writeEntry($message, $location); + } + } + + /** + * @param string $location + */ + public function debugGlobalVariables($location = '') + { + if (self::$_blDebugLogGlobals) { + $oLogger = oxNew('fcpodebuglogger'); + $aVariables = [ + 'REQUEST' => $_REQUEST, + 'SESSION' => $_SESSION, + 'GET' => $_GET, + 'POST' => $_POST, + 'FCPOSession' => $this->fcpoGetSession() + ]; + + $oLogger->writeEntry(var_export($aVariables, true), $location); + } + } + } diff --git a/metadata.php b/metadata.php index ddb7d3c..b550825 100755 --- a/metadata.php +++ b/metadata.php @@ -99,6 +99,7 @@ 'fcpohelper' => 'fc/fcpayone/lib/fcpohelper.php', 'fcporequest' => 'fc/fcpayone/lib/fcporequest.php', 'fcpoparamsparser' => 'fc/fcpayone/lib/fcpoparamsparser.php', + 'fcpodebuglogger' => 'fc/fcpayone/lib/fcpodebuglogger.php', // core 'fcpayone_events' => 'fc/fcpayone/core/fcpayone_events.php', ), diff --git a/status.php b/status.php index 11f27d4..d01e78a 100644 --- a/status.php +++ b/status.php @@ -343,6 +343,8 @@ protected function _handleMapping() public function handle() { try { + $oFcpoHelper = oxNew('fcpohelper'); + $oFcpoHelper->debugLog('Handling txstatus for order (' . $this->fcGetPostParam('reference') . ') : ' . $this->fcGetPostParam('txaction'), '(' . __CLASS__ . '::' . __FUNCTION__ . ')'); $this->_isKeyValid(); $sStatusmessageId = $this->log(); $this->_allowDebit();