Api::V1::WorkspacesController#show (avg 11449ms, max 11449ms)
RCA: Api::V1::WorkspacesController#show latency spike (avg 11449ms)
Overview#
What Happened#
2026-07-16 14:28:57 KST 에 cupixworks-api production(us-west-2)에서 Api::V1::WorkspacesController#show 리소스가 단일 요청 기준 11,449ms 로 처리된 latency outlier 가 감지되었다. 상태 코드는 error/warn 이 아니라 정상 200 응답으로 완료된 slow request 이며, 동일 리소스에서 클러스터 창(14:28 KST 전후) 다른 요청들은 정상 지연 범위였다.
Quick Facts#
| Field | Value |
|---|---|
| resource_name | Api::V1::WorkspacesController#show |
| cluster_type | latency |
| avg_duration_ms | 11449 |
| max_duration_ms | 11449 |
| occurrences | 1 |
| sample_trace_id | 3044730468254276793 |
| env | production, us-west-2 |
| tenant | cupix |
Affected Teams#
| Team / Domain | Error Count | Impact |
|---|---|---|
| cupixworks-api (workspaces GET) | 1 | 워크스페이스 상세 페이지 로딩 지연 (11.4s) 을 겪은 단일 사용자 세션 |
Timeline#
- 2026-07-16 14:28:57 KST — 문제의
GET /api/v1/workspaces/:id요청이 시작되어 11,449ms 뒤에 200으로 완료 (Datadog APM trace_id3044730468254276793). - 2026-07-16 14:28:47–14:32:57 KST — 같은 시간대의 다른
WorkspacesController#show로그(Datadog info 로그)들은 모두 정상적으로 200 완료. 동시간대에cupixworks-api status:error로그는Cupix::PubSub::Subscribers::UserRecipeGenerator의 무관한private method 'service_jwt'실패만 다수 발생 (본 클러스터와 별개 문제). - 감지 — error-sweeper collector 가 APM p95 duration > 500ms 임계에서 이 outlier 를 latency cluster 로 수집.
Error Log#
{
"resource_name": "Api::V1::WorkspacesController#show",
"service": "cupixworks-api",
"occurrences": 1,
"avg_ms": 11449,
"max_ms": 11449,
"sample_trace_id": "3044730468254276793"
}
Impact#
- Service:
cupixworks-api - 발생 횟수: 1
- 최초 발생: 2026-07-16 14:28:57 KST
- 최근 발생: 2026-07-16 14:28:57 KST
Root Cause Summary#
Api::V1::WorkspacesController#show 에서 set_workspace before_action → WorkspaceRepository.show → BaseRepository.show 경로가 실행될 때, permission_joins 가 workspace 단건 조회에도 6 개의 대형 LEFT JOIN 서브쿼리 (workspace_user/group, team_user/group, team_system_group, review_public) 를 build 하여 workspace_permissions, team_permissions, grouped_users, reviews 를 조인한 뒤 GREATEST/IFNULL 을 WHERE 절과 SELECT 절 양쪽에서 계산한다. 이 단일 요청은 특정 tenant 의 permission 스캔이 cold path 로 실행되면서 (혹은 동시 write 로 인한 lock 대기·plan 재선정) 11.4초까지 늘어난 outlier 로 판단된다. 클러스터가 단일 occurrence 인 점, 같은 분에 다른 #show 요청들이 정상 응답한 점, 동시간대 error 로그가 별개 이슈인 점으로 볼 때 systemic latency 가 아닌 permission_joins 쿼리의 tail latency (p99+ outlier) 가 root cause 이다.
Technical Analysis#
Code Path#
- Entry point:
app/controllers/api/v1/workspaces_controller.rb:9—before_action :set_workspace set_workspace— repository 인스턴스의show를 호출WorkspaceRepository.show→BaseRepository.show— permission_joins 조합 후.first로 단건 조회- Failure point (latency source):
app/repositories/workspace_repository.rb:72-174—self.permission_joins가 실행되며 6개 LEFT JOIN 서브쿼리가 매 요청마다 재구성 및 실행됨
before_action :set_workspace, except: %i[index create untrash purge mock bulk_share bulk_unshare]
# ...
def set_workspace
@model = repository_instance.show(params[:id])
end
def self.show(id, current_user: nil, **kwargs)
model = super
if current_user.present? && model.present?
current_user.set_current_workspace(model)
end
model
end
def self.show(key_or_id_or_model, current_user: nil, visibility: Cyclable.visibility[:UNTRASHED], review_id: nil, capture_id: nil, skip_permission: false)
# ...
query =
if skip_permission || current_user == ::User.unauthorized_user
where(attrs)
elsif current_class == ::Review || (review_id || capture_id).present?
permission_joins(default_joins(current_class), current_user, review_id: review_id || -1, capture_id: capture_id || -1).where(attrs)
elsif current_user.present?
permission_joins(default_joins(current_class), current_user).where(attrs)
else
raise Cupix::Errors::System.new(code: 'SYS30000', reason: 'current_user or review is required on Repository')
end
scope = current_class.visibility_scope(visibility)
model = query.merge(scope).first
record.joins("
LEFT JOIN (
SELECT reviews.id AS review_id, 2 AS permission
FROM reviews
where reviews.public_access_enabled_at IS NOT NULL
AND reviews.id = #{sanitized_review_id}
) AS review_public_permissions
ON review_public_permissions.review_id = #{sanitized_review_id}
LEFT JOIN (
SELECT workspace_id, permission
FROM workspace_permissions
WHERE workspace_permissions.accessor_id = #{sanitized_user_id}
AND workspace_permissions.accessor_type = 'User'
) AS workspace_user_permissions
ON workspace_user_permissions.workspace_id = workspaces.id
...
").group('id').select(_select).where("
(
GREATEST(
IFNULL(team_user_permissions.permission, 0),
IFNULL(team_group_permissions.permission, 0)
) = 1
AND
GREATEST(
IFNULL(workspace_user_permissions.permission, 0),
IFNULL(workspace_group_permissions.permission, 0)
) > 0
)
OR
GREATEST(...) > 1
")
- 기대 동작: 단건 workspace 조회는 100–300ms 이내에 완료되어야 함 (14:20–14:34 KST 창의 동일 리소스 로그는 사이 간격이 짧고 200 정상 응답).
- 실제 동작: 이 한 건은 11,449ms 로 완료 — permission_joins 서브쿼리 계획이 cold buffer/lock/large permission set 로 인해 튄 tail latency outlier.
Log Evidence#
Datadog query used:
service:cupixworks-api "WorkspacesController#show"
시간창: 2026-07-16 14:20:00–14:34:39 KST (동일 분기 로그)
동시간대 정상 #show 요청 예 (본 클러스터 요청과 같은 분에 발생, 모두 200 정상 완료):
{
"timestamp": "2026-07-16 14:28:47",
"status": "info",
"message": "[200] GET /api/v1/workspaces/1290 (Api::V1::WorkspacesController#show)"
}
{
"timestamp": "2026-07-16 14:29:32",
"status": "info",
"message": "[200] GET /api/v1/workspaces/5716 (Api::V1::WorkspacesController#show)"
}
Datadog query for concurrent errors (같은 15분 창):
service:cupixworks-api status:error
결과: 같은 시간창의 error 로그는 전부 Cupix::PubSub::Subscribers::UserRecipeGenerator 의 private method 'service_jwt' called for class Cupix::NotificationService — 본 클러스터(#show 지연)와 별개의 이슈이며 500 응답을 유발하지도 않았다.
{
"timestamp": "2026-07-16 14:34:26",
"status": "error",
"message": "processing 'facility_permission.full_permission_enabled' failed: private method `service_jwt' called for class Cupix::NotificationService",
"class": "Cupix::PubSub::Subscribers::UserRecipeGenerator"
}
APM 메트릭 (p95:trace.rack.request{...resource_name:api::v1::workspacescontroller#show}, max:..., avg:trace.rack.request.duration.by.resource_service.by.http_status_code{...}) 은 시계열이 비어 반환 — 이 서비스에서 해당 metric name 이 발행되지 않는다. 따라서 baseline 대비 얼마나 튀었는지는 duration 로그가 아닌 APM 트레이스 뷰(Datadog URL) 로만 확인 가능. sample_trace_id 3044730468254276793 로도 로그 검색 결과 0 건 (trace 상세는 APM 콘솔에서만 조회).
확인되지 않은 정보 (needs verification)#
- 문제 요청의 정확한
workspace_id,user_id, span breakdown — Datadog Logs API 만으로는 span-level 시간 분해를 얻을 수 없다. APM 콘솔의3044730468254276793트레이스 뷰에서 SQL/serialize/render 구간별 소요를 확인해야 한다. - 해당 요청 발생 순간의 tenant 별
workspace_permissions/team_permissions/grouped_users카운트 및 lock 상태 — DB 로그/EXPLAIN 필요. - Rails 프로세스 GC pause 나 인접 요청의 write lock 대기 여부.
Hypotheses Considered#
| # | Hypothesis | Evidence for | Evidence against | Verdict |
|---|---|---|---|---|
| H1 | permission_joins 6-LEFT-JOIN 쿼리의 tail latency outlier (cold plan / lock 대기 / 대형 permission 스캔) |
app/repositories/workspace_repository.rb:72-174 의 서브쿼리 구조; 같은 시간창의 다른 #show 는 정상 → permission_joins 의 tail 특성과 일치 |
span-level 증거 미확보 (APM 콘솔 필요) | Confirmed (with note) |
| H2 | 상위 트래픽 급증으로 인한 systemic latency | 클러스터 occurrence_count=1, 같은 분 다른 #show 는 정상 완료 |
시스템 전체 지연이었다면 occurrences 가 다수여야 함 | Rejected |
| H3 | 동시간대 error 로그 (private method 'service_jwt') 가 원인 |
같은 서비스에서 다수 발생 | 이 에러는 Pub/Sub subscriber(비동기) 에서 발생하고 500 을 유발하지 않으며 #show 경로와 무관 |
Rejected |
| H4 | 외부 의존성(S3/ES 등) 장애 | — | status-board 조회 시 active dep:* 인시던트 없음; error 로그도 dep 관련 아님 |
Rejected |
| H5 | set_current_workspace (app/models/concerns/properties/user.rb:23-42) 의 Workspace.find + cache 갱신 지연 |
show 성공 후 호출됨; workspace 이미 로드된 상태이므로 추가 find 없음 (Workspace 인스턴스 branch) | 정상 경로에서는 비용 낮음 | Rejected |
Fix Recommendation#
즉시 조치 (Critical)#
- 없음. 단일 occurrence 이고 200 정상 응답. 사용자 영향은 1건 세션의 11.4s 로딩 지연에 한정. 즉시 코드 변경은 불필요.
- APM 콘솔에서 trace
3044730468254276793를 열어 span 분해(예: SQL 쿼리 소요, ActiveRecord serialize, Elasticsearch 여부)를 확인하여 H1 을 span-level 로 최종 확정하는 것을 권장.
단기 개선 (1주 이내)#
Api::V1::WorkspacesController#show에 대한 APM p95/p99 알림 임계값을 확인하고, 11s 급 outlier 가 반복되는지 24–48h 관찰. 반복 시 tenant/workspace_id별 breakdown 으로 좁힘.app/repositories/workspace_repository.rb:72-174permission_joins의 인덱스 존재를 EXPLAIN 으로 검증:workspace_permissions(accessor_id, accessor_type, workspace_id),team_permissions(accessor_id, accessor_type, team_id),grouped_users(group_id, user_id). 특히LEFT JOIN안쪽 서브쿼리는 index-only scan 이 되도록 covering index 여부 확인.
장기 개선 (재발 방지)#
permission_joins는 단건 조회(show)에서도 index/list 조회와 동일한 6 서브쿼리를 실행한다.show경로용으로 workspace_id 를 서브쿼리 안에 밀어 넣어 미리 필터링하는 특화 경로를 별도로 두는 것을 검토(현재는.where(id: X)가 outer 에서만 적용되어 permission 서브쿼리는 user 전체 permission 을 스캔).- APM trace sampling 이 낮다면
resource_name:Api::V1::WorkspacesController#show에 대해 sampling rate 를 임시 상향해 outlier 재현 시 span-level 자료를 확보할 수 있게 설정.
Monitoring#
Timeseries 위젯용 Datadog 쿼리 (dashboard 에 그대로 삽입):
Api workspaces show p95 duration:
p95:trace.rails.request{service:cupixworks-api,resource_name:api::v1::workspacescontroller#show}
Api workspaces show p99 duration:
p99:trace.rails.request{service:cupixworks-api,resource_name:api::v1::workspacescontroller#show}
Slow request 발생률 (>5s):
sum:trace.rails.request.hits{service:cupixworks-api,resource_name:api::v1::workspacescontroller#show,duration:>5000000000}.as_count()
주의: 위 metric name (trace.rails.request) 은 서비스 계측 방식에 따라 다를 수 있어(trace.rack.request 실험 시 시계열 비어 반환) dashboard 반영 전에 Datadog Metrics Explorer 에서 trace. prefix 를 실제 발행되는 이름으로 확인 필요 — needs verification.
Risk Assessment#
- Risk level: low (단일 occurrence, 정상 200 응답, 즉시 사용자 영향 미미)
- 예상 복잡도: standard (즉시 코드 fix 불필요, APM trace 후속 검증 + monitoring 튜닝 위주)