Офіційний блог DIBAL Ukraine про вагові технології

Новини та анонси Dibal Украина.

Детектив на 38 регістрів: пошук і усунення логічної колізії у ПЗ Dibal та СУБД MySQL 5.0

Dibal LS4000 / Dibal DIS Dashboard

З початку 2026 року у клієнта спостерігалась нестабільна робота системи передачі даних на маркувальне обладнання Dibal. Помилка довгий час вважалась наслідком дій операторів — поки детальний аналіз не вказав на приховану логічну колізію у СУБД MySQL 5.0.

Вступ і постановка задачі

Проблема проявлялась хаотично: при відправці товарів через RGI частина текстових полів (з 12 по 30), що містили інформацію для етикетки різними мовами, інколи не передавалась на обладнання — хоча дані коректно потрапляли у DIS. Через неповну передачу інформації на лінію виходили упаковки з некоректними або неповними етикетками.

Після аналізу логів та виїзної діагностики вдалось підтвердити, що проблема відтворюється на стороні програмного забезпечення Dibal DIS версії 1.11W.

Особливість інциденту полягала в тому, що помилка виникала непередбачувано: один і той же набір даних міг бути переданий коректно або частково — лише при зміні коду товару. За результатами тестування, ймовірність виникнення проблеми складала близько 30% відправлень.

Вихідні дані архітектури

  • Операційна система: Windows 10.
  • Керуюче ПЗ: Служба RGI_i.exe — компонент інтеграційного пакету Dibal DIS. Моніторить директорію C:/DibalExport. При появі файлу importas2.xlsx парсить його, транслює дані по протоколу TCP пакетами-регістрами на LS4000 та виконує запис до локальної СУБД MySQL. Після завершення циклу файл переміщується до C:\Program Files (x86)\Dibal\DIS\RGI\Processed files з додаванням часового штампу YYYYMMDDHHmmss_Importas2.xlsx.
  • СУБД: MySQL Server 5.0.19-nt (база даних sys_datos_dis, рушій таблиць InnoDB).
  • Обладнання: Ваговимірювальний комплекс Dibal LS4000 (порт 3000).
  • Еталонний показник: При штатному циклі імпорту ПЗ повідомляє в консоль: «Передано 38 записів».

Постановка проблеми

В певний момент часу поведінка комплексу змінилась. При відправці файлу з певним ідентифікатором товару (ID=5) утиліта RGI_i.exe відправляла на ваги лише 15 записів, після чого коректно (без падіння процесу) завершувала цикл і переміщувала файл до архіву.

Ключові симптоми: Перезапуск служби RGI_i.exe та повне перезавантаження ОС сервера не усували аномалію. Якщо в тому ж файлі Excel змінити значення комірки ID з 5 на 1 — утиліта миттєво відпрацьовувала штатно, передаючи всі 38 записів.

Чому стандартні логи не показували проблему?

Застосунок RGI_i.exe не логує кількість рядків, повернених MySQL-запитом — лише результат відправки. Якщо MySQL повернув 15 рядків, застосунок чесно відправив 15 пакетів і написав «Передано 15 записів». З точки зору застосунку — все штатно.

Висновок: Логи на рівні застосунку описують те, що процес зробив, але не те, чому він отримав менше даних, ніж мав. Спускайтесь на рівень нижче.

Хронологія розслідування та етапи локалізації

Етап 1: Розгортання лабораторного стенду та перевірка первинних гіпотез

Оскільки з подібною містичною поведінкою системи за 6 років експлуатації ми зіткнулись вперше, проведення тестів на «живому» сервері клієнта було неприпустимо. Прийнято рішення ізолювати проблему у контрольованому середовищі.

Дія: З об'єкту клієнта було вилучено: резервну копію бази даних MySQL, оригінальні лог-файли та файли імпорту importas2.xlsx. У лабораторії розгорнуто два ідентичних незалежних стенди, що повністю дублювали бойове оточення: серверна частина (MySQL 5.0 + DIS Suite + RGI_i.exe) та апаратна частина (фізичні машини Dibal LS4000).

Результат: Ми методично гоняли імпорт файлів, намагаючись зловити момент, коли система спіткнеться. Удача посміхнулась на одному зі стендів: як тільки у файлі імпорту ID товару змінено на 5, конвеєр завантаження зламався — ваги прийняли лише 15 записів (регістрів) замість належних 38. Стабільний баг спійманий у контрольованому середовищі.

Гіпотеза №1: Зависання процесу / витік пам'яті / кеш ОС. Перезапуск служби, примусова очистка пулу потоків, повне перезавантаження ОС сервера — результат від'ємний. Після перезавантаження при першому ж циклі звернення до ID=5 трансляція обривалась на 15 пакетах. Висновок: Проблема має персистентний (постійний) характер і жорстко зафіксована у структурі даних СУБД.

Етап 2: Мережевий аналіз та дешифровка TCP-трафіку

Гіпотеза №2: Апаратний збій ваг або спотворення пакетів на фізичному рівні. Передбачалось, що ваги Dibal LS4000 нативно відбраковують специфічну послідовність байт, що генерується при обробці ID=5, або мережевий стек ОС некоректно обробляє сокет.

Дія: Між процесом RGI_i.exe та вагами включено сніфер трафіку Packet Sender, налаштований на прослуховування порту 3000. Перехоплено байтові потоки для обох сценаріїв.

Результат: Аналіз сирого трафіку показав, що мережа працює ідеально. Формат команд Dibal DIS повністю відповідав специфікації. Пакети летіли у абсолютно правильному порядку, підтвердження (ACK) від ваг приходили без затримок. Сніфер зафіксував:

  • Для ID=1: Успішні транзакції TCP Send, після чого ініціалізувався TCP Disconnect.
  • Для ID=5: Успішні транзакції TCP Send, після чого з боку сервера летів пакет закриття сесії FIN/ACK.
