Нетипичное поведение PHP!

[borodul]

Здравствуйте, коллеги!
Вчера с заказчиком столкнулись с незадачей. Кратко: CMS == Drupal 6, интернет-магазин на UberCart, я писал модуль интеграции с системой "Купивкредит" (от банка "Тинькофф" которая).
В нашем модуле все реализовано следующим образом: на стадии подтверждения заказа формируется анкета, в которую подставляется номер заявки в банке (уникальная строка, в общем случае - результат работы функции time(), у нас - комбинация функции time() и номера заказа в магазине по принципу $orderNumber = sprintf("%s-%s", ${номер заказа}, base_convert(time(), 10, 36)), а одновременно с этим в таблицу в базе данных номер заявки привязывается к номеру заказа. Сделано это было для того, чтобы потом мы могли с помощью API, предоставляемого банком, проверять сделанные заказы в автоматическом режиме.

Специально хочу отметить, что переменная $orderNumber была определена всего один раз, а далее скрипт работает только с полученным ее значением. По крайней мере, я так думал.

На тестовом сервере все работало нормально (огрехи были, конечно, куда без этого, но то были МОИ огрехи, я их быстро находил и устранял). Когда же мы перенесли модуль на "боевой" сайт, выяснилось, что все работает как-то не так. Еще через некоторое время выяснилось, что работает-то все хорошо, вот только в базу данных и в банк летят разные значения $orderNumber. Да какие разные! Отличались они чаще всего одной буквой, последней, так что мы не сразу и заметили, в чем дело. Реже - двумя последними. Как будто значения вычислялись с разницей в несколько секунд, но ведь я же определил эту переменную только один раз! Как такое может быть внутри одной области видимости?
Убрал из определения переменной base_convert, оставил просто time (base_convert был придуман для подсокращения таймстемпа, заказчик ворчал, что строка длинная, неудобно ему было, видите ли). Но я все равно не понимаю, как такое возможно?! Если я присвоил переменной некоторое вычисленное значение, сделал это всего один раз и в одном месте кода, а потом просто подставляю переменную в нужные мне места, то как, черт побери, КАК в разных местах получаются разные значения переменной????

Я очень надеюсь, что я не одинок в своих несчастьях (потому что когда заказ на самом финише не сдается из-за таких вот кренделей - это счастьем никак нельзя назвать), и у кого-то подобная ситуация была, либо она где-то уже описана. Просто я за почти 10 лет кодинга на PHP с таким встречаюсь впервые.

 

[С.]

Хочется конечно верить, что найден супербаг века. Но все гораздо прозаичнее. Отлаживайте, Шура, отлаживайте.

 

[artoodetoo]

Вероятно разные значения рождаются в разных запросах. Ты думаешь, что он один, а их несколько. Протоколировать надо всё.

 

[borodul]

Вероятно разные значения рождаются в разных запросах. Ты думаешь, что он один, а их несколько. Протоколировать надо всё.

Ребята, читаем внимательно. Я там даже кусок кода привел, в котором максимально подробно рассказывается, как эта переменная объявляется. Запросы тут ни при чем - в них подставляется то, что УЖЕ вычислилось и более изменениям не подвергалось.

Хочется конечно верить, что найден супербаг века. Но все гораздо прозаичнее. Отлаживайте, Шура, отлаживайте.

И вообще, я вам, парни, вот что хочу сказать, только без обид: я с PHP уже далеко не первый год общаюсь, и тыкать меня носом в очевидные вещи не надо. Я слово "отладка" впервые услышал не сегодня, и не вчера, и не год назад. Так что если по делу сказать нечего, а хочется только потрындеть, то валите флудерасничать в другую тему. Это я к тому, что если бы Вам, уважаемый, было, что сказать, то начали бы Вы с того, что попросили бы привести хотя бы участок кода. За грубость извиняюсь, я после бессонной ночи.

На тестовом сервере все работало нормально

Обратите внимание, на тестовом сервере все работало нормально, а огрехи, которые мне там встречались, не представляли для меня никакой сложности, поэтому я их и устранял легко. Во всяком случае, ни разу за время работы на тесте не было такого, чтобы в базу ушла одна строка, а в банк - чуть-чуть другая. Меня, собственно, и интересует, не случалось ли у кого-нибудь подобных ситуаций (в предпоследнем предложении).

 

[флоппик]

Чувак, не гони пургу. Тот, кто знаком с отладкой не понаслышке, не напишет «работает как-то не так». Он покажет логи и сделает тестовый кейс с данными. Тут не юные девственницы сидят, не надо сказки рассказывать, надо логи, код и данные показать.

 

[borodul]

Вероятно разные значения рождаются в разных запросах. Ты думаешь, что он один, а их несколько. Протоколировать надо всё.

Вообще, это можно было бы назвать верной мыслью, если бы я вычислял значение с помощью выражения каждый раз по новой - т.е. если бы я подставлял не переменную, а в каждом месте писал бы sprintf("%s-%s", ${номер заказа}, base_convert(time(), 10, 36)). Но даже при этом значение менялось бы раз в секунду, а время работы скрипта всяко много меньше. Поэтому иногда бы получалось то мимо, то в цвет. А оно все время получается мимо.

 

[borodul]

Чувак, не гони пургу. Тот, кто знаком с отладкой не понаслышке, не напишет «работает как-то не так». Он покажет логи и сделает тестовый кейс с данными. Тут не юные девственницы сидят, не надо сказки рассказывать, надо логи, код и данные показать.

Вот, вооот!

    $NEW_ORDER = uc_order_load($_SESSION['cart_order']);
    if (strtolower($NEW_ORDER->payment_method) != 'kupivkredit') {
        return drupal_render($form);
    }
    $host = 'https://form.kupivkredit.ru/sdk/v1/sdk.js';

    $partnerId = '*********************';
    $secretPhrase = '***********************';
    $orderNumber = sprintf('%s-%s', $NEW_ORDER->order_id, base_convert(time(), 10, 36));

    // проверяем наличие в таблице заявки для данного заказа
    $result = db_fetch_array(db_query("SELECT id from {credit_payments} WHERE shop_order_id = %d", $NEW_ORDER->order_id));
    $paymentId = $result['id'];

    // пишем в базу номер будущей заявки для нашего заказа и статус com (заполняется в данный момент)
    $query = "REPLACE INTO {credit_payments} (id, shop_order_id, bank_order_id, status) VALUES (%d, %d, '%s', '%s')";
    $args = array($paymentId, $NEW_ORDER->order_id, $orderNumber, 'com');
    $result1 = db_query($query, $args); // в базу идет значение '4194-nrwom1'

    $order = array();
    $order['partnerId'] = $partnerId;
    $order['merchantId'] = '';
    $order['partnerOrderId'] = $orderNumber; // в банк летит значение '4194-nrwolx'
    $order['deliveryType'] = '';
    $order['details'] = array(
        'firstname' => $NEW_ORDER->billing_first_name,
        'lastname' => $NEW_ORDER->billing_last_name,
        'middlename' => $NEW_ORDER->tmp_secondname,
        'email' => $NEW_ORDER->primary_email,
        'cellphone' => $NEW_ORDER->billing_phone,
    );

    $order['items'] = array();

    foreach ($NEW_ORDER->products as $product) {
        $node = node_load($product->nid);

        $order['items'][] = array(
            'title' => $node->title,
            'category' => '',
            'qty' => $product->qty,
            'price' => ($node->field_special_price[0]['value']?$node->field_special_price[0]['value']:$node->sell_price),
        );
    }
    $type = variable_get('uc_kk_type', 'full');

    $json = json_encode($order);
    $base64 = base64_encode($json);

    $sig = _signMessage($base64, $secretPhrase);
 
    $month_payment = ceil($NEW_ORDER->order_total * ((int) variable_get('uc_kk_monthly_payment', 6)) / 100);
    $output = drupal_render($form);
    $script = <<<EOD
        window.callbacks = [];
        var KVKform;
     
        window.onload = function () {
            for (var i = 0; i < this.callbacks.length; i++) {
                this.callbacks[i].call();
            };
        };
     
        window.myOnLoadFunction = function(KVK) {
            var openForm, backButton, submitButton, complete = 0;
     
            KVKform = KVK.ui("form", {
                order:"$base64",
                sign:"$sig",
                type:"$type",
            });
     
            window.callbacks.push(function () {
                openForm = document.getElementById('edit-credit');
                backBtn = document.getElementById('edit-back');
                submitBtn = document.getElementById('edit-submit');
     
                openForm.onclick = function () {
         
                    KVKform.open();
                    KVKform.on("close", function (form) {
                        $.ajax("/check/order/state/$NEW_ORDER->order_id", null, function (data) {
                            complete = parseInt(data);
                        }, 'text');
                        setTimeout(function () {
                            if (complete == 1) {
                                openForm.style.display = 'none';
                                submitBtn.style.display = 'inline-block';
                            };
                        }, 2000);
                    });
             
                    KVKform.on("complete", function (form) {
                        complete = 1;
                        setTimeout(function () {
// проверка статуса заявки
                            $.ajax("**********************************", null, function (data) {
                                complete = parseInt(data);
                            }, 'text');
                        }, 10000);
                    });
                    KVKform.on("decision", function (form, decision) {
                        if (decision == 'rejected') {
                            complete = 0;
                        };
                    });
             
                    KVKform.on("deny", function (form) {
                        complete = 0;
                        KVKform.close();
                    });
             
                    KVKform.on("admit", function (form) {
                        complete = 1;
                        submitBtn.click();
                    });
             
                    return false;
                };
            });
        };
        function loadSDK(path, fnName) {
     
                var scriptPath, firstScript, scriptElement;
                scriptPath = path + "?onload=" + fnName;
                firstScript  = document.getElementsByTagName("script")[0];
                scriptElement = document.createElement("script");
                scriptElement.src = scriptPath;
                firstScript.parentNode.insertBefore(scriptElement, firstScript.nextSibling || firstScript);
        };
     
        loadSDK("https://form.kupivkredit.ru/sdk/v1/sdk.js", "myOnLoadFunction");
EOD;
    require_once 'includes/class.JavaScriptPacker.php';
    $jsPacker = new JavaScriptPacker($script, 62, false, true);
    $packed = $jsPacker->pack();
    drupal_set_html_head('<script type="text/javascript">'.$script.'</script>');

Чувак, не гони пургу. Тот, кто знаком с отладкой не понаслышке, не напишет «работает как-то не так». Он покажет логи и сделает тестовый кейс с данными. Тут не юные девственницы сидят, не надо сказки рассказывать, надо логи, код и данные показать.

Логи показать не могу, они мне недоступны, к сожалению. Правки заливаются в SVN, а потом ревизии летят на сервер руками заказчика.
Что касается "напишет - не напишет"... Даже когда я только начинал кодить, я НИКОГДА не обращался на форумы за помощью, всегда все проблемы сам разгрызал. Но вот это поведение мне непонятно. Я бы не удивлялся так, если бы оно везде работало так. Но на локале и на тестовом сервере оно работает правильно, штатно, а на "боевом" - так, как я описал выше.

 

[флоппик]

Я попробую еще раз: ты не гадалка. Пока ты будешь «Логи показать не могу, они мне недоступны, к сожалению.» вместо того, что бы просить логи — ты не программист, а гадалка, потому что гадаешь. Гадать нельзя в этой профессии, нужно реальными данными оперировать.

 

[borodul]

Я попробую еще раз: ты не гадалка. Пока ты будешь «Логи показать не могу, они мне недоступны, к сожалению.» вместо того, что бы просить логи — ты не программист, а гадалка, потому что гадаешь. Гадать нельзя в этой профессии, нужно реальными данными оперировать.

Попробую объяснить еще раз: у меня с заказчиком отношения и без того непростые. Я в Новосибирске, он в Москве. Я к нему на чай прийти не могу, чтобы в логи заглянуть. Сам он их может только по SSH посмотреть, даже скачать не может по FTP error.log. Теперь ясно, почему я логи здесь не привел?

Все, чем он ограничился - это сказал, что на файл модуля в логах ссылок нет. Код я привел. Но привел я его не потому, что мне в нем что-то непонятно (мне как раз понятно в нем абсолютно ВСЕ, я его САМ писал от начала и до конца), а чтобы заинтересованные люди сами могли убедиться, что такая ситуация не может получиться, потому что представить себе, как одна и та же переменная, будучи ровно один (1) раз объявленной, будет то тут, то там сама по себе менять значение свое, я никак не могу. Я даже ее реальные значения привел в комментариях, для наглядности.

В любом случае, даже если все-таки я - лох, я обязательно об этом здесь сообщу, и пусть все посмеются. И я тоже посмеюсь, потому что смеяться над собственными ошибками и глупостью - оно не стыдно. Только вот думаю, что не до смеха тут будет.

 

[Breeze]

а мне от другое интересно, как sprintf("%d") может выдавать что-то отличное от нуля в случае с base_convert(time(), 10, 36) ? nrwolx никак не %d
а то ведь окажется, что !на самом деле! $orderNumber получается через какую-то такую такую штуку :о)

