ES /docs

GraphicsMagickManager::execute | error: Command failed: gm convert -verbose -debug All -log "%t [NaN

RCA: GraphicsMagickManager::execute | Command failed on BIM-derived floorplan PNGs

Overview#

What Happened#

2026-07-23 16:11-16:12 KST 사이 cupixworks-any-thumbnail-agent 에서 5개의 Floorplan 썸네일 생성이 연속 실패했다. 모두 동일한 Navisworks(.nwd) BIM 파일에서 파생된 Floorplan(floorplan_type=bim) 레코드로, 소스 PNG 를 gm convert 로 리사이즈하려는 순간 자식 프로세스가 non-zero exit 로 종료되어 Error: Command failed: gm convert ... 를 던졌다. SQS 메시지는 재시도 없이 삭제되었고, 각 Floorplan 은 DB 에 state: done 으로 남았지만 썸네일은 생성되지 않았다.

Quick Facts#

Field Value
exception.class Error (child_process Command failed)
exception.message Command failed: gm convert -verbose -debug All -log "%t [NaN] %m::%f:%l %e" -background white -flatten -limit memory 682MB -limit map 1364MB -limit disk 18GB -resize 300x200 /tmp/workspace/{id}/{id}.png /tmp/workspace/{id}/{id}_thumbnail.jpg
top_frame ChildProcessManager2.handleMessage (/tmp/agent/dist/app.cjs:1519:26)
runtime Node.js child_process → GraphicsMagick (gm) CLI
env production, us-west-2
tenant cupix

Affected Teams#

Team / Domain Error Count Impact
weoneil / workspace 4318 (Pacific Village Campus SB), facility 13786 (Pacific Village Overall) 5 5 개의 BIM 파생 Floorplan (WD-PVPC_COORD_R24.nwd-*.png) 이 썸네일 없이 저장됨. UI 에서는 placeholder 만 노출될 것으로 예상.

Timeline#

  1. 2026-07-23 16:11:48 KST — Floorplan 91537 SQS 메시지 수신, downloadOriginal 시작 (source: /api/v1/floorplans/91537/download)
  2. 2026-07-23 16:11:55 KST — 91537 gm convert 실패 → GraphicsMagickManager::execute | error 발생 (첫 오류)
  3. 2026-07-23 16:11:49 ~ 16:12:26 KST — 91539, 91536, 91540, 91538 도 동일 패턴으로 순차 실패
  4. 2026-07-23 16:12:34 KST — 91538 실패 (마지막 오류, occurrence_count: 5 도달)
  5. 2026-07-23 16:11-16:22 KST 동안 — 다른 tenant/워크스페이스의 썸네일 (91550, 91555, 91557, 91558, 91568~91572 등) 은 성공 → 인프라 문제 아님, 특정 소스 파일에 국한

Error Log#

Datadog Logs

text
GraphicsMagickManager::execute | error: Command failed: gm convert -verbose -debug All -log "%t [NaN] %m::%f:%l %e" -background white -flatten -limit memory 682MB -limit map 1364MB -limit disk 18GB -resize 300x200 /tmp/workspace/91537/91537.png /tmp/workspace/91537/91537_thumbnail.jpg

Impact#

  • Service: cupixworks-any-thumbnail-agent
  • Team: weoneil
  • 발생 횟수: 5
  • 최초 발생: 2026-07-23 16:11:55 KST
  • 최근 발생: 2026-07-23 16:12:34 KST

영향받은 레코드 (Kibana floorplans index 에서 확인):

Floorplan ID source_filename floorplan_type 결과 state
91536 WD-PVPC_COORD_R24.nwd-Overall - Site.png bim done (썸네일 없음)
91537 WD-PVPC_COORD_R24.nwd-SUD - Level 01.png bim done (썸네일 없음)
91538 WD-PVPC_COORD_R24.nwd-CDH - Level 01.png bim done (썸네일 없음)
91539 WD-PVPC_COORD_R24.nwd-DAAS - Level 01.png bim done (썸네일 없음)
91540 WD-PVPC_COORD_R24.nwd-RCC - Level 01.png bim done (썸네일 없음)

