[SW정글 72일차] pintos project2 : user prog 회고

rg.log·2022년 11월 29일

SW 사관학교 JUNGLE

목록 보기

16/31

팀원들과 겪었던 어려움을 정리하고 공유하며 우리도, 후배들도 다음번엔 이런 오류를 뛰어넘는 속도가 빨라지길 바란다.

pintos의 코드가 2만줄 넘다 보니까 하나하나 test case 확인이 쉽지 않았다. 하나하나 확인이 불가해서 test가 맞는지에 대한 어려움을 겪었다.

하지만 결국 fork는 구현하였지만 통과되지 않는 fork 관련 test case 확인하여 아직 open, read 등의 함수를 구현하지 않아 통과하지 않음을 확인하고, 코드 변경 사항이 있을 때마다 make check & test case를 한개씩 돌려보며 통과 여부 확인하는 것이 도움이 되었다.
또한 git 버전관리를 활용해 어떤 부분을 수정해 잘되었는지를 확인할 수 있었다.

다음번엔 test case를 잠깐 보고, 순서를 정하는 시간도 필요했나 싶다.

test case 중 sync-read 와 multi-oom FAIL 디버깅

해당 오류들을 잡기 위해 3일정도를 디버깅했던 것 같다. 주위 동기들의 카더라도 많이 들으며 참고했지만, 결국은 휴먼오류로 인한 간단한 부분이었던 것을 알게되었다..🙃

FAIL tests/filesys/base/syn-read

FAIL tests/userprog/no-vm/multi-oom

처음에는 "sys-read test가 fail or pass 확률게임입니다"라는 팀원의 말을 듣고 으잉? test code가? 하는 마음에 성공했던 sys-read test를 다시 돌려보니 50%의 확률로 성공과 실패를 왔다갔다했다.

어지러운 마음에 들어가본 sys-read test를 보니 왜 확률게임이었는가를 알게되었다. 아래는 tests/filesys/base/syn-read test 코드이다.

void
test_main (void) 
{
  pid_t children[CHILD_CNT];
  int fd;

  CHECK (create (file_name, sizeof buf), "create \"%s\"", file_name);
  CHECK ((fd = open (file_name)) > 1, "open \"%s\"", file_name);
  random_bytes (buf, sizeof buf);
  CHECK (write (fd, buf, sizeof buf) > 0, "write \"%s\"", file_name);
  msg ("close \"%s\"", file_name);
  close (fd);
  /* 이부분까지 출력이 잘되었다 */ 

  exec_children ("child-syn-read", children, CHILD_CNT);
  wait_children (children, CHILD_CNT);
}

void
exec_children (const char *child_name, pid_t pids[], size_t child_cnt) 
{
  size_t i;

  for (i = 0; i < child_cnt; i++) 
    {
      char cmd_line[128];
      snprintf (cmd_line, sizeof cmd_line, "%s %zu", child_name, i);
      if ((pids[i] = fork (child_name))){
        CHECK (pids[i] != PID_ERROR,
             "exec child %zu of %zu: \"%s\"", i + 1, child_cnt, cmd_line);
      } else {
        exec (cmd_line);
      }
      
    }
}

해당 test case를 돌리면 close하는 부분까지는 출력이 잘되었다.

그 후 exec_children 함수에 들어가 open fail 오류와 함께 실패하여 syscall open을 먼저 들여다보게 되었다. syn-read에서는 fork로 여러 자식 프로세스를 open하고

syscall open의 코드상의 문제는 없기에 printf를 찍어보며 어느부분까지 불리고, 언제부터 fail이 나는가를 찾아보았다.

fd_table 인덱스별로 0xccccccccccccccccc 값이 들어있었던 것이었다.

PAL_ZERO가 말이 ZERO지 사실 진짜 값은 2였다. test case를 디버깅하다가 결국 우리가 짠 코드를 하나하나 보면서도 한 끝 차이로 놓친 실수였다. 비트로 변환하여 계산되는 부분을 이전에 고민했으면서도 다시 훑을 때는 미처 생각하지 못했던 것이다.

palloc_get_multiple

실수로 매개변수에 필요한 flags에 PAL_ZERO(2)를 0로 넣었던 함수 내부는 아래와 같다.

수정 후 드디어 sync-read 와 multi-oom Success!! 🥹🥳

발표 후 팀원을 통해 알게 된 gitbook > APPENDIX > Debugging Tools > Tips 에 우리가 겪은 오류에 대한 팁이 들어있었다.

The page allocator in threads/palloc.c and the block allocator in threads/malloc.c clear all the bytes in memory to '0xcc' at time of free. Thus, if you see an attempt to dereference a pointer like 0xcccccccc, or some other reference to 0xcc, there's a good chance you're trying to reuse a page that's already been freed. Also, byte 0xcc is the CPU opcode for "invoke interrupt 3," so if you see an error like Interrupt 0x03 (#BP Breakpoint Exception), then Pintos tried to execute code in a freed page or block. An assertion failure on the expression sec_no < d->capacity indicates that Pintos tried to access a file through an inode that has been closed and freed. Freeing an inode clears its starting sector number to 0xcccccccc, which is not a valid sector number for disks smaller than about 1.6 TB.
threads/palloc.c의 페이지 할당자와 threads/malloc.c의 블록 할당자는 빈 시간에 메모리의 모든 바이트를 '0xcc'로 지웁니다. 따라서 0xcccccc와 같은 포인터의 참조 취소 시도나 0xcc에 대한 다른 참조를 볼 경우 이미 해제된 페이지를 다시 사용하려고 할 가능성이 높습니다. 또한 바이트 0xcc는 "invoke interrupt 3"의 CPU opcode이다. 따라서 Interrupt 0x03 (#BP Breakpoint Exception)과 같은 오류가 표시되면 핀토스는 자유로운 페이지나 블록에서 코드를 실행하려고 했습니다. sec_no capacity라는 표현에 대한 어설션 오류는 핀토스가 닫히고 해제된 아이노드를 통해 파일에 액세스하려고 시도했음을 나타냅니다. 아이노드를 해제하면 시작 섹터 번호가 0xcccc로 지워지는데, 이는 약 1.6TB보다 작은 디스크에 유효한 섹터 번호가 아닙니다.

디버깅을 진행하면서 왜 자꾸 구찌 0xccccccccccccccccc가 나오지? 하는 의문을 해결할 수 있었다.