TECH ARTICLE

PHP Session Locking: PHP Session 장애 재현 및 해결 방법

이 글은 PHP Session Hang 장애를 직접 재현해 보고 왜 이런 문제가 발생하는지, 어떻게 이 문제를 해결할 수 있는지 설명합니다. 글 하단의 결론만 읽으셔도 충분합니다. 이제 장애를 재현해 보겠습니다.

Session을 사용하지 않았을 때

다음 PHP 스크립트를 작성합니다.

<?php
    function useful_function() {
        sleep(1);
    }
    useful_function();
?>

ab 명령을 이용해 first.php로 동시에 10개 요청을 서버에 보냅니다.

ab -c 10 -n 10 http://localhost:8999/first.php

결과는 다음과 같습니다.

...
Concurrency Level:      10
Time taken for tests:   1.003 seconds
Complete requests:      10
...

1초가 걸리는 요청을 동시에 10개 수행했으니, 위 ab 명령어의 수행 시간은 당연히 1초입니다.

PHP Session을 사용했을때

이제 Session을 사용해 요청자의 페이지 방문 횟수를 보여주는 기능을 추가하겠습니다.

<?php //session_test1.php
    function useful_function(){
        sleep(1);
    }
    session_start();
    if(isset($_SESSION['visit_count'])===FALSE){
        $_SESSION['visit_count'] = 1;
    }
    else{
        $_SESSION['visit_count'] += 1;
    }
    $visit_count = 'visit_count = '.$_SESSION['visit_count'];
    echo $visit_count;
    aries_add_message_profile($visit_count); //add 'visit_count' to jennifer profiles
    useful_function();
?>

curl 호출을 통해 단일 요청의 결과를 확인했을때 결과는 다음과 같습니다.

curl -v http://localhost:8999/session_test1.php
*   Trying 127.0.0.1...
...
< HTTP/1.1 200 OK
< Date: Wed, 05 Dec 2018 05:34:53 GMT
< Server: Apache/2.2.22 (Ubuntu)
< Set-Cookie: PHPSESSID=lmrfduhgfm6oik62fi2c9q4ek7; expires=Wed, 05-Dec-2018 13:34:53 GMT; path=/
< Expires: Thu, 19 Nov 1981 08:52:00 GMT
...
visit_count = 1%  

응답으로 visit_count=1이 주어졌습니다. HTTP 응답 쿠키에  PHPSESSID=lmrfduhgfm6oik62fi2c9q4ek7이 추가된 것으로 보아 PHP 기본 Session 핸들러는 Cookie를 사용하며, PHPSESSID 쿠키 값이 Session 식별자로 사용됨을 알 수 있습니다. 다시 한번 curl을 요청을 보내되, Cookie에 PHPSESSID를 넣어 보내겠습니다.

curl --cookie "PHPSESSID=lmrfduhgfm6oik62fi2c9q4ek7" http://localhost:8999/session_test1.php
...
visit_count = 2%  

응답으로 visit_count=2 를 얻었습니다. 새로 만든 기능은 잘 동작하고 있네요. 이제 웹 서버에 어떤 일이 벌어졌는지 확인해보겠습니다. ls /tmp 를 실행해보면 lmrfduhgfm6oik62fi2c9q4ek7 파일이 존재함을 알 수 있습니다. 해당 파일의 내용은 다음과 같은데, 이것으로 세션이 어떻게 저장되는지 확인할 수 있습니다.

visit_count|i:2;

PHP 세션 장애 재현 Case 1

Cookie로 PHPSESSID를 지정해 동시에 10개 요청을 보냅니다. 그리고 어떤 일이 벌어지는지 확인해보겠습니다.

ab -c 10 -n 10 -C PHPSESSID=lmrfduhgfm6oik62fi2c9q4ek7 http://localhost:8999/session_test1.php
...
Concurrency Level:      10
Time taken for tests:   10.006 seconds
Complete requests:      10
...

