Skip to content

Commit aa2b956

Browse files
kojiromikekojiromike
committed
fix(CodeImporter): identify lock and lock holder
1 parent 69b514f commit aa2b956

File tree

2 files changed

+199
-20
lines changed

2 files changed

+199
-20
lines changed

‎composer.json‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -140,8 +140,8 @@
140140
"rector": "rector process --dry-run",
141141
"rector-fix": "rector process",
142142
"test": "@phpunit",
143-
"test:unit": "vendor/bin/phpunit --testsuite unit --testdox",
143+
"test:e2e": "vendor/bin/phpunit -c phpunit-integration.xml --testsuite e2e --testdox",
144144
"test:integration": "vendor/bin/phpunit -c phpunit-integration.xml --testsuite integration --testdox",
145-
"test:e2e": "vendor/bin/phpunit -c phpunit-integration.xml --testsuite e2e --testdox"
145+
"test:unit": "vendor/bin/phpunit --testsuite unit --testdox"
146146
}
147147
}

‎src/Service/CodeImporter.php‎

Lines changed: 197 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -7,7 +7,7 @@
77
* @package OpenCoreEMR\CLI\ImportCodes
88
* @link https://opencoreemr.com
99
* @author Michael A. Smith <[email protected]>
10-
* @copyright Copyright (c) 2025 OpenCoreEMR Inc
10+
* @copyright Copyright (c) 2025-2026 OpenCoreEMR Inc
1111
* @license https://github.com/openemr/openemr/blob/master/LICENSE GNU General Public License 3
1212
*/
1313

@@ -25,7 +25,11 @@ class CodeImporter
2525
private bool $waitedForLock = false;
2626

2727
/**
28-
* Set custom temporary directory
28+
* Validate temporary directory is writable
29+
*
30+
* TODO: This method validates but doesn't store the temp directory.
31+
* The actual temp dir comes from $GLOBALS['temporary_files_dir'].
32+
* Consider removing this method or making it actually set an override.
2933
*/
3034
public function setTempDir(string $tempDir): void
3135
{
@@ -305,6 +309,140 @@ public function getStagingFiles(string $type): array
305309
return $files;
306310
}
307311