Висновок: LS4000 та мережа не винні. Процес RGI_i.exe сам, за власною ініціативою, приймає рішення закрити сокет після відправки 15 записів. Мережевий слід привів назад всередину сервера.

Етап 3: Порядковий аналіз системних журналів (Process Monitor)

Оскільки ПЗ працювало і не генерувало виключень (Exception), потребувалось дослідити його взаємодію з ОС та СУБД на рівні ядра.

Дія: Запущено Process Monitor. У диспетчері фільтрів встановлено правила: Process Name IS RGI_i.exe та Process Name IS mysqld-nt.exe.

  1. Запуск файлу з ID=5 (збій) → Експорт у Logfile.CSV.
  2. Запуск файлу з ID=1 (норма) → Експорт у LogfileGood.CSV.

Знято два трейси: Logfile.CSV (12 373 рядки) та LogfileGood.CSV (14 906 рядків).

Аналіз трейсів: що показав Process Monitor

Кількість TCP-пакетів до ваг — підтвердження

BAD — ID=5 (15 пакетів)
"16:14:26,6170903","RGI_i.exe","13840","TCP Send",
  "IGPRESTADO3.deriods.local:57652 -> 192.168.150.144:3000",
  "SUCCESS","Length: 130, startime: 2614704, ..."
GOOD — ID=1 (38 пакетів)
"16:27:34,6402458","RGI_i.exe","13840","TCP Send",
  "IGPRESTADO3.deriods.local:57782 -> 192.168.150.144:3000",
  "SUCCESS","Length: 130, startime: 2693506, ..."

Обидва пакети ідентичні за структурою: 130 байт, одне з'єднання. BAD відправив рівно 15 таких пакетів та зупинився. GOOD — 38.

Перша відмінність: звернення до файлів схеми MySQL (.frm)

Це і є ключова аномалія:

МетрикаBADGOOD
Звернень до .frm-файлів2822
Таблиць з повним читанням схеми260
Звернень до dat_articulo_t_b.frm90

В MySQL 5.0 файл .frm містить схему таблиці. В нормі схема кешується у table_cache. Якщо MySQL вимушений повторно читати .frm з диску — це може означати, що кеш було скинуто. Причина скидання: виконання запиту, який зажадав тимчасової перебудови структури — наприклад, складний JOIN з великою кількістю рядків в одній із таблиць.

З трейса BAD, вікно підготовки даних (між виявленням файлу та першим TCP-пакетом до ваг):

Process Monitor — BAD (dat_articulo_t_b.frm)
"16:14:26,2334247","mysqld-nt.exe","1980","CreateFile",
  "...sys_datos_dis\dat_articulo_t_b.frm",
  "SUCCESS","Desired Access: Generic Read, Disposition: Open..."

"16:14:26,2334766","mysqld-nt.exe","1980","ReadFile",
  "...dat_articulo_t_b.frm",
  "SUCCESS","Offset: 0, Length: 64, Priority: Normal"

"16:14:26,2335120","mysqld-nt.exe","1980","ReadFile",
  "...dat_articulo_t_b.frm","SUCCESS","Offset: 64, Length: 7"

"16:14:26,2335241","mysqld-nt.exe","1980","ReadFile",
  "...dat_articulo_t_b.frm","SUCCESS","Offset: 4096, Length: 104"

"16:14:26,2335866","mysqld-nt.exe","1980","CloseFile",
  "...dat_articulo_t_b.frm","SUCCESS",""

"16:14:26,2341394","mysqld-nt.exe","1980","CreateFile",
  "...dat_articulo_t_b.TRG","NAME NOT FOUND",
  "Desired Access: Read Attributes, Disposition: Open..."

MySQL читає схему dat_articulo_t_b повністю з диску (5 послідовних ReadFile по всіх секціях .frm-файлу), потім намагається знайти тригер .TRG — і не знаходить його (NAME NOT FOUND). У GOOD-сценарії цих операцій немає взагалі: схема була у кеші.

Повна часова шкала інциденту

BAD — 15 пакетів
16:14:26,0897  RGI виявляє Importas2.xlsx
16:14:26,1825  MySQL створює тимчасову таблицю — початок JOIN-запиту
16:14:26,2334  MySQL читає dat_articulo_t_b.frm з диску (НЕ з кешу!)
16:14:26,6171  RGI відправляє ПЕРШИЙ регістр (130 байт) → ваги :3000
16:14:27,0705  RGI відправляє ОСТАННІЙ регістр — підсумок: 15 відправлено
16:14:27,0778  RGI пише в EnvioModificaciones_log — сесія завершена
GOOD — 38 пакетів
16:27:34,1800  RGI виявляє Importas2.xlsx
16:27:34,2683  MySQL створює тимчасову таблицю — початок JOIN-запиту
               [.frm файли НЕ читаються — схема у кеші]
16:27:34,6402  RGI відправляє ПЕРШИЙ регістр (130 байт) → ваги :3000
16:27:35,4631  RGI відправляє ОСТАННІЙ регістр — підсумок: 38 відправлено
16:27:35,4705  RGI пише в EnvioModificaciones_log — сесія завершена

Характеристики передачі

МетрикаBADGOOD
Пакетів відправлено1538
Байт відправлено1 9504 420
Тривалість передачі0,453 сек0,823 сек
Час на пакет30,2 мс24,2 мс
Розмір кожного пакету130 байт130 байт

Корінна причина: дублікати у dat_articulo_t_b

