코드가 생각보다 느리게 실행된다면 속도 향상에 앞서 어떤 부분에 시간이 오래 걸리는지를 조사할 필요가 있다. 이런 목적으로 코드 성능을 평가하는 방법에는 system.time()을 사용해 간단히 함수의 수행 시간을 출력해보는 방법과 Rprof() 함수를 사용해 좀 더 본격적인 보고서를 출력해보는 방법이 있다.
명령문 실행 시간 측정
system.time()은 인자로 주어진 명령이 수행하는 데 걸린 시간을 측정한다.
-system.time : 표현식을 평가하는 데 걸린 CPU 시간을 구한다.
system.time(
expr #평가할 표현식
)
다음은 1부터 N까지 더하는 함수인 sum_to_n( )의 수행 시간을 N=10,000, N=100,000, N=1,000,000인 경우에 대해 각각 측정해본 예다.
| >sum_to_n<-function(n) { + sum <- 0 + for (i in 1:n) { + sum <- sum + i + } + return(sum) + } >system.time(sum_to_n(10000)) user system elapsed 0 0 0 >system.time(sum_to_n(100000)) user system elapsed 0.08 0.00 0.08 >system.time(sum_to_n(1000000)) user system elapsed 0.68 0.00 0.69 |
system.time()이 출력하는 수행 시간은 user time, system time, elapsed time으로 구분된다. 이 중 elapsed time이 가장 알기 쉬운 개념이다. 이 시간은 코드의 총 소요 시간으로, 코드를 시작한 직후부터 코드 수행이 끝날 때까지의 시간을 초시계로 쟀을 때 얼마나 걸렸는지를 나타낸다. 통상적으로 이야기하는 코드 수행 시간이 이에 해당한다.
user time, system time은 elapsed time을 구성하는 요소로, 각각 프로그램 코드 자체를 수행하는 데 걸린 시간과 프로그램이 운영체제의 명령을 호출했다면 그때 운영체제가 명령을 수행하는 데 걸린 시간을 의미한다.
프로그램이 운영체제의 명령을 호출하는 대표적인 예로는 파일 입출력이 있다. "파일 입출력" 절에서 살펴본 파일 입출력 명령을 사용해 큰 파일을 저장 및 로드해보고 이때 걸리는 시간을 측정해보자.
| >x<-matrix(1:(10000*10000), ncol=10000) >system.time(save(x, file="x.RData")) user system elapsed 75.49 0.56 76.05 >system.time(load(file="x.RData")) user system elapsed 2.81 0.20 3.01 |
위 결과를 보면 1부터 N까지의 숫자를 합하는 함수의 경우와 달리 system time이 크게 나타난 것을 볼 수 있다. 이는 파일 입출력을 위해 R 환경이 운영체제의 기능을 많이 호출해 사용하기 때문에 발생한 현상이다.
system time은 코드를 수행하는 머신의 메모리가 부족해 운영체제가 디스크의 일부를 메모리로 사용하는 페이징Paging이 빈번히 발생할 경우에도 증가할 수 있다. 따라서 system time이 크다면 메모리가 혹시 부족하지는 않은지 운영체제의 작업 관리자를 통해 잘 살펴봐야 한다.
이처럼 코드의 수행 시간을 측정할 수 있으면 다양한 구현 방법 중 어떤 방법이 더 나은 성능을 보이는지 평가할 수 있다. 한 가지 예로 "리스트를 데이터 프레임으로 변환하기" 절에서는 rbind()보다 rbindlist()가 성능이 더 나음을 system.time() 함수를 사용해 보인 바 있다.
코드 프로파일링
Rprof()는 좀 더 본격적인 코드 수행 성능 평가를 위한 함수다. prof는 Profiling을 의미하는데 소프트웨어 공학에서는 프로그램의 동적인 성능, 즉 메모리나 CPU 사용량을 평가하는 작업을 흔히 코드 프로파일링이라 부른다.
코드 프로파일링은 Rprof() 함수 호출로 시작한다. Rprof() 호출 이후에는 특정 시간 간격마다 현재 어떤 함수가 수행 중인지 샘플이 추출되어 파일에 저장된다. 파일에 기록된 결과는 이후 summaryRprof() 함수로 분석할 수 있다. 다음 표에 이들 함수에 대해 정리했다.
-Rprof : R코드 실행에 대한 코드 프로파일링을 활성화한다.
Rprof(
# 프로파일링 정보를 저장할 파일. 파일명이 지정되면 프로파일링이 시작되고
#NULL이 지정되면 프로파일링이 중단된다.
filename="Rprof.out",
append=FALSE, # 결과 파일에 프로파일링 정보를 덧붙일지 여부. FALSE면 파일을 덮어쓴다.
interval=0.02 # 프로파일링을 위한 샘플을 채취하는 시간 간격
)
-summaryRprof : R샘플링 프로파일러의 결과를 요약한다.
summaryRprof(
filename # 프로파일링 정보가 저장된 파일
)
다음은 주어진 벡터에 1을 더하는 비효율적인 함수에 대해 코드 프로파일링을 수행하는 예를 보여준다. 코드에서 seq_along()은 인자로 주어진 벡터의 길이만큼 1, 2, 3, …, N으로 구성된 숫자 벡터를 생성하는 함수다.
| >add_one<-function(val) { + return(val + 1) + } >add_one_to_vec<-function(x) { + for (i in seq_along(x)) { + x[i] <- add_one(x[i]) + } + return(x) + } >Rprof("add_one.out") >x <-add_one_to_vec(1:1000000) >head(x) [1] 2 3 4 5 6 7 >Rprof(NULL) |
코드를 실행하면 add_one.out이라는 파일이 생성된다. 결과를 분석하려면 Rprof()가 생성한 파일을 summaryRprof()에 넘겨주면 된다.
| >summaryRprof("add_one.out") $by.self self.time self.pct total.time total.pct "add_one" 3.08 50.49 3.32 54.43 "add_one_to_vec" 2.78 45.57 6.10 100.00 "+" 0.24 3.93 0.24 3.93 $by.total total.time total.pct self.time self.pct "add_one_to_vec" 6.10 100.00 2.78 45.57 "add_one" 3.32 54.43 3.08 50.49 "+" 0.24 3.93 0.24 3.93 $sample.interval [1] 0.02 $sampling.time [1] 6.1 |
summaryRprof()의 분석 결과는 크게 by.self와 by.total 두 섹션으로 나뉘는데, 이 두 섹션에 들어 있는 내용은 동일하다. 다만 by.self는 self.time으로 정렬된 표이고, by.total은 total.time으로 정렬된 표다. 따라서 설명의 편의를 위해 여기서는 by.self를 기준으로 살펴보기로 하자.
| >summaryRprof("add_one.out")$by.self self.time self.pct total.time total.pct "add_one" 3.08 50.49 3.32 54.43 "add_one_to_vec" 2.78 45.57 6.10 100.00 "+" 0.24 3.93 0.24 3.93 |
표에서 self.time은 각 함수가 수행하는 데 걸린 시간이다. add_one은 해당 함수 내 코드를 수행하는 데 3.08초가 소요되었으며, add_one_to_vec은 함수 내 코드를 수행하는 데 2.78초가 소요되었다. 코드 전체 수행 시간 대비 각 함수의 self.time 시간의 비율은 self.pct를 통해 알 수 있다.
total.time은 각 함수 내 코드를 수행하는 데 걸린 시간과 해당 함수가 호출한 함수를 수행하는 데 걸린 시간의 합이다. 예를 들어, + 연산은 self.time이 0.24초였다. + 연산자 자체는 단독으로 수행되므로 total.time도 0.24초다. 반면 add_one 함수는 해당 함수 내에서 val + 1 명령을 수행하기 위해 +를 호출한다. 따라서 add_one의 total.time은 자신의 self.time 3.08초에 +의 self.time 0.24초를 더한 3.32초다. 마찬가지로 add_one_to_vec은 해당 함수 내 코드를 수행하는 데 2.78초가 걸리고 여기에 add_one을 호출하므로 add_one의 total.time인 3.32초가 추가로 걸린다. 따라서 add_one_to_vec의 total.time은 2.78 + 3.32 = 6.10초다.
이처럼 summaryRprof()의 결과는 어떤 함수가 수행하는 데 얼마나 시간이 소모되는지를 좀 더 쉽고 분석적으로 나열해주므로, 어떤 함수에서 가장 긴 시간이 소모되는지를 판단할 수 있다. 만약 R 코드의 성능이 만족스럽지 못하다면 Rprof()를 사용해 소모 시간과 그 비율을 판단하고 가장 긴 시간이 걸리는 항목부터 개선해나감으로써 더 과학적인 성능 개선을 이룰 수 있다.
Rprof()에는 여기에서 설명하지 않은 메모리 프로파일링 등의 다양한 옵션이 있으므로 코드 성능 평가 시 help(Rprof)를 살펴보기 바란다.
R을 이용한 데이터 처리&분석 실무 中
'R > R을 이용한 데이터 처리&분석 실무' 카테고리의 다른 글
| 기초 통계량 (0) | 2020.02.04 |
|---|---|
| 난수 생성 및 분포 함수 (0) | 2020.02.04 |
| 데이터 구조의 변형과 요약 (0) | 2020.02.03 |
| 데이터 정렬 (0) | 2020.02.03 |
| 데이터 분리 및 병합 (0) | 2020.02.03 |