모두 동일 사용자 (dustin.kim@cupix.com, id 31939) 가 workspace 4318 (Pacific Village Campus SB) / facility 13786 에 업로드한 하나의 Navisworks 파일에서 파생된 레이어별 PNG.

Root Cause Summary#

GraphicsMagick(gm convert) 자식 프로세스가 non-zero exit code 로 종료되어 Error: Command failed: ... 예외가 던져졌다. 실패한 5개 파일은 모두 동일한 BIM (WD-PVPC_COORD_R24.nwd) 을 레이어별로 export 한 PNG 로 (floorplan_type: "bim"), Navisworks → PNG 변환 파이프라인이 생성한 이미지가 GraphicsMagick 이 처리할 수 없는 형태 (예: 지원하지 않는 PNG 청크 조합, 손상, 예상보다 훨씬 큰 dimensions/색심도) 로 추정된다. 동시간대에 다른 tenant 의 썸네일 요청은 정상 성공했으므로 인프라/gm binary 문제가 아닌 입력 파일 특성 문제다.

실패 원인 진단이 어려운 이유는 graphics-magick.process.ts:76child_process.execSync(command, { stdio: 'ignore' }) 설정으로 인해 gm 의 stderr (실제 실패 사유) 가 완전히 폐기되기 때문이다. 로그에는 Node 가 만든 상투적 문자열 Command failed: ... 만 남아 원인 규명이 불가능하다.

부수적 이슈: 에러 메시지의 -log "%t [NaN] %m::%f:%l %e" 에서 [NaN] 은 원래 gm 의 로그 포맷 지정자 %d (duration) 인데, logger.error('... | error:', error)error.message 를 format string 으로 해석하면서 %d 를 대응 인자가 없는 상태로 소비해 NaN 으로 치환한 결과 (utils/format 스타일 로거의 부작용). 실제 실행된 커맨드는 [%d] 이며 이 치환은 진단을 방해하는 로그 오염이다.

Technical Analysis#

Code Path#

  • Entry point: applications/agents/packages/cupix-tesla-thumbnail-agent/src/thumbnail-service.ts:58 (ThumbnailService::run) — SQS 메시지 → CPFloorplan 모델 생성 → downloadOriginalgenerateThumbnail
  • Thumbnail 생성 호출: image-cpobject.ts:208this.graphicsMagickManager.execute(params)
  • Manager: graphics-magick.manager.ts:38 — IPC 로 자식 프로세스에 execute 요청
  • Failure point: graphics-magick.process.ts:76child_process.execSync 가 non-zero exit 로 throw

ThumbnailService::run 은 실패 시 재시도 없이 handlingMessageErrors 를 통해 SQS 메시지를 삭제한다 (base-service.ts:300-309).

applications/agents/packages/cupix-tesla-thumbnail-agent/src/process/graphics-magick.process.ts:42-77typescript
let command = 'gm convert -verbose -debug All -log "%t [%d] %m::%f:%l %e" -background white -flatten';
// ... 옵션 조립 ...
if (source.toLowerCase().indexOf('pdf') > -1) {
    command += ' -define "pdf:use-cropbox=true"';
    command += ` ${source}[${frame}]`;
} else {
    command += ` ${source}`;
}
command += ` ${output}`;

this.log(`GraphicsMagickProcess::execute - command: ${command}`);
child_process.execSync(command, { stdio: 'ignore' });

stdio: 'ignore' 로 인해 gm 의 stderr (gm convert: ... 실제 에러 텍스트) 가 소실된다. 에러 발생 시에도 무슨 이유로 실패했는지 로그가 남지 않아 진단 불가.

applications/agents/packages/cupix-tesla-thumbnail-agent/src/manager/graphics-magick.manager.ts:37-50typescript
try {
    await this.childProcessManager.execute('execute', params);
    logger.debug('GraphicsMagickManager::execute | completed successfully');
} catch (error) {
    logger.error('GraphicsMagickManager::execute | error:', error);

    const errorCode = ErrorCode.Agent.Default;

    if (this.setJobErrorCode) {
        this.setJobErrorCode(errorCode);
    }

    throw error;
}