Process Monitor вказав на dat_articulo_t_b як на аномальну точку. Наступний крок — аналіз вмісту таблиці напряму.

Структура таблиці

SQL — DDL таблиці
CREATE TABLE `dat_articulo_t_b` (
  `IdArticulo`  int(11) NOT NULL,
  `IdEmpresa`   int(11) NOT NULL DEFAULT '1',
  `IdTienda`    int(11) NOT NULL DEFAULT '1',
  `IdBalanza`   int(11) NOT NULL DEFAULT '0',
  -- ... поля стану ...
  PRIMARY KEY (`IdEmpresa`, `IdTienda`, `IdBalanza`, `IdArticulo`),
  KEY BusquedaArticulos (`IdEmpresa`, `IdArticulo`)
) ENGINE=InnoDB ROW_FORMAT=DYNAMIC;

Таблиця є зв'язковою: вона зберігає, які артикули (IdArticulo) призначено на які ваги (IdBalanza). Саме по ній RGI будує список регістрів для відправки.

Дублікати у даних

У таблиці були присутні записи з однаковим IdArticulo=5 для однакових IdTienda/IdBalanza, що неможливо при дотриманні PRIMARY KEY. Це могло статись через прямий імпорт даних в обхід обмежень або при використанні INSERT IGNORE / REPLACE INTO.

SQL — приклад записів з дампу клієнта
-- Коректні записи (різні IdBalanza)
(5,1,1,1, 0,0,0,0,0,0,'M','usuario','2024-07-05 08:36:29'),
(5,1,1,2, 0,0,0,0,0,0,'M','usuario','2024-07-05 08:36:29'),

При наявності дублів MySQL змушений виконувати запит без використання індексу на частині шляху — еквівалент повного сканування з дедуплікацією. Це призводить до:

  1. Скидання table_cache (звідси — читання .frm з диску).
  2. Повернення непередбачуваної підмножини рядків замість повного результату.
  3. Відсутності будь-яких помилок у логах — MySQL технічно виконав запит успішно.

Чому залежить від значення ID?

RGI_i.exe будує список відправки, запитуючи dat_articulo_t_b з фільтром по IdArticulo. При ID=5 (з дублями) — запит потрапляв у деградований шлях виконання. При іншому ID — використовувався нормальний індексний шлях, що повертав усі 38 рядків.

Саме тому: перезапуск застосунку не допомагав — стан зберігався у MySQL; проблема була детерміновано відтворюваною за значенням ID; власні логи RGI були чистими — застосунок коректно працював з тими даними, що йому повернула БД.

Реалізовані рішення та ліквідація наслідків

Оскільки проблема полягала у пошкодженні логічних зв'язків конкретних рядків, стандартні утиліти відновлення таблиць (REPAIR TABLE неприйнятний для InnoDB, а OPTIMIZE TABLE перебудовував фізичну структуру файлів, не видаляючи логічні колізії даних всередині рядків) виявились неефективними.

Очищення пошкоджених сутностей у СУБД

Для повної ліквідації заклинілих індексів прийнято рішення примусово очистити всі дані з таблиці dat_articulo_t_b, змусивши ПЗ відтворити її структуру з чистого аркушу.

На тестовому стенді (а потім і на бойовому сервері) зупинено службу RGI_i.exe та виконано наступний SQL-скрипт:

SQL — скрипт відновлення
-- Перемикання на цільову БД
USE `sys_datos_dis`;

-- Видалення заклинілих записів артикула з ключових таблиць
DELETE FROM `dat_articulo_t_b` WHERE `IdArticulo` > 0;

-- Відтворення таблиці з повною перебудовою даних і індексів
ALTER TABLE `dat_articulo_t_b` ENGINE=InnoDB;

-- Скидання глобального кешу запитів СУБД
RESET QUERY CACHE;
FLUSH TABLES;
✅ Результат: Після запуску служби RGI_i.exe та повторної подачі файлу з ID=5 утиліта ініціалізувала запис у СУБД «з нуля». Конвеєр успішно пройшов усі стадії, і на ваги LS4000 полетіли штатні 38 записів. Проблему повністю усунуто.

Висновки та Post-Mortem

Цей інцидент — класичний приклад того, як специфіка обробки помилок у ПЗ може маскувати проблеми у СУБД. Програма не видавала статус ERROR або CRITICAL, вона виконувала логічно легітимний (з її точки зору) цикл роботи, ґрунтуючись на спотворених даних, що повертались MySQL.

Ключові висновки

1
Не довіряйте логам застосунків. Якщо інтерфейс утиліти рапортує про статус SUCCESS або штатне завершення роботи, але результат не відповідає еталону — спускайтесь на рівень нижче (до системних викликів ядра ОС).
2
Диференціальний аналіз логів — ключ до успіху. Маючи під рукою ProcMon, завжди знімайте два логи — збійний та еталонний. Порядкове порівняння моментів розходження траєкторій процесів заощаджує години роботи.
3
InnoDB потребує контролю логічної цілісності. Механізми ACID в InnoDB захищають базу від руйнування файлів, але логічні колізії всередині бізнес-логіки ПЗ можуть призводити до прихованих відмов транзакцій.

The 38-Register Detective: Finding and Fixing a Logic Collision in Dibal Software and MySQL 5.0

Dibal LS4000 / Dibal DIS Dashboard

Since early 2026, a client had been experiencing intermittent failures in the data transmission system for Dibal labelling equipment. The error was long assumed to be operator-related — until detailed analysis revealed a hidden logic collision inside MySQL 5.0.

Introduction and Problem Statement

The problem appeared randomly: when sending products via RGI, some text fields (12 through 30) containing multi-language label information were occasionally not transmitted to the equipment — even though the data arrived correctly in DIS. As a result, packages left the line with incorrect or incomplete labels.