class OrderNumber {

        public function __toString() {
                return sprintf('%d-%s', 1147, base_convert(time(), 10, 36));
        }

}

$orderNumber = new OrderNumber();

print $orderNumber.PHP_EOL;

sleep(3);

print $orderNumber.PHP_EOL;

или классическая 404/background=#ffffff

 

[borodul]

а мне от другое интересно, как sprintf("%d") может выдавать что-то отличное от нуля в случае с base_convert(time(), 10, 36) ? nrwolx никак не %d
а то ведь окажется, что !на самом деле! $orderNumber получается через какую-то такую такую штуку :о)

class OrderNumber {

        public function __toString() {
                return sprintf('%d-%s', 1147, base_convert(time(), 10, 36));
        }

}

$orderNumber = new OrderNumber();

print $orderNumber.PHP_EOL;

sleep(3);

print $orderNumber.PHP_EOL;

или классическая 404/background=#ffffff

Благодарю за ответ. Я по-видимому, малость напорол в sprintf, когда сюда код выводил. Все там чисто

<?php
sprintf('%s-%s', $NEW_ORDER->order_id /* число */, time() /* естественно, тоже число */)

Попробовал определить номер заявки не в переменной, а в константе. И константу вместо переменной так же пихать. Интересно, подействует?

 

