log weekly november 2024 multi threading thread transaction idle in transaction

유휴 트랜잭션

2024년 11월 29일 금요일

Today I Learned

날짜

2024년 11월 29일 금요일

내용

무한증식 커넥션

그저께, 커넥션 풀 문제가 생겨 한도를 늘려줘서 해결했다. 그런데 갑작스레 오늘 점심 쯤에 같은 오류가 발생했다. 그렇게 유저가 바글바글하지도 않은데 뭐지 싶어 RDS에서 커넥션 풀 그래프를 찾아봤다.

1

처음 50정도로 늘렸을 때 였다가 그저께 올리자마자 급격히 상승해서 유지됐다. 항상 연결이 많은걸로 보이는데, 피크타임도 없이 그렇다는게 뭔가 납득이 안됐다. RDS에서 어떤 경고(?)가 떠서 확인해보니

2

유휴 상태로 쓰이지 않는 트랜잭션이 너무 많이 유지되고 있다는 에러다. 유휴 상태는 데이터베이스에 접속해서 현재 유휴 상태인 트랜잭션을 확인했다.

1
2
3

SELECT pid, usename, state, query, age(query_start), datname
FROM pg_stat_activity
WHERE state = 'idle in transaction';

  • 메시지

    7390 instgram_prod idle in transaction SELECT instagram_product.id, instagram_product.price, instagram_product.inventory, instagram_product.image_url, instagram_product.origin_id, instagram_product.title, instagram_product.handle, instagram_product.created_at, instagram_product.updated_a + -02:24:32.972911 postgres
          FROM instagram_product +    
          WHERE instagram_product.origin_id = ‘1483381637173’    
    23084 instgram_prod idle in transaction SELECT instagram_product.id, instagram_product.price, instagram_product.inventory, instagram_product.image_url, instagram_product.origin_id, instagram_product.title, instagram_product.handle, instagram_product.created_at, instagram_product.updated_a + -02:38:05.720898 postgres
          FROM instagram_product +    
          WHERE instagram_product.origin_id = ‘8073092628733’    

작동되는 쿼리를 보니 쇼피파이 상품 수정 웹훅에서 호출되는 것 같다. 실제로 이 문제로 인해 가장 오류가 많이 발생하는 엔드포인트기도 하다. 이런 유휴 상태의 트랜잭션이 70여개가 넘어, 우선 직접 종료해주었다.

1
2
3
4
5

# 현재 연결을 제외하고 유휴 상태의 트랜잭션 종료
SELECT pg_terminate_backend(pid)
FROM pg_stat_activity
WHERE state = 'idle in transaction'
AND pid <> pg_backend_pid();

맨 위의 사진에서도 보이지만 이 이후 급격하게 내려갔다. 이제 왜 그랬는지를 찾고 재발을 방지해야 하는데..

웹훅이 멀티스레드로 실행되기 때문인 것 같다. 서버에서 요청이 호출될 때 종속성을 이용해 데이터베이스를 호출하고 로직이 끝날때 종료한다. 백그라운드에서 작동하는 로직은 별도의 쓰레드로 처리된다. 따라서 요청에서 주입된 세션이 백그라운드에도 적용될 경우, 트랜잭션이 유휴 상태에 빠질 수 있다고 한다.

이를 방지하기 위해, 백그라운드로 로직을 돌릴땐, 요청의 생명주기와는 독립적으로 세션을 관리하도록 코드를 변경했다.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43

# 기존 코드
@router.post("/webhook")
def get_webhook(
	webhook_data,
	background_tasks: BackgroundTasks
	db : Session = Depends(get_db)
):
	background_tasks.add_task(
		delete_data_from_database,
		data=webhook_data,
		db=db
	)
	
def delete_data_from_database(
	data: dict,
	db: Session
):
	stmt = delete(models.User).where(models.User.id == data.id)
	db.execute(stmt)
	db.commit()  # 이 함수가 별도의 쓰레드에서 처리되어서 커밋 후에도 연결이 유지됨
	return True
	

# 개선 코드
@router.post("/webhook")
def get_webhook(
	webhook_data,
	background_tasks: BackgroundTasks
	db : Session = Depends(get_db)
):
	background_tasks.add_task(
		delete_data_from_database,
		data=webhook_data,
	)

def delete_data_from_database(
	data: dict,
):
	with SessionWriteLocal() as db:  # with 문이 종료되면 자동으로 db.close()
		stmt = delete(models.User).where(models.User.id == data.id)
		db.execute(stmt)
		db.commit()
		return True

3

일단 수동 삭제후 다시 증가하던 트랜잭션이 다시 감소중..

회고

이거.. 맞겠지…?

CATALOG
    weekly