After log analysis and on-site diagnostics it was confirmed that the issue was reproducible on the software side of Dibal DIS version 1.11W.

The unusual aspect was that the error occurred unpredictably: the same data set could be transmitted fully or partially — solely depending on the product code. Testing showed the problem occurred in approximately 30% of send operations.

System Architecture

  • Operating System: Windows 10.
  • Control Software: Service RGI_i.exe — component of the Dibal DIS integration package. Monitors directory C:/DibalExport. When importas2.xlsx appears, it parses the file, transmits data via TCP as register packets to the LS4000, and writes to the local MySQL database. After the cycle the file is moved to C:\Program Files (x86)\Dibal\DIS\RGI\Processed files with timestamp YYYYMMDDHHmmss_Importas2.xlsx.
  • Database: MySQL Server 5.0.19-nt (database sys_datos_dis, table engine InnoDB).
  • Hardware: Dibal LS4000 weighing system (port 3000).
  • Baseline: On a normal import cycle the software reports to console: "38 records transmitted."

The Problem

At a certain point, the system behaviour changed. When sending a file with product identifier ID=5, RGI_i.exe sent only 15 records to the scale, then cleanly (without crashing) completed the cycle and moved the file to the archive.

Key symptoms: Restarting the RGI_i.exe service and fully rebooting the server OS did not resolve the anomaly. Changing the ID cell in the Excel file from 5 to 1 made the utility process all 38 records immediately.

Why Did Standard Logs Not Show the Problem?

RGI_i.exe does not log the number of rows returned by the MySQL query — only the result of the send operation. If MySQL returned 15 rows, the application faithfully sent 15 packets and logged "15 records transmitted." From the application's perspective, everything was fine.

Conclusion: Application-level logs describe what the process did, not why it received fewer data than it should have. Go one level deeper.

Investigation Timeline and Localisation Stages

Stage 1: Lab Bench Setup and Initial Hypothesis Testing

Since this was the first time in 6 years of operation that we encountered such mysterious behaviour, running tests on the client's live server was out of the question. The decision was made to isolate the problem in a controlled environment.

Action: A MySQL database backup, original log files, and importas2.xlsx import files were retrieved from the client's site. Two identical independent benches were deployed in the lab, fully replicating the production environment: server side (MySQL 5.0 + DIS Suite + RGI_i.exe) and hardware side (physical Dibal LS4000 machines).

Result: We methodically ran file imports, trying to catch the moment the system stumbled. On one bench, luck struck: as soon as the product ID was changed to 5, the loading pipeline broke — the scale received only 15 records (registers) instead of the expected 38. The stable bug was caught in a controlled environment.

Hypothesis #1: Process hang / memory leak / OS cache. Service restart, forced thread pool cleanup, full OS reboot — result: negative. After the reboot, on the very first cycle with ID=5, transmission broke at 15 packets. Running ID=1, ID=2, or ID=3 in parallel passed fine. Conclusion: The problem is persistent and firmly embedded in the database structure.

Stage 2: Network Analysis and TCP Traffic Decryption

Hypothesis #2: Hardware fault in the scale or packet corruption at the physical layer.

Action: The traffic sniffer Packet Sender was placed between RGI_i.exe and the scale, listening on port 3000. Byte streams were captured for both scenarios.

Result: Raw traffic analysis showed the network was working perfectly. The Dibal DIS command format fully matched the specification. Packets arrived in exactly the right order; ACK confirmations from the scale came without delays. The sniffer recorded:

  • For ID=1: Successful TCP Send transactions, followed by TCP Disconnect.
  • For ID=5: Successful TCP Send transactions, followed by a FIN/ACK session close packet from the server side.
Conclusion: The LS4000 and the network are not at fault. The RGI_i.exe process itself decides to close the socket after sending 15 records. The network trail led back inside the server.

Stage 3: Line-by-Line System Log Analysis (Process Monitor)

Since the software was running without throwing exceptions, we needed to examine its interaction with the OS and database at the kernel level.

Action: Process Monitor was launched with filters: Process Name IS RGI_i.exe and Process Name IS mysqld-nt.exe.

  1. Run file with ID=5 (failure) → Export to Logfile.CSV.
  2. Run file with ID=1 (normal) → Export to LogfileGood.CSV.

Two traces were captured: Logfile.CSV (12,373 lines) and LogfileGood.CSV (14,906 lines).

Trace Analysis: What Process Monitor Revealed

TCP Packet Count to the Scale — Confirmation

BAD — ID=5 (15 packets)
"16:14:26,6170903","RGI_i.exe","13840","TCP Send",
  "IGPRESTADO3.deriods.local:57652 -> 192.168.150.144:3000",
  "SUCCESS","Length: 130, startime: 2614704, ..."
GOOD — ID=1 (38 packets)
"16:27:34,6402458","RGI_i.exe","13840","TCP Send",
  "IGPRESTADO3.deriods.local:57782 -> 192.168.150.144:3000",
  "SUCCESS","Length: 130, startime: 2693506, ..."

Both packets are structurally identical: 130 bytes, one connection. BAD sent exactly 15 such packets and stopped. GOOD — 38.

First Difference: MySQL Schema File (.frm) Accesses

This is the key anomaly:

MetricBADGOOD
Accesses to .frm files2822
Tables with full schema read260
Accesses to dat_articulo_t_b.frm90

In MySQL 5.0, the .frm file contains the table schema. Normally it is cached in table_cache. If MySQL is forced to re-read .frm from disk, the cache has been flushed — caused by a query that required temporary structural rebuilding, such as a complex JOIN against a table with a large or corrupted row set.