312+
/**
313+
* Get our own MySQL connection ID
314+
*/
315+
private function getOurConnectionId(): ?int
316+
{
317+
if (!function_exists('sqlQuery')) {
318+
return null;
319+
}
320+
321+
try {
322+
$result = sqlQuery("SELECT CONNECTION_ID() as connection_id");
323+
324+
if ($result && $result['connection_id'] !== null) {
325+
return (int)$result['connection_id'];
326+
}
327+
} catch (\Throwable $e) {
328+
$this->logJson('warning', 'Could not retrieve our connection ID', [
329+
'error' => $e->getMessage()
330+
]);
331+
}
332+
333+
return null;
334+
}
335+
336+
/**
337+
* Get information about the process holding a lock
338+
*
339+
* @return array{connection_id: int, host: ?string, user: ?string, time: ?int, state: ?string}|null
340+
*/
341+
private function getLockHolderInfo(string $lockName): ?array
342+
{
343+
if (!function_exists('sqlQuery')) {
344+
return null;
345+
}
346+
347+
try {
348+
$result = sqlQuery("SELECT IS_USED_LOCK(?) as connection_id", [$lockName]);
349+
350+
if (!$result || $result['connection_id'] === null) {
351+
return null;
352+
}
353+
354+
$connectionId = (int)$result['connection_id'];
355+
356+
// Try to get more details from processlist.
357+
// Note: The OpenEMR database user typically lacks the PROCESS privilege
358+
// required to query INFORMATION_SCHEMA.PROCESSLIST, so this will often
359+
// return no additional info beyond the connection ID.
360+
$host = null;
361+
$user = null;
362+
$time = null;
363+
$state = null;
364+
365+
try {
366+
$processInfo = sqlQuery(
367+
"SELECT HOST, USER, TIME, STATE FROM INFORMATION_SCHEMA.PROCESSLIST WHERE ID = ?",
368+
[$connectionId]
369+
);
370+
371+
if ($processInfo) {
372+
$host = $processInfo['HOST'] ?? null;
373+
$user = $processInfo['USER'] ?? null;
374+
$time = isset($processInfo['TIME']) ? (int)$processInfo['TIME'] : null;
375+
$state = $processInfo['STATE'] ?? null;
376+
}
377+
} catch (\Throwable) {
378+
// User likely lacks PROCESS privilege - continue with just connection ID
379+
}
380+
381+
return [
382+
'connection_id' => $connectionId,
383+
'host' => $host,
384+
'user' => $user,
385+
'time' => $time,
386+
'state' => $state,
387+
];
388+
} catch (\Throwable $e) {
389+
$this->logJson('warning', 'Could not retrieve lock holder info', [
390+
'lock_name' => $lockName,
391+
'error' => $e->getMessage()
392+
]);
393+
}
394+
395+
return null;
396+
}
397+
398+
/**
399+
* Format lock holder info for error messages
400+
*
401+
* @param array{connection_id: int, host: ?string, user: ?string, time: ?int, state: ?string}|null $info
402+
*/
403+
private function formatLockHolderMessage(?array $info): string
404+
{
405+
if ($info === null) {
406+
return '';
407+
}
408+
409+
$parts = ["Lock held by MySQL connection {$info['connection_id']}"];
410+
411+
if ($info['host'] !== null) {
412+
$parts[] = "from {$info['host']}";
413+
}
414+
415+
if ($info['time'] !== null) {
416+
$parts[] = "for {$info['time']}s";
417+
}
418+
419+
return ' ' . implode(' ', $parts) . '.';
420+
}
421+
422+
/**
423+
* Get the current database name
424+
*/
425+
private function getDatabaseName(): ?string
426+
{
427+
if (!function_exists('sqlQuery')) {
428+
return null;
429+
}
430+
431+
try {
432+
$result = sqlQuery("SELECT DATABASE() as db_name");
433+
434+
if ($result && $result['db_name'] !== null) {
435+
return $result['db_name'];
436+
}
437+
} catch (\Throwable $e) {
438+
$this->logJson('warning', 'Could not retrieve database name', [
439+
'error' => $e->getMessage()
440+
]);
441+
}
442+
443+
return null;
444+
}
445+
308446
/**
309447
* Acquire a database lock for the given code type to prevent concurrent imports
310448
*/
@@ -314,8 +452,26 @@ private function acquireLock(string $codeType): void
314452
throw new CodeImportException("OpenEMR database functions not available");
315453
}
316454

317-
// Create a unique lock name for this code type
318-
$lockName = "openemr_vocab_import_{$codeType}";
455+
// Create a unique lock name for this code type and database
456+
// Include database name since GET_LOCK() is server-wide, not per-database
457+
// MySQL has a 64-character limit on lock names in 5.7+
458+
$dbName = $this->getDatabaseName() ?? 'unknown';
459+
$lockName = "oe-vocab-import-{$dbName}-{$codeType}";
460+
461+
// MySQL lock names are limited to 64 characters (MySQL 5.7+)
462+
// If lock name exceeds this limit, use a hash instead
463+
if (strlen($lockName) > 64) {
464+
$originalLockName = $lockName;
465+
// Use SHA-256 base64-encoded (44 characters) for better collision resistance
466+
$hash = base64_encode(hash('sha256', $dbName . '-' . $codeType, true));
467+
$lockName = 'oe-vocab-' . $hash;
468+
$this->logJson('warning', 'Lock name exceeds MySQL 64-character limit, using hash', [
469+
'original_lock_name' => $originalLockName,
470+
'hashed_lock_name' => $lockName,
471+
'original_length' => strlen($originalLockName)
472+
]);
473+
}
474+
319475
$this->currentLockName = $lockName;
320476

321477
$attempt = 1;
@@ -325,8 +481,15 @@ private function acquireLock(string $codeType): void
325481
// Attempt to acquire the lock with a 10-second timeout per attempt
326482
$result = sqlQuery("SELECT GET_LOCK(?, 10) as lock_result", [$lockName]);
327483

