동기화 딜레이 시간 개선

문제 상황

각 사용자 간의 게임 진행 중 한 사용자의 작업, 음악 선택 제출, 허밍 제출, 정답 제출 등, 이후 다른 사용자의 디바이스에 해당 작업이 동기화되기까지 딜레이 시간 발생.

테스트 과정

측정 방법

여러 사용자 간의 게임 진행 중, 한 사용자가 제출한 결과가 다른 사용자에게 전달되기까지의 시간을 어떻게 측정할 수 있을까?

1. 서버에서 A 사용자의 제출을 받은 시간 기록, 다른 사용자로부터 요청을 받은 시간을 기록하여 그 차로 측정 -> 파이어베이스를 수정해야한다는 문제 발생.

2. Date()로 클라이언트 측 로그로 시간 간격 측정 -> 많은 로그 중 특정 로그를 하나씩 파악하고, 시간을 비교하는 과정이 필요해지지만 제출 버튼을 누른 시점부터 다른 사용자가 받은 시점을 계산할 수 있음.

서버를 만질 수 없는 당장에 가능한 방법은 2번. 하지만, 서로 다른 디바이스의 로그를 어떻게 확인할 것인가?

로그 확인 방법

로그 확인 방법은 다음과 같이 총 3 가지 방법이 있다.

1. CLI에서 명령어를 사용하여 특정 시뮬레이터의 로그를 확인 (시뮬레이터 UUID를 확인하고 다시 명령어로 해당 시뮬레이터의 로그를 확인하는 방법)

-> 보기가 매우 불편하다는 문제 발생.

2. Instrument 앱에서 os_log를 추가하여 확인

-> Time Profiler 등 문제의 원인을 함께 파악할 수 있지만, 초 단위의 차이를 파악하기 어렵고 측정에 있어 시간이 많이 소요됨.

3. macOS의 Console 앱을 사용하여 로그를 확인 (print문이 아닌 NSLog 등을 사용해야 확인 가능) (프로세스를 기준으로 alsongDalsong을 검색하여 필터링)

-> filter를 사용하면 시뮬레이터, 연결된 실기기의 로그를 모두 확인할 수 있고, 초 단위의 측정 또한 가능하다.

동기화가 필요한 상황

다음 버튼이 있는 경우는 다음과 같다.

1. 노래선택 후 선택완료
2. 허밍 후 제출하기
3. 정답 선택 후 정답 제출
4. 정답 확인 후 다음
5. 모든 정답 확인 후 종료

각 버튼의 액션에 Date()를 출력하는 NSLog 문을 추가하고,

상대방의 액션을 받아 처리하는 부분에 마찬가지로 NSLog 문을 추가한다.

• 네비게이션 시간 확인

    private func updateViewControllers(state: GameState) {
        let viewType = state.resolveViewType()
        switch viewType {
            case .submitMusic:
                NSLog("음악 선택 화면 시작: \(Date())")
                navigateToSelectMusic()
            case .humming:
                NSLog("허밍 화면 시작: \(Date())")
                navigateToHumming()
            case .rehumming:
                NSLog("리허밍 화면 시작: \(Date())")
                navigateToRehumming()
            case .submitAnswer:
                NSLog("정답제출 화면 시작: \(Date())")
                navigateToSubmitAnswer()
            case .result:
                NSLog("결과 화면 시작: \(Date())")
                navigateToResult()
            case .lobby:
                NSLog("로비 화면 시작: \(Date())")
                navigateToLobby()
            default:
                break
        }
    }

1. 노래선택 후 선택완료: 순서: submit 버튼 → VM → AnswerRepository → Network → ASFirebaseDatabase listener → MainRepository status → PlayersRepository → VM Binding → UI Update → GameStateRepository → GameNavigationController → Humming

• 제출 선택 버튼

    private func showSubmitMusicLoading() {
        NSLog("음악 선택 제출 버튼 클릭: \(Date())")
        let alert = LoadingAlertController(
            progressText: .submitMusic,
            loadAction: { [weak self] in
                try await self?.submitMusic()
            },
            errorCompletion: { [weak self] error in
                self?.showFailSubmitMusic(error)
            })
        presentAlert(alert)
    }