Process Monitor — BAD (dat_articulo_t_b.frm)
"16:14:26,2334247","mysqld-nt.exe","1980","CreateFile",
  "...sys_datos_dis\dat_articulo_t_b.frm",
  "SUCCESS","Desired Access: Generic Read, Disposition: Open..."

"16:14:26,2334766","mysqld-nt.exe","1980","ReadFile",
  "...dat_articulo_t_b.frm","SUCCESS","Offset: 0, Length: 64"

"16:14:26,2335120","mysqld-nt.exe","1980","ReadFile",
  "...dat_articulo_t_b.frm","SUCCESS","Offset: 64, Length: 7"

"16:14:26,2335241","mysqld-nt.exe","1980","ReadFile",
  "...dat_articulo_t_b.frm","SUCCESS","Offset: 4096, Length: 104"

"16:14:26,2335866","mysqld-nt.exe","1980","CloseFile",
  "...dat_articulo_t_b.frm","SUCCESS",""

"16:14:26,2341394","mysqld-nt.exe","1980","CreateFile",
  "...dat_articulo_t_b.TRG","NAME NOT FOUND",
  "Desired Access: Read Attributes, Disposition: Open..."

MySQL reads the dat_articulo_t_b schema entirely from disk (5 sequential ReadFile operations across all .frm sections), then attempts to find a trigger file .TRG — and fails (NAME NOT FOUND). In the GOOD scenario, none of these operations occur: the schema was in cache.

Full Incident Timeline

BAD — 15 packets
16:14:26.0897  RGI detects Importas2.xlsx
16:14:26.1825  MySQL creates temp table — start of JOIN query
16:14:26.2334  MySQL reads dat_articulo_t_b.frm from DISK (NOT from cache!)
16:14:26.6171  RGI sends FIRST register (130 bytes) → scale :3000
16:14:27.0705  RGI sends LAST register — total: 15 sent
16:14:27.0778  RGI writes to EnvioModificaciones_log — session closed
GOOD — 38 packets
16:27:34.1800  RGI detects Importas2.xlsx
16:27:34.2683  MySQL creates temp table — start of JOIN query
               [.frm files NOT read — schema is in cache]
16:27:34.6402  RGI sends FIRST register (130 bytes) → scale :3000
16:27:35.4631  RGI sends LAST register — total: 38 sent
16:27:35.4705  RGI writes to EnvioModificaciones_log — session closed

Transmission Statistics

MetricBADGOOD
Packets sent1538
Bytes sent1,9504,420
Transfer duration0.453 sec0.823 sec
Time per packet30.2 ms24.2 ms
Each packet size130 bytes130 bytes

Root Cause: Duplicates in dat_articulo_t_b

Process Monitor pointed to dat_articulo_t_b as the anomalous point. The next step was to analyse the table contents directly.

Table Structure

SQL — Table DDL
CREATE TABLE `dat_articulo_t_b` (
  `IdArticulo`  int(11) NOT NULL,
  `IdEmpresa`   int(11) NOT NULL DEFAULT '1',
  `IdTienda`    int(11) NOT NULL DEFAULT '1',
  `IdBalanza`   int(11) NOT NULL DEFAULT '0',
  -- ... status fields ...
  PRIMARY KEY (`IdEmpresa`, `IdTienda`, `IdBalanza`, `IdArticulo`),
  KEY BusquedaArticulos (`IdEmpresa`, `IdArticulo`)
) ENGINE=InnoDB ROW_FORMAT=DYNAMIC;

The table is a junction table: it stores which items (IdArticulo) are assigned to which scales (IdBalanza). RGI uses it to build the register list for transmission.

Duplicate Records

The table contained records with the same IdArticulo=5 for the same IdTienda/IdBalanza combination — which should be impossible given the PRIMARY KEY constraint. This could have occurred through direct data import bypassing constraints, or via INSERT IGNORE / REPLACE INTO.

When duplicates exist, MySQL is forced to execute the query without using the index for part of the path — the equivalent of a full scan with deduplication. This causes:

  1. table_cache flush (hence reading .frm from disk).
  2. Return of an unpredictable subset of rows instead of the full result set.
  3. No errors in any logs — MySQL technically executed the query successfully.

Why Does the Behaviour Depend on the ID Value?

RGI_i.exe builds the send list by querying dat_articulo_t_b filtered by IdArticulo. With ID=5 (containing duplicates) the query fell into a degraded execution path. With any other ID, the normal index path was used and all 38 rows were returned.

That is why: restarting the application did not help — the state resided in MySQL; the problem was deterministically reproducible by ID value; RGI's own logs were clean — the application worked correctly with the data MySQL returned.

Solution Implementation

Since the problem lay in corrupted logical links of specific rows, standard table recovery utilities were ineffective (REPAIR TABLE is not applicable to InnoDB; OPTIMIZE TABLE rebuilt the physical file structure without removing the logical data collisions within rows).

Purging Damaged Entities from the Database

To fully eliminate the stuck indexes, the decision was made to forcibly clear all data from the dat_articulo_t_b table, allowing the software to recreate its structure from scratch.

On the test bench (then on the production server) the RGI_i.exe service was stopped and the following SQL script was executed:

SQL — Recovery Script
-- Switch to target database
USE `sys_datos_dis`;

-- Remove stuck article records from key tables
DELETE FROM `dat_articulo_t_b` WHERE `IdArticulo` > 0;

-- Rebuild table with full data and index reconstruction
ALTER TABLE `dat_articulo_t_b` ENGINE=InnoDB;

-- Flush global query cache
RESET QUERY CACHE;
FLUSH TABLES;
✅ Result: After restarting RGI_i.exe and submitting the file with ID=5, the utility initialised the database write from scratch. The pipeline successfully passed all stages, and the LS4000 received the full 38 records. Problem fully resolved.