Session기능을 넣지 않았을때 ab 명령의 수행 시간은 1초였습니다. 같은 Session ID로 동시에 10개의 요청을 보내니 10초가 걸렸습니다. 이때 JENNIFER X-View는 다음과 같습니다.

위 그림에서 X 축은 요청 시간(Request Time)이며, Y축은 처리 시간(Elapsed Time)입니다. 10개 요청은 모두 동일한 시간에 들어왔으나 처리된 시간은 각각 다르다는 사실을 알 수 있습니다.

트랜잭션의 상세 내용을 보면 시작시간은 모두 16:12:52 090 으로 차이가 없으나 응답시간은 1초, 2초, 3초, 4초, … 10초 입니다. 그리고 마지막으로 처리된 요청의 session_start 함수의 수행 시간이 9초가 걸렸네요. 위 현상이 관찰되는 까닭은 File session handler가 Race Condition을 피하기 위해 Session 파일을 잠그기 때문입니다. (링크) 이는 실시간 콜스택을 확인해 보면 확실히 드러납니다. (현재 실행중인 함수가 Lock을 얻기 위해 사용되는 flock 임에 주목해 주세요)

사용자가 동시에 요청을 보내지 않으니, 이런 일은 벌어지지 않는다구요? 그렇지 않습니다. 이런 시나리오를 상상해 봅니다. 로그인한 사용자가 브라우저로 요청을 보냈습니다. 그런데 해당 사이트의 응답이 느려 사용자가 F5를 눌러 재 요청을 보냅니다. 그래도 응답이 오지 않아 계속 F5를 반복해 누릅니다. 그 결과 사용자가 재 요청 보낸 수 만큼 아파치 프로세스가 생성되며(아파치 Prefork 모드의 경우) 이는 자원 고갈로 이어질 수 있습니다. (100번 재요청 했다고 상상해보세요)

 PHP 세션 장애 재현 Case 2

문제를 좀 더 심각하게 만들어 보겠습니다. useful_function에 기능을 추가하되, 그 기능을 위해 db connection이 필요하다고 가정하겠습니다.

<?php //session_test2.php
    function useful_function($db){
        sleep(1);
    }
    $db = mysql_connect('...');
    session_start();
    if(isset($_SESSION['visit_count'])===FALSE){
        $_SESSION['visit_count'] = 1;
    }
    else{
        $_SESSION['visit_count'] += 1;
    }
    $visit_count = 'visit_count = '.$_SESSION['visit_count'];
    echo $visit_count;
    aries_add_message_profile($visit_count); 
    useful_function($db);
?>

session_start() 전에 mysql_connect를 호출했습니다. 이 경우 한 Session의 요청이 동시에 N번 호출되면 DB Connection 수 또한 N개 만큼 증가 합니다. 이를 피하기 위해선 session_start 전에 자원을 획득하지 않아야 합니다.

DB 자원을 session_start() 호출 후 얻게 코드를 수정 했을때 Active DB Connection 차트는 다음과 같습니다. DB 커넥션 수가 1로 유지됨을 알 수 있습니다.

session_write_close를 이용한 문제 해결

PHP.net은 위 사항에 대해 경고 하고 있고 이에 대한 해결 방법도 제안하고 있습니다.

  1. read_and_close 옵션과 함께 session_start 함수를 사용하라. (PHP 7.0 이상만 이 옵션을 사용할 수 있습니다.)
  2. 세션 데이터를 수정한 후 가능한 빨리 session_commit 또는 session_write_close를 사용해 session lock을 해제해라.

여기서는 2번 방법을 택해 문제를 해결하도록 하겠습니다.

<?php
    function useful_function($db){
        sleep(1);
    }
    session_start();
    if(isset($_SESSION['visit_count'])===FALSE){
        $_SESSION['visit_count'] = 1;
    }
    else{
        $_SESSION['visit_count'] += 1;
    }
    session_write_close(); //release session lock
    $visit_count = 'visit_count = '.$_SESSION['visit_count'];
    echo $visit_count;
    $db=mysql_connect('...'); 
    aries_add_message_profile($visit_count); 
    
    //Change _SESSION['visit_count']
    $_SESSION['visit_count'] = 'write data after session_write_close()'; 
    aries_add_message_profile($_SESSION['visit_count']); 
    useful_function($db);