logger.error('... | error:', error)error 를 두 번째 인자로 넘기지만 첫 인자에 % 지정자가 없으므로 로거가 error.message 를 이어붙이는 과정에서 error.message 내부의 %d 를 format specifier 로 오해해 NaN 으로 치환한다 (Datadog 에 남은 [NaN] 의 정체).

applications/agents/packages/base/src/base-service.ts:240-276typescript
private getApiErrorToDeleteMessage = (error: any): any => {
    if (error == undefined) { /* ... */ }
    if (error.errno != undefined && error.code != undefined && error.syscall != undefined) {
        logger.warn('BaseService::getApiErrorToDeleteMessage | nodejs common system error', error);
        return;
    }
    const response = CPUtils.isJsonString(error) ? JSON.parse(error) : error.response;
    if (response == undefined) {
        logger.warn('BaseService::getApiErrorToDeleteMessage | undefined response', error);
        return 'undefined response';   // ← 여기 경로
    }
    // ...
    if (statusCode != undefined && statusCode >= 400 && statusCode <= 500) { /* ... */ }
    return;
};

child_process 에러는 error.response 도 없고 JSON string 도 아니므로 'undefined response' 를 반환 → handlingMessageErrors 에서 apiErrorObject != undefined 로 판정되어 SQS 메시지를 삭제한다. 재시도 없이 즉시 폐기되는 것이 현재 동작이다.

Log Evidence#

Datadog 쿼리 (재현용):

text
service:cupixworks-any-thumbnail-agent status:error @environment:production "GraphicsMagickManager::execute"

시간 범위: 2026-07-23T06:11:00Z ~ 2026-07-23T08:13:00Z

91537 단일 실행 흐름 (KST):