Conclusions and Post-Mortem

This incident is a classic example of how error-handling specifics in software can mask database problems. The application produced no ERROR or CRITICAL status — it performed a logically legitimate (from its perspective) work cycle based on distorted data returned by MySQL.

Key Takeaways

1
Don't trust application logs. If the utility reports SUCCESS but the result doesn't match the expected baseline — go one level deeper (OS kernel system calls).
2
Differential log analysis is the key. With ProcMon available, always capture two traces — the failing one and the baseline. Line-by-line comparison of where process paths diverge saves hours of work.
3
InnoDB requires logical integrity monitoring. ACID mechanisms in InnoDB protect against file corruption, but logical collisions within business logic can lead to silent transaction failures.

El Detective de los 38 Registros: Localización y Resolución de una Colisión Lógica en el Software Dibal y MySQL 5.0

Dibal LS4000 / Dibal DIS Dashboard

Desde principios de 2026, un cliente presentaba fallos intermitentes en el sistema de transmisión de datos al equipo de etiquetado Dibal. Durante mucho tiempo el error se atribuyó a los operadores — hasta que un análisis detallado reveló una colisión lógica oculta dentro de MySQL 5.0.

Introducción y Planteamiento del Problema

El problema se manifestaba de forma aleatoria: al enviar artículos a través de RGI, una parte de los campos de texto (del 12 al 30), que contenían información para la etiqueta en diferentes idiomas, no se transmitía al equipo, aunque los datos llegaban correctamente a DIS. Debido a la transmisión incompleta, los envases salían a la línea con etiquetas incorrectas o incompletas.

Tras el análisis de registros y el diagnóstico in situ, se confirmó que el problema era reproducible en el lado del software Dibal DIS versión 1.11W.

La peculiaridad del incidente era que el error ocurría de forma impredecible: el mismo conjunto de datos podía transmitirse completa o parcialmente, dependiendo únicamente del código del artículo. Según las pruebas, la probabilidad de error era de aproximadamente el 30% de los envíos.

Arquitectura del Sistema

  • Sistema Operativo: Windows 10.
  • Software de Control: Servicio RGI_i.exe — componente del paquete de integración Dibal DIS. Monitorea el directorio C:/DibalExport. Al detectar el archivo importas2.xlsx, lo analiza, transmite los datos mediante paquetes-registro TCP al LS4000 y escribe en la base de datos MySQL local. Al finalizar el ciclo, el archivo se mueve a C:\Program Files (x86)\Dibal\DIS\RGI\Processed files con marca de tiempo YYYYMMDDHHmmss_Importas2.xlsx.
  • Base de Datos: MySQL Server 5.0.19-nt (base de datos sys_datos_dis, motor de tablas InnoDB).
  • Hardware: Sistema de pesaje Dibal LS4000 (puerto 3000).
  • Indicador de referencia: En un ciclo de importación normal, el software reporta en consola: «Se transmitieron 38 registros».

Descripción del Problema

En un momento dado, el comportamiento del sistema cambió. Al enviar un archivo con el identificador de artículo ID=5, la utilidad RGI_i.exe enviaba a la balanza únicamente 15 registros, tras lo cual completaba el ciclo correctamente (sin caída del proceso) y movía el archivo al archivo histórico.

Síntomas clave: Reiniciar el servicio RGI_i.exe y reiniciar completamente el SO del servidor no resolvía la anomalía. Si en ese mismo archivo Excel se cambiaba el valor de la celda ID de 5 a 1, la utilidad procesaba inmediatamente todos los 38 registros.

¿Por Qué los Registros Estándar No Mostraban el Problema?

La aplicación RGI_i.exe no registra el número de filas devueltas por la consulta MySQL — sólo el resultado del envío. Si MySQL devolvía 15 filas, la aplicación enviaba honestamente 15 paquetes y registraba «15 registros transmitidos». Desde el punto de vista de la aplicación, todo estaba en orden.

Conclusión: Los registros a nivel de aplicación describen lo que el proceso hizo, no por qué recibió menos datos de los que debería. Hay que descender un nivel más.

Cronología de la Investigación y Etapas de Localización

Etapa 1: Montaje del Banco de Pruebas y Verificación de Hipótesis Iniciales

Como era la primera vez en 6 años de operación que nos enfrentábamos a este comportamiento tan peculiar, realizar pruebas en el servidor en producción del cliente era inadmisible. Se decidió aislar el problema en un entorno controlado.

Acción: Se obtuvo del cliente una copia de seguridad de la base de datos MySQL, los archivos de registro originales y los archivos de importación importas2.xlsx. En el laboratorio se desplegaron dos bancos idénticos e independientes que replicaban completamente el entorno de producción: parte servidora (MySQL 5.0 + DIS Suite + RGI_i.exe) y parte hardware (máquinas físicas Dibal LS4000).

Resultado: Ejecutamos importaciones de archivo de forma metódica, intentando capturar el momento en que el sistema fallara. La suerte llegó en uno de los bancos: en cuanto el ID del artículo se cambió a 5, la tubería de carga se rompió — la balanza recibió sólo 15 registros en lugar de los 38 esperados. El error estable fue capturado en un entorno controlado.

Hipótesis #1: Bloqueo del proceso / fuga de memoria / caché del SO. Reinicio del servicio, limpieza forzada del pool de hilos, reinicio completo del SO — resultado negativo. Tras el reinicio, en el primer ciclo de acceso a ID=5, la transmisión se interrumpía en 15 paquetes. Conclusión: El problema es persistente y está firmemente arraigado en la estructura de datos de la base de datos.