• VM

    private func bindSubmissionStatus() {
        let playerPublisher = playersRepository.getPlayersCount()
        let answersPublisher = answersRepository.getAnswersCount()

        playerPublisher.combineLatest(answersPublisher)
            .receive(on: DispatchQueue.main)
            .sink { [weak self] playersCount, answersCount in
                NSLog("팀원 음악 선택 완료 반영: \(Date())")
                let submitStatus = (submits: String(answersCount), total: String(playersCount))
                self?.submissionStatus = submitStatus
            }
            .store(in: &cancellables)
    }

2. 허밍 후 제출하기: 순서: Submit 버튼 → VM → RecordsRepository uploadRecording → MainRepo postRecording → Network → Database → MainRepository Status (players) → playerRepository → VM → UI

• Submit 버튼

    private func showSubmitHummingLoading() {
        NSLog("1차 허밍 제출 \(Date())")
        let alert = LoadingAlertController(
            progressText: .submitHumming,
            loadAction: { [weak self] in
                try await self?.submitHumming()
            },
            errorCompletion: { [weak self] error in
                self?.showFailSubmitMusic(error)
            }
        )
        presentAlert(alert)
    }

• VM

    private func bindSubmissionStatus(with recordOrder: UInt8) {
        let playerPublisher = playersRepository.getPlayersCount()
        let recordsPublisher = recordsRepository.getRecordsCount(on: recordOrder)

        playerPublisher.combineLatest(recordsPublisher)
            .receive(on: DispatchQueue.main)
            .sink { [weak self] playersCount, recordsCount in
                NSLog("팀원 허밍 완료 반영: \(Date())")
                let submitStatus = (submits: String(recordsCount), total: String(playersCount))
                self?.submissionStatus = submitStatus
            }
            .store(in: &cancellables)
    }

3. 정답 선택 후 정답 제출:

• 정답 제출

    private func showSubmitAnswerLoading() {
        NSLog("정답 제출 \(Date())")
        let alert = LoadingAlertController(
            progressText: .submitMusic,
            loadAction: { [weak self] in
                try await self?.submitAnswer()
            }
        ) { [weak self] error in
            self?.showFailSubmitMusic(error)
        }
        presentAlert(alert)
    }

• VM

    private func bindSubmissionStatus(with recordOrder: UInt8) {
        let playerPublisher = playersRepository.getPlayersCount()
        let submitsPublisher = submitsRepository.getSubmitsCount()

        playerPublisher.combineLatest(submitsPublisher)
            .sink { [weak self] playersCount, submitsCount in
                NSLog("팀원 정답 완료 반영: \(Date())")
                let submitStatus = (submits: String(submitsCount), total: String(playersCount))
                self?.submissionStatus = submitStatus
            }
            .store(in: &cancellables)
    }

나머지도 위와 동일하게 버튼 선택 부분과 결과를 받는 ViewModel 부분에 NSLog를 추가.

테스트 결과

시뮬레이터 - 시뮬레이터

