Skip to content

Commit d8d8bfb

Browse files
kojiromikekojiromike
authored
fix(CodeImporter): identify lock and lock holder (#5)
1 parent 917c70d commit d8d8bfb

File tree

2 files changed

+198
-20
lines changed

2 files changed

+198
-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: 196 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,10 @@ class CodeImporter
2525
private bool $waitedForLock = false;
2626

2727
/**
28-
* Set custom temporary directory
28+
* Validate temporary directory is writable
29+
*
30+
* Note: This method validates but doesn't store the temp directory.
31+
* The actual temp dir comes from $GLOBALS['temporary_files_dir'].
2932
*/
3033
public function setTempDir(string $tempDir): void
3134
{
@@ -305,6 +308,140 @@ public function getStagingFiles(string $type): array
305308
return $files;
306309
}
307310

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

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

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

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

@@ -340,21 +502,31 @@ private function acquireLock(string $codeType): void
340502
}
341503

342504
// Lock is held by another process ($result['lock_result'] == 0)
505+
// Try to get info about the process holding the lock for debugging
506+
$lockHolderInfo = $this->getLockHolderInfo($lockName);
507+
343508
if ($this->lockRetryDelaySeconds === 0) {
344509
// No retry mode - fail immediately
345510
$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-
);
511+
$errorMsg = "Failed to acquire database lock for {$codeType} import - " .
512+
"another import is in progress and no-wait mode is enabled.";
513+
$errorMsg .= $this->formatLockHolderMessage($lockHolderInfo);
514+
515+
throw new DatabaseLockException($errorMsg);
350516
}
351517

352518
if ($attempt < $this->lockRetryAttempts) {
353-
$this->logJson('info', 'Lock is held by another process', [
519+
$logData = [
354520
'delay_seconds' => $delay,
355521
'attempt' => $attempt,
356522
'max_attempts' => $this->lockRetryAttempts
357-
]);
523+
];
524+
525+
if ($lockHolderInfo !== null) {
526+
$logData['lock_holder'] = $lockHolderInfo;
527+
}
528+
529+
$this->logJson('info', 'Lock is held by another process', $logData);
358530
$this->waitedForLock = true;
359531
sleep($delay);
360532

@@ -366,11 +538,12 @@ private function acquireLock(string $codeType): void
366538
// Final attempt failed
367539
$this->currentLockName = null;
368540
$totalWaitTime = $this->calculateTotalWaitTime();
369-
throw new DatabaseLockException(
370-
"Failed to acquire database lock for {$codeType} import after " .
541+
$errorMsg = "Failed to acquire database lock for {$codeType} import after " .
371542
"{$this->lockRetryAttempts} attempts ({$totalWaitTime} seconds total). " .
372-
"Another import may still be in progress."
373-
);
543+
"Another import may still be in progress.";
544+
$errorMsg .= $this->formatLockHolderMessage($lockHolderInfo);
545+
546+
throw new DatabaseLockException($errorMsg);
374547
}
375548
}
376549
}
@@ -406,15 +579,20 @@ private function releaseLock(): void
406579

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

413588
try {
414589
sqlQuery("SELECT RELEASE_LOCK(?)", [$this->currentLockName]);
415590
} catch (\Throwable $e) {
416591
// Log error but don't throw exception during cleanup
417-
error_log("Warning: Failed to release database lock '{$this->currentLockName}': " . $e->getMessage());
592+
$this->logJson('warning', 'Failed to release database lock', [
593+
'lock_name' => $this->currentLockName,
594+
'error' => $e->getMessage()
595+
]);
418596
} finally {
419597
$this->currentLockName = null;
420598
$this->waitedForLock = false;

0 commit comments

Comments
 (0)