prometheus stall

특정 클러스터1 prometheus 조회가 간헐적으로 stall(멈춤,지연)되는 현상이 발생했다.

버스트(동시에 여러 접속 시도)시에 주로 발생한다.

같은 구성의 k8s 클러스터2 prometheus 는 지연없이 조회 된다.

참고로 클러스터는 2개의 노드에 각각 prometheus pod 1개씩 떠있고, 데이터(메트릭)이 유입되면 각각 똑같은 데이터를 저장하게 된다.

버스트요청 - stress test 로 10개 쿼리 동시 요청 x n 번(round)시 반응

문제가 되는 클러스터1 - prometheus 일부 요청들 지연 응답 또는 연결 취소 발생

문제가 없는 클러스터2 - prometheus 모든 요청 정상 응답

체크 - 쿼리가 무거워서?

무거운 쿼리 1동시 요청은 괜찮았지만 vector(1) 8동시 요청을 하면 23%확률로 스톨된다.

체크 - 클러스터들간의 데이터량(pod) 80 vs 40) 차이나서?

클러스터 양쪽 메트릭을 사이즈 차이가 크지 않다.

체크 - 요청 부하(GC / 스로틀 / 메모리 / 디스크 등)?

파드/노드 지표 12h 그래프를 봐도 cpu, 메모리가 튀지는 않는다.

체크 - 존/랙 업링크등의 문제가 있나?

같은 존/랙 떠있을것으로 추정되는 노드의 grafana 연결은 지연이 없다.

체크 - 진입 노드 외부 구간

문제가 있는 노드1를 통해서 grafana 조회시 지연이 없다.

체크 - LB(VIP)1 경유시 

스톨 발생

체크 - 새로운 LB2 를 생성하고 서비스는 기존 prometheus 로 연결

스톨 발생

체크 - LB 미경유 nodeport 로 바로 조회

스톨 발생

체크 - cilium 패킷 drop 이 발생하나?

cilium 측정(cilium hubbl ui 서비스 portfowrading)시 패킷 드랍 없음

[원인]

클러스터1,2 모두 --web.max-connections 512 (디폴트)로 되어 있다.

문제가 되는 클러스터1 이 클러스터2 200 개 정도에 비해 2배정도 많은 400 개 정도다.

현재 prometheus 연결 수는 config-reload container 를 통해 다음 명령으로 확인

kubectl -context ysoftman1-context -n ysoftman-monitoring-stack \

 exec ysoftman-monitoring-stack-prometheus-1 -c config-reloader -- \

 sh -c 'awk "\$2 ~ /:2382\$/ && \$4==\"01\" {c++} END{print c+0}" /proc/net/tcp /proc/net/tcp6'

또는 다음 prometheus 매트릭/쿼리로 확인할 수 있다.

net_conntrack_listener_conn_accepted_total{listener_name="http"} - net_conntrack_listener_conn_closed_total

클러스터1,2 둘다 batch 로 promql 조회를 하고 있는데 이게 클러스트의 pod 의 비례해서 상대적으로 많은 pod 를 가진 클러스터의 트래픽이 2배가 됐다.

512까지 여유가 없는 상태에서 버스트 요청시 클러스터2 보다 상대적으로 accept 가 빨리 찬다.

1. prometheus 가 들고 있는(accept 된) 연결이 512 에 도달 -> prometheus LimitListener 가 accept 호출 자체를 연결 하나가 닫혀 슬롯이 반환될 때까지 멈춘다. 

2. 그 동안 들어오는 새 연결은 커널이 알아서 3-way handshake 를 완료하고 accept 대기열에 쌓아둔다. 클라이언트 입장에선 connect 성공(tcp= 15ms), 요청까지 전송

3. 하지만 prometheus가 accept 을 안 하니 클라이언트는 first-byte 무한 대기한다. 서버가 끊는 게 아니라 클라이언트가 중단하게 된다.