?>

이렇게 프로그램을 수정한 후 동시에 10개 요청을 보내겠습니다.

ab -c 10 -n 10 -C PHPSESSID=lmrfduhgfm6oik62fi2c9q4ek7 http://localhost:8999/session_test3.php
...
Concurrency Level:      10
Time taken for tests:   1.007 seconds
...

문제가 해결되었네요. 동시에 모든 요청이 처리되었습니다. 단, 주의점이 있습니다. 위 코드는 session_write_close() 호출 이후 $_SESSION[‘visit_count’]를 수정하고 있습니다. 어떻게 동작할까요? Jennifer 프로파일을 확인해보겠습니다.

$_SESSION[‘visit_count’] 값이 ‘write data after session_write_close()’로 수정된것을 확인할 수 있습니다. 이제 /tmp 에 저장된 sess파일의 내용을 확인해봅시다.

cat /tmp/sess_lmrfduhgfm6oik62fi2c9q4ek7 
visit_count|i:40;

visit_count 값이 ‘write data after session_write_close()‘가 아니라 40인 것을 알 수 있습니다. 이것으로 session_write_close() 호출 이후 수정된 $_SESSION 변수 값은 요청이 처리되는 동안 유효하나, Session 데이터에 기록되지 않는 다는 사실을 알 수 있습니다. 이것이 session_write_close 해법의 단점입니다. 만약 session을 수정하고 사용하는 코드가 여러 곳에 흩어져 있다면 이 방법을 적용하기 까다로우며, 실수했을 경우 사용자가 보는 값과 실제 Session에 저장된 값이 다를 수 있습니다.

Redis Session Handler를 사용해 문제 해결

이번에는 Session을 잠그지 않는 Redis 세션 핸들러를 사용해 문제를 해결해보겠습니다.(option으로 Lock을 사용하게 할 수도 있습니다.) 위에 정의한 session_test2.php(session_write_close를 사용하지 않는 스크립트)를 동시에 10번 호출합니다.

ab -c 10 -n 10 -C PHPSESSID=lmrfduhgfm6oik62fi2c9q4ek7 http://localhost:8999/session_test2.php
...
Concurrency Level:      10
Time taken for tests:   1.006 seconds

Lock으로 인한 문제는 사라졌습니다. 모든 요청이 동시에 처리되었네요. Session Data도 확인해 봅니다.

# redis-cli
127.0.0.1:6379> KEYS *
1) "PHPREDIS_SESSION:lmrfduhgfm6oik62fi2c9q4ek7"
127.0.0.1:6379> GET "PHPREDIS_SESSION:lmrfduhgfm6oik62fi2c9q4ek7"
"visit_count|i:6;"
127.0.0.1:6379> v

Session 데이터가 저장되어 있음을 알 수 있습니다. 그런데 visit_count가 10이 아니라 6으로 기록 되어 있습니다. Lock을 사용하지 않았기에 동시성 문제가 발생한 것입니다. 이것이 Lock을 사용하지 않는 Session Handler의 단점입니다. Redis Session Handler를 Lock 없이 사용하기로 했다면 이를 알고 있어야 하며 Session에 저장된 값이 무결(Integrity)할 것이란 기대를 하지 않아야 합니다. 그리고 무결성을 요구하는 데이터를 Session에 저장하지 않아야 합니다.

Framework, Library의 단순한 사용은 해결책이 될 수 없습니다.

위는 CodeIgniter에서 session 핸들러로 database를 지정했을때 확인 가능한 프로파일 입니다. session_handler로 database를 사용하게 했습니다. 따라서 session_start 함수 전에 DB_CONNECTION이 호출 되어야만 합니다. SQL Query를 확인해보니 Lock을 사용하고 있으며 session_start() 메소드 호출이 2초 이상 걸린 것으로 보아 Lock으로 인한 문제가 발생하고 있음을 알 수 있습니다. 위를 재현하기 위해 사용한 CodeIgniter Controller 코드는 아래와 같습니다.