328-
if ($result && $result['lock_result'] == 1) {
329-
// Lock acquired successfully
484+
if ($result && (int) ($result['lock_result'] ?? 0) === 1) {
485+
// Lock acquired successfully - log our own connection ID for identification
486+
$ourConnectionId = $this->getOurConnectionId();
487+
$this->logJson('info', 'Database lock acquired', [
488+
'code_type' => $codeType,
489+
'lock_name' => $lockName,
490+
'connection_id' => $ourConnectionId,
491+
'pid' => getmypid()
492+
]);
330493
return;
331494
}
332495

@@ -340,21 +503,31 @@ private function acquireLock(string $codeType): void
340503
}
341504

342505
// Lock is held by another process ($result['lock_result'] == 0)
506+
// Try to get info about the process holding the lock for debugging
507+
$lockHolderInfo = $this->getLockHolderInfo($lockName);
508+
343509
if ($this->lockRetryDelaySeconds === 0) {
344510
// No retry mode - fail immediately
345511
$this->currentLockName = null;
346-
throw new DatabaseLockException(
347-
"Failed to acquire database lock for {$codeType} import - " .
348-
"another import is in progress and no-wait mode is enabled."
349-
);
512+
$errorMsg = "Failed to acquire database lock for {$codeType} import - " .
513+
"another import is in progress and no-wait mode is enabled.";
514+
$errorMsg .= $this->formatLockHolderMessage($lockHolderInfo);
515+
516+
throw new DatabaseLockException($errorMsg);
350517
}
351518

352519
if ($attempt < $this->lockRetryAttempts) {
353-
$this->logJson('info', 'Lock is held by another process', [
520+
$logData = [
354521
'delay_seconds' => $delay,
355522
'attempt' => $attempt,
356523
'max_attempts' => $this->lockRetryAttempts
357-
]);
524+
];
525+
526+
if ($lockHolderInfo !== null) {
527+
$logData['lock_holder'] = $lockHolderInfo;
528+
}
529+
530+
$this->logJson('info', 'Lock is held by another process', $logData);
358531
$this->waitedForLock = true;
359532
sleep($delay);
360533

@@ -366,11 +539,12 @@ private function acquireLock(string $codeType): void
366539
// Final attempt failed
367540
$this->currentLockName = null;
368541
$totalWaitTime = $this->calculateTotalWaitTime();
369-
throw new DatabaseLockException(
370-
"Failed to acquire database lock for {$codeType} import after " .
542+
$errorMsg = "Failed to acquire database lock for {$codeType} import after " .
371543
"{$this->lockRetryAttempts} attempts ({$totalWaitTime} seconds total). " .
372-
"Another import may still be in progress."
373-
);
544+
"Another import may still be in progress.";
545+
$errorMsg .= $this->formatLockHolderMessage($lockHolderInfo);
546+
547+
throw new DatabaseLockException($errorMsg);
374548
}
375549
}
376550
}
@@ -406,15 +580,20 @@ private function releaseLock(): void
406580

407581
if (!function_exists('sqlQuery')) {
408582
// Log warning but don't throw exception during cleanup
409-
error_log("Warning: Could not release database lock - OpenEMR functions not available");
583+
$this->logJson('warning', 'Could not release database lock - OpenEMR functions not available', [
584+
'lock_name' => $this->currentLockName
585+
]);
410586
return;
411587
}
412588

413589
try {
414590
sqlQuery("SELECT RELEASE_LOCK(?)", [$this->currentLockName]);
415591
} catch (\Exception $e) {
416592
// Log error but don't throw exception during cleanup
417-
error_log("Warning: Failed to release database lock '{$this->currentLockName}': " . $e->getMessage());
593+
$this->logJson('warning', 'Failed to release database lock', [
594+
'lock_name' => $this->currentLockName,
595+
'error' => $e->getMessage()
596+
]);
418597
} finally {
419598
$this->currentLockName = null;
420599
$this->waitedForLock = false;

0 commit comments

Comments
 (0)