4. 기존 연결이 닫혀 슬롯이 나면 대기열에서 순서대로 accept 재개되고 밀렸던 연결들이 한꺼번에 처리 된다. 1~7초 동기 방출되는 prometheus 쿼리 자체는 15ms 로 금방 처리된다.

이미 accept 돼 있던 연결(scrape 로 다른 클러스터에 긁어 가고 있는 경우 keep-alive 재사용)은 이 제한과 무관하게 계속 동작한다.

그래서 서버 히스토그램 기존 트래픽은 내내 정상으로 보였고, 신규 연결만 지연으로 관측됐다.

[해결방법]

max-connections 을 늘리자. 디폴트 512는 너무 작고 2048 정도로 늘려도 무리가 없다.

helm chart 로 설정

kube-prometheus-stack:

 prometheusSpec:

  prometheus:

      web:

        maxConnections: 2048

(수동 적용시) argocd syncPolicy.automated (selfHeal 포함) 를 제거해서 auto-sync 끈다.

kubectl -n ysoftman-argocd patch application ysoftman-monitoring-stack \

 --type merge -p '{"spec":{"syncPolicy":{"automated":null}}}'

(수동 적용시) prometheus cr 변경하면 operator 감지해서 적용

kubectl -n ysoftman-monitoring-stack patch prometheus ysoftman-monitoring-stack-prometheus \

 -type merge -p '{"spec":{"web":{"maxConnections":2048}}}'

pod 에 적용 모습

spec:

  containers:

  - args:

    - --web.max-connections=2048

--web.max-connections 는 커맨드라인 플래그라 reload operator가 StatefulSet 템플릿을 바꾸면서 롤링 재시작 된다.(replicas: 2 로 쓰고 있어서 한 대씩 앞 pod 이 ready 된 후 다음 pod 진행)

StatefulSet volumeClaimTemplate 기반이라 pod 삭제와 무관하게 pvc/pv(local-path-retain)는 그대로 남고, 새 pod 가 같은 pvc 에 다시 붙는다.

local-path 특성상 pv 가 노드에 고정돼 있어 pod 도 같은 노드로 다시 스케줄된다.

pod1대 재시작 중 나머지 replica 가 조회/수집을 계속 받아서 전체적으로 메트릭 유실은 없다.

max-connections 을 늘린 후로 스톨이 발생하지 않는다.ㅎ

late.sh terminal clubhouse

ssh 접속하면 터미널 공간에서 채팅하고 음악도 듣고, 갤러리도 보고 만들고 게임도 하고 그런 휴식처가 late 다

https://github.com/mpiorowski/late-sh

# late 설치하고 접속

curl -fsSL https://cli.late.sh/install.sh | bash

late

kafka invalid timestamp error by pidstat

k8s 환경에서 프로세스등의 로그를 수집(collector pod) > json stdout(/var/log/pods/.../0.log) > filebeat > kafka cluster 로 흐름이 구축되어 있다.

그런데 자정(0시)에 가끔 collector CPU 90% 이 넘어가고 해소가 되지 않는다.

kafka(4.0.2) server.log 를 보면 다음과 같이 invalid timestamp 로 거부가 됐다.

kafka 디폴트로 메시지 1시간까지 허용하고 넘어가면 거부된다.

https://kafka.apache.org/40/generated/kafka_config.html#brokerconfigs_log.message.timestamp.after.max.ms

org.apache.kafka.common.errors.InvalidTimestampException: One or more records have been rejected due to invalid timestamp

collector 는 pidstat 커맨드로 수집을 하는데 pidstat 는 Time=HH:MM:SS 으로 날짜가 출력되지 않는다.

# -h : 한 줄 가로 출력, 평균 행 없음 (파싱용)

# -u : CPU

# -r : 메모리

# -d : 디스크 I/O

# -l : Command 에 전체 커맨드라인

# -I : CPU 사용률을 전체 코어 수로 나눔 (SMP 정규화)

# -T : TASK + CHILD 통계 모두