<?php
class Welcome extends CI_Controller {
	function __construct(){
		parent::__construct();
		$this->load->library('session');
	}
	public function index()
	{
		sleep(1);
		$this->load->view('welcome_message');
	}
}

이 단순한 코드에 session_start 와 session_write_close가 감춰져 있다는 사실이 놀랍습니다. 혹시 CodeIgniter Session을 사용하고 있다면 CodeIgniter/A note about concurrency 단락을 읽어보시기 바랍니다. 저 단락은 해당 문서의 다른 단락과는 달리 다소 격정적인 문체로 쓰여 있습니다. CodeIgniter가 Session Lock으로 많은 고심(또는 고생)을 했다고 추측할 수 있습니다. (CodeIgniter 3.0 Session Library는 완전히 재 작성되었다고 하네요) 그 고심 끝에 CodeIgniter는 다음 문장을 내놓습니다.

Locking is not the issue, it is a solution. Your issue is that you still have the session open, while you’ve already processed it and therefore no longer need it. So, what you need is to close the session for the current request after you no longer need it.


CodeIgniter – A note about concurrency 단락에서 발췌


위에 인용한 내용이 CodeIgniter가 Session Lock을 바라보는 관점입니다. 이와 달리 Laravel의 Session기능은 session_start함수를 사용하지 않으며 Session Lock도 하지 않습니다. 다만 이로 인해 동시성 문제가 발생합니다. 이 이슈를 살펴 보시기 바랍니다.

Fraemework, 또는 Library의 Session 기능을 사용하고 있다면 Session Lock 여부에 대해 알아야 합니다. Lock을 한다면 Session을 수정한 후 가능한 빨리 Lock을 해제해야 합니다. Session Lock을 사용하지 않는 Framework라면 동시성 문제가 발생할 수 있음을 알고 있어야 합니다.

결론

지금까지 Session Lock으로 인한 장애를 재현해보고 해결해보았습니다. 이 과정을 통해 다음 권고 사항을 도출할 수 있습니다.

  • 사용하고 있는 Session Handler의 Lock 정책이 무엇인지 알아야 한다.
    • PHP 기본 Session Handler는 file이며, Session Data를 Lock한다.
    • Redis Session Handler는 Lock을 하지 않는다. 옵션을 통해 Lock 정책을 변경할 수 있다.
    • Memcached Session Handler는 Lock을 한다. 옵션을 통해 Lock 정책을 변경할 수 있다.
  • Session Handler가 Lock을 사용하고 있다면 Session을 수정한 후 반드시 session_write_close로 Lock을 해제해 주어야 한다.
  • Session Handler가 Lock을 하고 있지 않다면 동시성 문제가 발생할 수 있다는 사실을 알아야 하며, 무결성을 요구하는 데이터를 Session에 저장하지 말아야 한다.

마지막에 살펴봤듯이 위 권고는 Library, Framework에 있는 Session기능을 사용할 때도 적용되어야 합니다. 여러분이 사용하는 Library의 Session은 어떻게 구현되어 있나요? Lock을 사용하나요? 동시성 문제가 발생하지는 않나요?

Next

Contact Us

안녕하세요? 제니퍼소프트입니다.
기술 문의의 경우 질문자의 회사/이름/연락처를 본문에 기술해 주셔야만 원할한 지원이 가능합니다.
보내주신 문의 사항을 검토하여 빠른 시일 내에 답변해 드리겠습니다.

  • Chris
  • Irene

메일을 보냈습니다.

메일 전송이 완료되었습니다.
빠른 시일 내에 답변드리겠습니다.
감사합니다.
제니퍼소프트 웹사이트는 쿠키를 사용합니다. 쿠키에 대한 자세한 정보 및 삭제 방법은 제니퍼소프트의 개인정보처리방침을 참고하시기 바라며 본 사이트를 계속해서 이용하는 것은 제니퍼소프트의 쿠키 사용에 동의함을 의미합니다.