[Breeze]

Я по-видимому, малость напорол в sprintf, когда сюда код выводил

о чем это говорит?

 

[borodul]

о чем это говорит?

Я понимаю Ваш намек. Но отличное от нуля такая конструкция никогда бы не выдала. Просто когда я выводил сюда код, он уже был изменен (константу уже везде определил), и я его правил прямо здесь. Я ведь прекрасно понимаю, чем отличается "%d" от "%s". Просто в спешке исправлял.
Получилась такая фигня потому, что я заказчику отправил изменение, до того, как задал здесь вопрос. Посему прошу извинить за некую сумбурность в изложении, этой ночью я потерял много волос в битве с этой неисправностью.
Ночью же я убрал base_convert, потому что прочитал в доке, что при конвертации больших чисел возможны ошибки. base_convert я добавил для того, чтобы подсократить строку, выдаваемую функцией time(). Просто заказчику не нравилось, что строка сильно длинная получается. Надо было его с этими замечаниями послать подальше, конечно, но отношения у нас и без того несколько напряженные. Так вот, base_convert я убрал, оставил time() без конвертации - только числа и ничего больше (оттуда "%d-%d" и осталось). В результате эта фигня повторилась.

В банке: 4196-1437633368
В таблице: 4196-1437633370

Такое впечатление, что в таблицу заносится с опозданием на две-три-пять секунд, чем в банк. Но ведь я же определяю значение один раз, а потом его подставляю в нужном месте. Вернее, в двух нужных местах. Если бы я писал везде не значение выражения, а само выражение, и оно вычислялось бы каждый раз по новой, то теоретически можно было предположить, что скрипт медленно работает. Но к функции sprintf, насколько я помню, слово "медленный" не относится! И вообще, функции обработки строк - одни из самых быстрых в PHP. Можно поверить в то, что медленно добавляется запись в базу данных (тем более, когда речь идет о друпале!), медленно идет запрос по cUrl. Но чтобы строки обрабатывались медленно... Это слишком кругло для моей квадратной головы.

 