text
2026-07-23 16:11:48  info  BaseService::runByMessage | id: 91537
2026-07-23 16:11:48  info  ThumbnailService::newModel | model id: 91537, type: Floorplan
2026-07-23 16:11:48  info  ImageCPObject::downloadOriginal | url: http://api-tesla.cupix.internal/api/v1/floorplans/91537/download, path: /tmp/workspace/91537/91537.png
2026-07-23 16:11:48  info  ImageCPObject::generateThumbnail | params: {"input_file_path":"/tmp/workspace/91537/91537.png","output_image_path":"/tmp/workspace/91537/91537_thumbnail.jpg","resized_width":300,"resized_height":200,"frame":0}
2026-07-23 16:11:55  error GraphicsMagickManager::execute | error: Command failed: gm convert ... /tmp/workspace/91537/91537.png /tmp/workspace/91537/91537_thumbnail.jpg
2026-07-23 16:11:55  warn  CupixAuth::handleError | Undefined response: {"stack":"Error: Command failed: gm convert -verbose -debug All -log \"%t [%d] %m::%f:%l %e\" ...
2026-07-23 16:11:55  warn  BaseService::getApiErrorToDeleteMessage | undefined response Command failed: gm convert ...
2026-07-23 16:11:55  info  BaseService::cleanUpAnythingRelatedModel | path: /tmp/workspace/91537
  • downloadOriginal | end - size: 는 debug 레벨이라 Datadog 에 없지만, generateThumbnail 이 시작한 사실은 다운로드 후 진행되었음을 시사한다 (source 파일 부재 시 gm 이 such file or directory not found 로 실패하는 것과 구별되지 않지만, elapsed 4-8s 는 gm 이 실제로 파일을 읽고 처리 중 실패한 시간에 가깝다).
  • Retry 흔적 없음: 각 ID 는 1회만 시도되고 cleanUpAnythingRelatedModel 호출됨 → SQS 메시지 즉시 삭제.

Kibana floorplans 인덱스 결과 (prod):

json
{
  "id": 91537,
  "state": "done",
  "floorplan_type": "bim",
  "source_filename": "WD-PVPC_COORD_R24.nwd-SUD - Level 01.png",
  "workspace": { "id": 4318, "name": "07 - Pacific Village Campus SB" },
  "facility": { "id": 13786, "name": "Pacific Village Overall " },
  "user": { "id": 31939, "email": "dustin.kim@cupix.com" }
}

동시간대 성공 사례 (다른 tenant/모델):

text
2026-07-23 16:15:23  info  ImageCPObject::generateThumbnail | end - output: /tmp/workspace/91558/91558_thumbnail.jpg, size: 2832, elapsed time: 74521 ms
2026-07-23 16:15:13  info  ImageCPObject::generateThumbnail | end - output: /tmp/workspace/91572/91572_thumbnail.jpg, size: 7871, elapsed time: 16411 ms
2026-07-23 16:15:04  info  ImageCPObject::generateThumbnail | end - output: /tmp/workspace/91557/91557_thumbnail.jpg, size: 2888, elapsed time: 66080 ms

14일 lookback (now-14d ~ 2026-07-23T06:00Z) 에서 동일한 GraphicsMagickManager::execute | error 는 단 1건 (.rvt Revit 파일, 91537 무관):

text
2026-07-21 02:46:10  error  GraphicsMagickManager::execute | error: Command failed: gm convert ... /tmp/workspace/20655/20655.rvt /tmp/workspace/20655/20655_thumbnail.jpg

→ 이 오류는 만성적이지 않고, 특정 BIM upload 배치에서 발생한 국소 이벤트임이 확인된다.

Hypotheses Considered#

# Hypothesis Evidence for Evidence against Verdict
H1 특정 BIM 파생 PNG 파일이 GraphicsMagick 이 처리할 수 없는 형태 (손상/비표준 PNG/과도한 해상도 등) 라서 gm convert 가 non-zero exit Kibana: 실패한 5개 모두 floorplan_type: "bim", source_filename: "WD-PVPC_COORD_R24.nwd-<layer>.png" 로 하나의 .nwd 에서 layer 별 export 된 PNG. 동시간대 다른 tenant 썸네일 다수 성공 (91558, 91572 등). 14일 lookback 에서 유사 에러 1건뿐이라 인프라/binary 문제 아님. — (직접 stderr 확인 못했으므로 정확한 gm 에러 코드는 uncertain — needs verification via reproduction) Confirmed (파일 특성 원인, 세부 에러는 stderr 미로깅으로 확증 불가)
H2 Node 프로세스 메모리/디스크 한도 초과 (-limit memory 682MB) 커맨드에 -limit memory 682MB -limit map 1364MB 명시. 다른 tenant BIM PNG 는 성공했다는 반증 필요. 동시간대 다른 썸네일 job 들 정상 완료 (elapsed 66-575s, size 정상). 실패까지 4-8s 로 gm 이 초기 파싱 단계에서 죽은 흐름에 부합 (map/memory 도달 시간 아님). Rejected
H3 downloadOriginal 이 부분 다운로드/0-byte 파일을 남겼고 gm 이 이를 열지 못함 `downloadOriginal end는 debug 라 Datadog 미저장 → 다운로드 성공 여부 로그로 확증 불가.downloadFile` 는 statusCode !== 200 시 명시적 error 를 남기는데 해당 로그 없음 → 200 응답은 받은 것으로 보임. 다운로드 실패 시 `ImageCPObject::downloadFile
H4 자식 프로세스 (gm) 자체가 없거나 PATH 문제 광범위한 실패 예상되어야 함. 같은 서비스에서 다른 썸네일 job 은 정상 성공. Rejected
H5 SQS 메시지 중복/재처리 loop SQS 메시지가 매우 짧은 간격으로 5개 처리됨. 각 message ID 는 서로 다른 model id (91536~91540) 를 참조하고, 각 ID 는 1회만 시도되고 삭제되었음 (cleanUpAnythingRelatedModel 각 1회). Rejected

Fix Recommendation#

즉시 조치 (Critical)#

  • graphics-magick.process.ts:76stdio: 'ignore'stdio: 'pipe' 로 변경하고 catch 블록에서 error.stderr / error.stdout 를 로그로 남길 것. 현재는 실패 사유가 완전히 소실되어 재발 시 진단 불가능. execSync 는 실패 시 error.stderr, error.stdout 에 자식 출력을 담아준다 (Node docs). Directory: applications/agents/packages/cupix-tesla-thumbnail-agent/src/process/graphics-magick.process.ts. 동일 코드가 applications/agents/packages/cupix-tesla-floorplan-agent/src/manager/graphics-magick.manager.ts 에도 존재 — 함께 수정 고려.

  • graphics-magick.manager.ts:41logger.error('... error:', error) 에서 error 를 두 번째 인자로 스플랫하지 말고 error.message / error.stack 을 명시적으로 문자열로 만들거나 logger 가 error 객체를 처리하는 방식으로 넘길 것. 현재 형식은 error.message 내부의 %d 를 format specifier 로 오해해 [NaN] 으로 오염시킨다. Directory: applications/agents/packages/cupix-tesla-thumbnail-agent/src/manager/graphics-magick.manager.ts:41 (그리고 applications/agents/packages/cupix-tesla-floorplan-agent/src/manager/graphics-magick.manager.ts:41 도 동일).

단기 개선 (1주 이내)#

  • 실패 원인별 분기 처리: getApiErrorToDeleteMessage (applications/agents/packages/base/src/base-service.ts:240-276) 가 child_process 실패를 'undefined response' 로 취급해 즉시 SQS 메시지를 삭제한다. 이 결과 5개 Floorplan 이 재시도 없이 영구적으로 썸네일 없이 남았다. child_process 계열 에러 (error.message 시작이 Command failed:, 혹은 별도 에러 클래스) 에 대해 receiveCount 기반 재시도를 최소 1-2회 허용하도록 조건 수정 검토.
  • BIM 파생 PNG 사전 검증: Floorplan(floorplan_type=bim) 을 upstream (Rails API 또는 BIM 변환 파이프라인) 에서 생성 직후 identify 로 헤더 검증하고, 문제가 있으면 tenant 에 알림 & 재변환. 5장 모두 동일 소스에서 나온 것이므로 파이프라인 상류의 문제일 가능성이 크다.
  • 부분 실패 UI 표시: DB state: done 이지만 썸네일이 없는 Floorplan 을 UI 가 감지해서 재생성 요청 버튼을 노출하거나, backend 배치가 thumbnail_urls 가 비어있는 done Floorplan 을 주기적으로 재처리하도록.

장기 개선 (재발 방지)#

  • 자식 프로세스 stderr 는 항상 캡처하는 표준 wrapper: graphics-magick.process.ts 이외에도 agents 리포지토리 전반에서 child_process.execSync(..., { stdio: 'ignore' }) 패턴이 반복되면 유사한 blind spot 이 생긴다. 표준 runExternalCommand() 유틸을 만들어 stderr 캡처 & 로깅을 강제.
  • BIM → PNG 변환 파이프라인 정합성 계약: 상류 (Navisworks/Revit → PNG 변환기) 가 어떤 PNG 스펙 (bit depth, dimension max, color type) 을 보장하는지 문서화하고 downstream 에서 사전 검증. 반복 재발 시 문제 파일 특성 (해상도/컬러 프로파일) 을 회귀 테스트 fixture 로 편입.

Monitoring#

  • Datadog error rate on thumbnail-agent:
text
sum:trace.express.request.errors{service:cupixworks-any-thumbnail-agent,env:production}.as_count()
  • GraphicsMagickManager::execute 실패 count (facet on floorplan_type, 팀별 파악):
text
service:cupixworks-any-thumbnail-agent status:error @environment:production "GraphicsMagickManager::execute"
  • 시간대별 실패 vs 성공 대비 (log-based metric 필요 — generateThumbnail | end 성공 count vs GraphicsMagickManager::execute | error count):
text
service:cupixworks-any-thumbnail-agent @environment:production "generateThumbnail | end"
  • 알림 임계: 10분에 3건 이상 GraphicsMagickManager::execute | error 발생 시 slack 알림. 지금까지 14일에 1건 수준이었으므로 낮은 임계도 노이즈가 적다.

Risk Assessment#

  • Risk level: low
    • 인프라 문제 아님, 동시간대 다른 tenant 정상. 특정 BIM upload 배치 국소 이슈.
  • 예상 복잡도: standard
    • 즉시 조치 (stderr 캡처 + 로그 포맷 fix) 는 trivial, 하지만 진짜 근본 원인 (BIM→PNG 파이프라인 검증) 은 상류 리포지토리 조사 필요해 standard.