Etapa 2: Análisis de Red y Descifrado del Tráfico TCP

Hipótesis #2: Fallo hardware de la balanza o corrupción de paquetes a nivel físico.

Acción: Se interpuso el capturador de tráfico Packet Sender entre el proceso RGI_i.exe y la balanza, configurado para escuchar el puerto 3000. Se capturaron flujos de bytes para ambos escenarios.

Resultado: El análisis del tráfico en bruto mostró que la red funcionaba perfectamente. El formato de los comandos Dibal DIS se ajustaba completamente a la especificación. Los paquetes llegaban en el orden correcto; las confirmaciones (ACK) de la balanza llegaban sin demoras. El capturador registró:

  • Para ID=1: Transacciones TCP Send exitosas, seguidas de TCP Disconnect.
  • Para ID=5: Transacciones TCP Send exitosas, seguidas de un paquete de cierre de sesión FIN/ACK desde el lado del servidor.
Conclusión: El LS4000 y la red no son responsables. El proceso RGI_i.exe, por iniciativa propia, decide cerrar el socket tras enviar 15 registros. La pista de red llevó de vuelta al interior del servidor.

Etapa 3: Análisis Línea a Línea de Registros del Sistema (Process Monitor)

Dado que el software funcionaba sin lanzar excepciones, fue necesario examinar su interacción con el SO y la base de datos a nivel del núcleo.

Acción: Se inició Process Monitor con filtros: Process Name IS RGI_i.exe y Process Name IS mysqld-nt.exe.

  1. Ejecución del archivo con ID=5 (fallo) → Exportar a Logfile.CSV.
  2. Ejecución del archivo con ID=1 (normal) → Exportar a LogfileGood.CSV.

Se capturaron dos trazas: Logfile.CSV (12.373 líneas) y LogfileGood.CSV (14.906 líneas).

Análisis de Trazas: Lo que Reveló Process Monitor

Recuento de Paquetes TCP a la Balanza — Confirmación

BAD — ID=5 (15 paquetes)
"16:14:26,6170903","RGI_i.exe","13840","TCP Send",
  "IGPRESTADO3.deriods.local:57652 -> 192.168.150.144:3000",
  "SUCCESS","Length: 130, startime: 2614704, ..."
GOOD — ID=1 (38 paquetes)
"16:27:34,6402458","RGI_i.exe","13840","TCP Send",
  "IGPRESTADO3.deriods.local:57782 -> 192.168.150.144:3000",
  "SUCCESS","Length: 130, startime: 2693506, ..."

Ambos paquetes son estructuralmente idénticos: 130 bytes, una conexión. BAD envió exactamente 15 paquetes y se detuvo. GOOD — 38.

Primera Diferencia: Accesos a Archivos de Esquema MySQL (.frm)

Esta es la anomalía clave:

MétricaBADGOOD
Accesos a archivos .frm2822
Tablas con lectura completa de esquema260
Accesos a dat_articulo_t_b.frm90

En MySQL 5.0, el archivo .frm contiene el esquema de la tabla. Normalmente se almacena en caché en table_cache. Si MySQL se ve obligado a releer .frm desde el disco, significa que el caché fue descartado — causado por una consulta que requirió una reconstrucción estructural temporal, como un JOIN complejo contra una tabla con un conjunto de filas grande o corrupto.

Process Monitor — BAD (dat_articulo_t_b.frm)
"16:14:26,2334247","mysqld-nt.exe","1980","CreateFile",
  "...sys_datos_dis\dat_articulo_t_b.frm",
  "SUCCESS","Desired Access: Generic Read, Disposition: Open..."

"16:14:26,2334766","mysqld-nt.exe","1980","ReadFile",
  "...dat_articulo_t_b.frm","SUCCESS","Offset: 0, Length: 64"

"16:14:26,2335120","mysqld-nt.exe","1980","ReadFile",
  "...dat_articulo_t_b.frm","SUCCESS","Offset: 64, Length: 7"

"16:14:26,2335241","mysqld-nt.exe","1980","ReadFile",
  "...dat_articulo_t_b.frm","SUCCESS","Offset: 4096, Length: 104"

"16:14:26,2335866","mysqld-nt.exe","1980","CloseFile",
  "...dat_articulo_t_b.frm","SUCCESS",""

"16:14:26,2341394","mysqld-nt.exe","1980","CreateFile",
  "...dat_articulo_t_b.TRG","NAME NOT FOUND",
  "Desired Access: Read Attributes, Disposition: Open..."

MySQL lee el esquema de dat_articulo_t_b íntegramente desde el disco (5 operaciones ReadFile secuenciales a través de todas las secciones del archivo .frm), luego intenta encontrar el archivo de trigger .TRG — y falla (NAME NOT FOUND). En el escenario GOOD, ninguna de estas operaciones ocurre: el esquema estaba en caché.

Línea Temporal Completa del Incidente

BAD — 15 paquetes
16:14:26.0897  RGI detecta Importas2.xlsx
16:14:26.1825  MySQL crea tabla temporal — inicio de consulta JOIN
16:14:26.2334  MySQL lee dat_articulo_t_b.frm desde DISCO (¡NO desde caché!)
16:14:26.6171  RGI envía PRIMER registro (130 bytes) → balanza :3000
16:14:27.0705  RGI envía ÚLTIMO registro — total: 15 enviados
16:14:27.0778  RGI escribe en EnvioModificaciones_log — sesión cerrada
GOOD — 38 paquetes
16:27:34.1800  RGI detecta Importas2.xlsx
16:27:34.2683  MySQL crea tabla temporal — inicio de consulta JOIN
               [archivos .frm NO leídos — esquema en caché]