• 1회 단독 진행

  메인 디바이스 : iPhone 16 Pro Max(18.0)

  1번 디바이스 : iPhone 16(18.0)

  <1차> 16이 호스트, 버튼 우선 선택은 16이 동일하게 진행.

  	16	16 Pro Max	시간 경과
  로비 화면 시작	09:56:14.546358	09:56:35.846932
  게임 시작 버튼 클릭	09:56:41.536243
  음악선택 화면 시작	09:56:44.671335	09:56:44.671256	약 3.1초
  음악 선택 완료 제출	09:56:58.017808
  음악 선택 완료 반영		09:57:00.585999	약 2.5초
  음악 선택 완료 제출		09:57:08.029330
  허밍 화면 시작	09:57:08.668318	09:57:08.668257	약 0.6초
  허밍 제출	09:57:24.680567
  팀원 허밍 완료 반영		09:57:30.587359	약 5.9초
  허밍 제출		09:57:40.581528
  정답 제출 화면 시작	09:57:43.819453	09:57:43.819694	약 3.2초
  정답 제출	09:57:57.586277
  정답 제출 반영		09:57:59.968472	약 2.4초
  정답 제출		09:58:07.896287
  결과 화면 시작	09:58:08.474395	09:58:08.474395	약 0.6초
  다음 정답 선택	09:58:53.307318
  결과 화면 시작	09:58:55.754285	09:58:55.752214	약 2.4초
  종료 선택	09:59:29.713690
  로비 화면 시작	09:59:32.439121	09:59:32.439270	약 2.7초

  <2차> 16 Pro Max가 호스트, 우선 제출도 동일하게 진행.

  	16	16 Pro Max	시간 경과
  로비 화면 시작	10:30:19.233820	10:29:52.000248
  게임 시작 버튼 클릭		10:30:16.149988
  음악선택 화면 시작	10:30:19.234100	10:30:19.234333	약 3초
  음악 선택 완료 제출		10:30:31.300359
  음악 선택 완료 반영	10:30:33.771752		약 2.5초
  음악 선택 완료 제출	10:30:40.531218
  허밍 화면 시작	10:30:41.112473	10:30:41.111114	약 0.58초
  허밍 제출		10:30:54.638113
  팀원 허밍 완료 반영	10:31:00.423475		약 5.8초
  허밍 제출	10:31:09.216072
  정답 제출 화면 시작	10:31:13.364888	10:31:13.363770	약 4.15초
  정답 제출		10:31:25.547763
  정답 제출 반영	10:31:28.040887		약 2.5초
  정답 제출	10:31:36.791060
  결과 화면 시작	10:31:37.461467	10:31:37.461467	약 0.7초
  다음 정답 선택		10:32:12.186389
  결과 화면 시작	10:32:14.744651	10:32:14.744625	약 2.56초
  종료 선택		10:32:44.042500
  로비 화면 시작	10:32:46.991545	10:32:46.991451	약 2.95초

  2인 기준, 두 번의 테스트 결과

  • 호스트의 게임시작 버튼 클릭 - 게임 시작(음악 선택 제출 화면 시작) : 약 3초
  • A의 음악 선택 제출 - B에게 제출 반영 : 약 2.5초
  • B의 음악 선택 제출 - A에게 제출 반영(허밍 제출 화면 시작) : 약 0.6초
  • A의 허밍 완료 제출 - B에게 제출 반영 : 약 6초 // 첫 제출이 반영되기까지의 시간
  • B의 허밍 완료 제출 - A에게 제출 반영(정답 제출 화면 시작) : 약 3 - 4초
  • A의 정답 제출 - B에게 제출 반영 : 약 2.5초
  • B의 정답 제출 - A에게 제출 반영(첫 번째 결과 화면 시작) : 약 0.7초
  • A의 다음 결과 화면 시작 버튼 클릭 - 다음 화면 시작 : 약 2.5초
  • A의 종료 버튼 클릭 - 로비 화면 시작 : 약 2.8초

• 1회 진행 후 2회차 진행

  호스트 디바이스: XR(17.2)

  게스트 디바이스: 16 Pro Max

  <1차>

  	Xr	16 Pro Max	시간 경과
  게임 방 생성 버튼 클릭	32:01.827759
  로비 화면 시작	32:02.813672		0.99
  게임 참가하기 버튼 클릭		32:17.688832
  로비 화면 시작		32:18.424525	0.94
  게임 시작 버튼 클릭	32:23.465997
  음악 선택 화면 시작	32:24.672267	32:24.674782	1.21
  음악 제출 버튼 클릭		32:39.810347
  팀원 음악 제출 반영	32:40.360450		0.56
  음악 제출 버튼 클릭	32:51.059822
  허밍 화면 시작	32:51.340081	32:51.340010	0.28
  허밍 제출 버튼 클릭		33:07.770625
  팀원 허밍 제출 반영	33:10.703749		2.93
  허밍 제출 버튼 클릭	33:12.669548
  정답 제출 화면 시작	33:16.562576	33:16.562165	3.89
  정답 제출 버튼 클릭		33:28.475096
  팀원 정답 제출 반영	33:29.330843		0.86
  정답 제출 버튼 클릭	33:35.478667
  결과 화면 시작	33:36.030591	33:36.033597	0.55
  종료 선택	34:45.280873
  로비 화면 시작	34:45.933259	34:45.933407	0.65

