I am experiencing some strange behavior in MySQL using transactions. We have a PHP site that runs ~100 workstations inserting thousands of items (table 1) daily, with 4 to 7 logged events (table 2) at creation. Roughly 3 times a day we are having partial success of our inserts. There are up to 3 MySQL users that could be called from PHP, and an ODBC source involved, so hopefully I explain this well enough. Unfortunately the PHP is spaghetti code from a previous dev so I'm having troubles tracing it all. Previously I had replicated this problem on every creation by inadvertently reconnecting to the DB under a different user, and making that conditional fixed it, but it's back and about as intermittent as can be. I caught this the first time by logging queries in the test environment and finding a different connection ID in the middle of the script, but this is unfeasible for how many statements run and how sparsely the problem occurs.
MySQL users: hostingconnection - r/o to get basicdata's username/password from a different data source on the same MySQL instance basicdata - r/w for the project's standard tables admindata - r/w for the project's elevated privilege tables All users can be used to get the ODBC connection string from a table in the main data source
Say we're doing an insert into Table1, and 4 inserts into Table2. During the PHP script that creates the records I can access all data that was inserted (Table1's values being used in Table2 as an example). After the PHP script finishes, Table1's record is missing and so are Table2's first two inserts, but the 3rd and 4th inserts to Table2 still exist. No errors are logged, no rollback is triggered, and the commit is "successful" (based on return value of PHP mysqli_commit()
).
This time around I've programmed the PHP in all the connection scripts to send an email if they're hit when a transaction is already active, and none are being hit. I can find no other "way in", so does anyone know of other ways a transaction can be "successful" but missing the first half or so of a transaction?
EDIT: Posting the relevant SQL taken from the test environment. Some things to know:
- The transaction starts at
INSERT INTO objects
. - The first
INSERT INTO object_events
that remains is the value "level partno". - Ignore the "label print failed" message - that means server-side cups printing failed, which wasn't configured on the test environment. A success message would have been there instead.
- The
SELECT VALUE FROM company
statements had been the culprit in the previous issue - cannot confirm or deny, but my check for an existing transaction in that connect script does not trigger an email. They had unnecessarily triggeredmysqli_connect()
, which "reset" the transaction without an error. UPDATE workcenters
may or may not be successful - it is overwritten shortly after and I have no way to know what it was previously.- I am not explicitly setting autocommit, but I would think that
mysqli_begin_transaction()
andmysqli_commit()
would imply that autocommit is false. - The log would need to run more than a little while - failures happen at random times, around 3 times a day over a 10 hour period. Even 1/2 hour of logs for the MySQL general log is too large of a file to manage. Unfortunately this leaves me only the provided log from the test environment to go on.
- The fact that the object ID exists in subsequent writes to object_events tells me that the insert was successful, but somehow not committed. If a rollback happened the script would have ended and the user would have been notified of an error, which is not the case.
- Not using
mysqli_begin_transaction()
andmysqli_commit()
"fixes" the problem, but having good reason to use transactions we would rather fix the underlying issue instead of having a workaround.
SQL:
SELECT EMPLOYEE_ID,FIRSTNAME,LASTNAME,STATUS FROM employees WHERE EMPLOYEE_ID=706279
;
SELECT * FROM workcenters where ID=148
;
SELECT ee.EMPLOYEE_ID,ee.FIRSTNAME,ee.LASTNAME,ee.STATUS,IF(wa.EMPLOYEE_ID=ep.EMPLOYEE_ID,1,0) AS AUTHORIZED FROM employee_presence ep JOIN workcenters wc ON wc.ID=ep.WORKCENTER_ID JOIN employees ee ON (ee.EMPLOYEE_ID=ep.EMPLOYEE_ID) LEFT JOIN workcenter_authorization wa ON (wa.EMPLOYEE_ID=ee.EMPLOYEE_ID and wa.WORKCENTER_ID=wc.ID) WHERE ep.WORKCENTER_ID=148 GROUP BY ee.EMPLOYEE_ID
;
UPDATE `workcenters` SET SHOP_ORDER='', WIP=0 WHERE ID=148
;
UPDATE workcenters SET LABEL_QTY=1 WHERE ID=148
;
SELECT DESCRIPTION from `label_types` WHERE ID=2
;
SELECT *,GetPartName('714883') AS `PARTNAME` FROM part_names WHERE `PART#`='714883' LIMIT 1
;
SELECT *,GetPartName('714883') AS `PARTNAME` FROM part_names WHERE `PART#`='714883' LIMIT 1
;
SELECT * FROM label_templates WHERE LABEL_ID=(SELECT PACK_LABEL_ID FROM part_names WHERE `PART#`='714883') LIMIT 1
;
SELECT NAME from printers
;
UPDATE workcenters SET LAST_UPDATE=now(), PRINTER_SELECTED=1 WHERE ID=148
;
-- BEGIN TRANSACTION
INSERT INTO objects (`TYPE`,`PART_NUMBER`,`LEVEL_PART_NUMBER`,`STATUS`,`QUANTITY`,`LOCATION`) VALUES ('COMPONENT','714883','714883','',375,'R1')
;
SELECT * FROM objects WHERE ID=LAST_INSERT_ID()
;
INSERT INTO object_events SET OBJECT_ID=2637120,WORKCENTER_ID=148, EVENT_TYPE='created', PROPERTY='location',EVENT_TEXT='R1'
;
SELECT NewLabel(2637120,'ATS') AS BARCODE
;
SELECT VALUE FROM company WHERE KEYNAME='XPPS_CONN' LIMIT 1
;
SELECT VALUE FROM company WHERE KEYNAME='XPPS_USER' LIMIT 1
;
SELECT VALUE FROM company WHERE KEYNAME='XPPS_PASS' LIMIT 1
;
SELECT EMPLOYEE_ID FROM object_events_employees WHERE EVENT_ID=LAST_INSERT_ID()
;
UPDATE workcenters SET PART_NUMBER='714883',LEVEL_PART_NUMBER='714883',STD_TIME=0 WHERE ID=148
;
-- FIRST REMAINING RECORD HERE
INSERT INTO object_events SET OBJECT_ID=2637120,LAST_UPDATE=now(),WORKCENTER_ID=148,EVENT_TYPE='set property', PROPERTY='level partno', EVENT_TEXT='714883'
;
SELECT EMPLOYEE_ID FROM object_events_employees WHERE EVENT_ID=LAST_INSERT_ID()
;
INSERT INTO object_events SET OBJECT_ID=2637120,LAST_UPDATE=now(),WORKCENTER_ID=148,EVENT_TYPE='set property', PROPERTY='label template', EVENT_TEXT='5'
;
SELECT EMPLOYEE_ID FROM object_events_employees WHERE EVENT_ID=LAST_INSERT_ID()
;
SELECT * from printers WHERE NAME='Put-Away'
;
UPDATE workcenters SET LAST_UPDATE=now(), STATUS_MESSAGE='Printer does not respond, is it turned off?', MESSAGE_STATUS=2 WHERE ID=148
;
INSERT INTO object_events SET OBJECT_ID=2637120,LAST_UPDATE=now(),WORKCENTER_ID=148,EVENT_TYPE='label print failed',EVENT_TEXT='ATS3282328*'
;
-- COMMIT TRANSACTION
SELECT EMPLOYEE_ID FROM object_events_employees WHERE EVENT_ID=LAST_INSERT_ID()
;