[AnrDaemon]

Ещё раз, медленно.
Бери отладчик и смотри по шагам, что у тебя творится при выполнении скрипта.

 

[borodul]

Ещё раз, медленно.
Бери отладчик и смотри по шагам, что у тебя творится при выполнении скрипта.

Посмотрел. Правда, отладчик не взял - не могу я никаким отладчиком к серверу подцепиться к этому. Доступа упорно не дают.
Ну да ладно. Вставил в код в 4 местах функцию mail, в которой указал свой адрес, и переслал ей номер заказа. Вставил ее в четырех местах, писем получил 8. Итого, если учесть, что функция theme_имя_формы_form в друпале запускается всего один раз, получается, что за один раз страница грузится как бы дважды. Весьма вероятно, что виноват какой-то "вредоносный" (т.е. вероятно, очень нужный и полезный) HTML-код, который заставляет грузиться страницу еще раз - с задержкой в 2-4 секунды.

Как вы думаете, ребята, может быть в этом виноват

<link rel="canonical" href="<?php echo $_SERVER['REQUEST_URI']; ?>">

?
У них эта хрень везде понатыкана, а я только что прочитал, что делать так нельзя.

 

[borodul]

Таким образом, становится понятно, что PHP ни в чем не виноват. Понятно становится и то, почему в базе значение "моложе" на несколько секунд, чем в банке. Просто страница второй раз грузится где-то за кадром. В результате получаем значение в базе новое, а значение в банке - старое.

 

[c0dex]

Кхм, а не favicon ли это с рерайтами .

 

[Breeze]

Кхм, а не favicon ли это с рерайтами .

классическая 404/background=#ffffff о чем написал выше

 

[borodul]

классическая 404/background=#ffffff о чем написал выше

Не подскажете ли Вы, коли проблема уже таки показала свои уши, лапы и хвосты, можно ли решить сей момент добавлением пути, по которому грузится сей скрипт, в robots.txt? Написать туда Disallow: /cart/checkout/review и шабаш, правильно? Мне кажется, это неправильно - что страница подтверждения заказа индексируется поисковиками. Я просто в этой теме уже плаваю, как...
Я попытался отследить firebug`ом, откуда при загрузке страница вызывается еще раз. Там куча всяких вызовов, а link canonical на каждой странице всего 1.

 

[Breeze]

оформление и отправку данных надо как минимум делать методом POST, чтобы избежать большинства неприятностей