시뮬레이터 - 실 기기

호스트 디바이스: XR 시뮬레이터

게스트 디바이스: 15 (18.0)

<1차>

	Xr	15	시간 경과
게임 방 생성 버튼 클릭	54:42.892581	휘발
로비 화면 시작	55:27.024996
게임 참가하기 버튼 클릭
로비 화면 시작
게임 시작 버튼 클릭	56:02.379997
음악 선택 화면 시작	56:06.320310
음악 제출 버튼 클릭
팀원 음악 제출 반영	56:29.451523
음악 제출 버튼 클릭	56:34.237663
허밍 화면 시작	56:34.964433
허밍 제출 버튼 클릭
팀원 허밍 제출 반영	56:57.598020
허밍 제출 버튼 클릭	57:03.118634
정답 제출 화면 시작	57:06.311522
정답 제출 버튼 클릭
팀원 정답 제출 반영	57:28.834393
정답 제출 버튼 클릭	57:30.771354
결과 화면 시작	57:31.321197
종료 선택	58:41.769697
로비 화면 시작	58:44.960232

<2차>

	Xr	15	시간 경과
게임 방 생성 버튼 클릭
로비 화면 시작	58:44.960232
게임 참가하기 버튼 클릭
로비 화면 시작		58:42.825437
게임 시작 버튼 클릭	58:53.501585
음악 선택 화면 시작	58:54.561814	58:52.421041	?
음악 제출 버튼 클릭		59:05.971514
팀원 음악 제출 반영	59:08.672724		2.70
음악 제출 버튼 클릭	59:14.021922
허밍 화면 시작	59:14.588166	59:12.442286	?
허밍 제출 버튼 클릭		59:28.226725
팀원 허밍 제출 반영	59:37.397793		9.17
허밍 제출 버튼 클릭	59:39.502202
정답 제출 화면 시작	59:42.662976	59:40.528762	1.03
정답 제출 버튼 클릭		59:53.532880
팀원 정답 제출 반영	59:56.270586		2.74
정답 제출 버튼 클릭	00:03.497533
결과 화면 시작	00:04.028354	00:01.891941	?
종료 선택	01:14.199053
로비 화면 시작	01:14.757338	01:12.624466	?

원인 (아이디어)

1. Task가 제대로 관리되지 않았고, Queue에 너무 많은 작업이 있고, 이로 인해 딜레이 발생 가능성 + 로비 이후 게임 과정의 모든 화면에 필요한 VC와 VM이 deinit되지 않아 그 안의 Task가 계속 돌아가고 있을 가능성
2. 메모리/디스크에 계속 데이터가 쌓이다 보니 이로인한 성능 감소 가능성
3. Constraints의 충돌로 인한 UI update 시간 지연 발생 가능성

해결방안 (아이디어)

• Task 관리 방법 개선 및 필요없는 화면 deinit 고려
• 메모리/디스크에 쌓인 데이터 삭제 및 누수 개선
• 캐싱 데이터 관리 방법 개선
• Constraints 재계산

요약

동기화가 필요한 부분, 특히 허밍 제출을 동기화 하는 부분,에서 약 2~6초 혹은 그 이상까지 케이스에 따라 시간 지연 발생.

이에 대한 원인으로는

1. 관리되지 않은 Task로 인한 너무 많은 작업,
2. 필요없는 뷰가 deinit 되지 않고 남아있는 상황,
3. 메모리/디스크에 데이터가 누적되어 쌓이는 문제,
4. 메모리 누수,
5. 그리고 Constraints 오류가 있다.