# -p : 대상 PID (discover 가 찾은 프로세스들)

pidstat -hurdl -I -T ALL -p <PIDs> <interval> <count>

# Time        UID       PID    %usr %system  %guest   %wait    %CPU   CPU  minflt/s  majflt/s     VSZ     RSS   %MEM   kB_rd/s   kB_wr/s kB_ccwr/s iodelay  Command

05:04:08        0       630    0.00    0.00    0.00    0.00    0.00     9      0.00      0.00    2228    1024   0.01      0.00      0.00      0.00       0  sleep 300

이 Time을 collector 에서 파싱해서 @timestamp 필드값을 설정한다.

# 파싱 과정

# local_to_utc() python 로직

dt = datetime.strptime(local_timestamp, "%H:%M:%S")

return datetime.now().replace(hour=dt.hour, minute=dt.minute, second=dt.second).astimezone(tz=timezone.utc)

# timestamp 필드 설정

obj["@timestamp"] = local_to_utc(obj.pop("Time")).strftime("%Y-%m-%dT%H:%M:%SZ")

# 문제가 되는 상황 예시

pidstat 출력 23:59:59.6 (8/15) -> Time="23:59:59"

파서 처리 시점 00:00:00.2 (8/16) -> now().date = 8/16 -> timestamp = 2026-0816T23:59:59Z

실제 측정 시각 8/15 23:59:59 대비 +24h이 지난 상태의 timestamp 가 된다.

+24h 메시지는 kafka 에서 거부하는데, collector 는 계속 재시도를 해 cpu 리소스가 높게 유지 된 것이다.

# 해결 시도

# pidstat 와 1초 정도밖에 차이 안나서 이렇게 파싱시 now 를 timestamp 로 사용할 수 있겠지만

# pidstat 이 한 주기에 프로세스 n개를 측정하고 있어 원래는 n개의 라인이 전부 Time 이 같아야 한다. 매번 now 로 조금씩 달라지면 배치 동일성이 깨진다.

obj["@timestamp"] = datetime.now(timezone.utc).strftime("%Y-%m-%dT%H:%M:%SZ")

# 해결 방법1

# +24(12시간 차이 정도로 하자)시간이 지난 경우 -1day 한다.

now = datetime.now()

ts = now.replace(hour=dt.hour, minute=dt.minute, second=dt.second, microsecond=0)

if ts - now > timedelta(hours=12):

    ts -= timedelta(days=1)

    logger.info(f"midnight rollover: Time={local_timestamp} -> {ts}")

return ts.astimezone(tz=timezone.utc)

# 해결 방법2

# pidstat 사용 안 하고 k8s 환경이면 이미 cAdvisor(ContainerAdvisor, kubelet 내장, 실행 중인 컨테이너들의 리소스 사용량과 성능 메트릭을 수집,처리,노출하는 도구)로 prometheus 에 메트릭이 있으니 이 값을 조회해서 사용한다.

# 메트릭들은 이미 같은 timestamp 로 저장되어 있다.

{"@timestamp": "2026-08-16T05:23:44Z", "%CPU": "0.88", "%usr": "35.59", "%system": "6.81", "RSS": "571528", "container": "ysoftman1-container", "pod": "ysoftman1-aaa"}

{"@timestamp": "2026-08-16T05:23:44Z", "%CPU": "0.88", "%usr": "35.59", "%system": "6.81", "RSS": "571528", "container": "ysoftman2-container", "pod": "ysoftman2-bbb"}

# 현재시각을 고정하고 이 값으로 prometheus 메트릭을 조회 하고 그대로 @timestamp 로 설정한다.

at = datetime.now(timezone.utc).timestamp()

ts = datetime.fromtimestamp(at, timezone.utc).strftime("%Y-%m-%dT%H:%M:%SZ")

# 어쩌다 발생해서 신경쓰였는데 원인 파악 돼서 개비스콘 짤로 남긴다.ㅎ