16:27:34.6402  RGI envía PRIMER registro (130 bytes) → balanza :3000
16:27:35.4631  RGI envía ÚLTIMO registro — total: 38 enviados
16:27:35.4705  RGI escribe en EnvioModificaciones_log — sesión cerrada

Estadísticas de Transmisión

MétricaBADGOOD
Paquetes enviados1538
Bytes enviados1.9504.420
Duración de transmisión0,453 seg0,823 seg
Tiempo por paquete30,2 ms24,2 ms
Tamaño de cada paquete130 bytes130 bytes

Causa Raíz: Registros Duplicados en dat_articulo_t_b

Process Monitor señaló dat_articulo_t_b como el punto anómalo. El siguiente paso fue analizar el contenido de la tabla directamente.

Estructura de la Tabla

SQL — DDL de la tabla
CREATE TABLE `dat_articulo_t_b` (
  `IdArticulo`  int(11) NOT NULL,
  `IdEmpresa`   int(11) NOT NULL DEFAULT '1',
  `IdTienda`    int(11) NOT NULL DEFAULT '1',
  `IdBalanza`   int(11) NOT NULL DEFAULT '0',
  -- ... campos de estado ...
  PRIMARY KEY (`IdEmpresa`, `IdTienda`, `IdBalanza`, `IdArticulo`),
  KEY BusquedaArticulos (`IdEmpresa`, `IdArticulo`)
) ENGINE=InnoDB ROW_FORMAT=DYNAMIC;

La tabla es una tabla de enlace: almacena qué artículos (IdArticulo) están asignados a qué balanzas (IdBalanza). RGI la utiliza para construir la lista de registros a enviar.

Registros Duplicados

La tabla contenía registros con el mismo IdArticulo=5 para la misma combinación IdTienda/IdBalanza — lo que debería ser imposible dada la restricción PRIMARY KEY. Esto pudo ocurrir mediante importación directa de datos saltándose las restricciones, o mediante INSERT IGNORE / REPLACE INTO.

Con duplicados presentes, MySQL se ve obligado a ejecutar la consulta sin usar el índice en parte del recorrido — equivalente a un escaneo completo con deduplicación. Esto provoca:

  1. Descarte del table_cache (de ahí la lectura de .frm desde disco).
  2. Devolución de un subconjunto impredecible de filas en lugar del conjunto completo.
  3. Ausencia de cualquier error en los registros — MySQL ejecutó técnicamente la consulta de forma exitosa.

¿Por Qué el Comportamiento Depende del Valor del ID?

RGI_i.exe construye la lista de envío consultando dat_articulo_t_b filtrado por IdArticulo. Con ID=5 (con duplicados), la consulta caía en una ruta de ejecución degradada. Con cualquier otro ID, se utilizaba la ruta normal con índice, devolviendo las 38 filas.

Por eso: reiniciar la aplicación no ayudaba — el estado residía en MySQL; el problema era reproducible de forma determinista por el valor del ID; los propios registros de RGI estaban limpios — la aplicación funcionaba correctamente con los datos que MySQL le devolvía.

Implementación de la Solución

Como el problema residía en la corrupción de los vínculos lógicos de filas específicas, las utilidades estándar de recuperación de tablas fueron ineficaces (REPAIR TABLE no es aplicable a InnoDB; OPTIMIZE TABLE reconstruía la estructura física de los archivos sin eliminar las colisiones lógicas dentro de las filas).

Eliminación de Entidades Dañadas de la Base de Datos

Para eliminar completamente los índices bloqueados, se decidió forzar el vaciado de todos los datos de la tabla dat_articulo_t_b, permitiendo al software recrear su estructura desde cero.

En el banco de pruebas (y luego en el servidor de producción) se detuvo el servicio RGI_i.exe y se ejecutó el siguiente script SQL:

SQL — Script de Recuperación
-- Cambiar a la base de datos objetivo
USE `sys_datos_dis`;

-- Eliminar los registros de artículo bloqueados de las tablas clave
DELETE FROM `dat_articulo_t_b` WHERE `IdArticulo` > 0;

-- Reconstruir la tabla con reconstrucción completa de datos e índices
ALTER TABLE `dat_articulo_t_b` ENGINE=InnoDB;

-- Vaciar la caché global de consultas
RESET QUERY CACHE;
FLUSH TABLES;
✅ Resultado: Tras reiniciar RGI_i.exe y enviar el archivo con ID=5, la utilidad inicializó la escritura en la base de datos desde cero. La tubería completó con éxito todas las etapas y la balanza LS4000 recibió los 38 registros completos. Problema completamente resuelto.

Conclusiones y Post-Mortem

Este incidente es un ejemplo clásico de cómo las particularidades del manejo de errores en el software pueden enmascarar problemas en la base de datos. La aplicación no generaba ningún estado ERROR o CRITICAL — ejecutaba un ciclo de trabajo lógicamente legítimo (desde su perspectiva) basándose en datos distorsionados devueltos por MySQL.

Conclusiones Clave

1
No confíe en los registros de la aplicación. Si la utilidad reporta SUCCESS pero el resultado no coincide con el esperado — descienda un nivel (a las llamadas del sistema del núcleo del SO).
2
El análisis diferencial de registros es la clave. Con ProcMon disponible, capture siempre dos trazas — la fallida y la de referencia. La comparación línea a línea de dónde divergen las trayectorias de los procesos ahorra horas de trabajo.
3
InnoDB requiere supervisión de la integridad lógica. Los mecanismos ACID de InnoDB protegen contra la corrupción de archivos, pero las colisiones lógicas dentro de la lógica de negocio pueden provocar fallos silenciosos de transacciones.