[태그:] linux

5장 인터럽트, p345 실습

책이 dwc_otg_driver.c의 request_irq로 인터럽트를 등록을 설명했다. 그러나, 라즈베리 파이4가 dwc-otg_driver.c 함수를 사용하지 않는다. 있긴 있는데, 4로 오면서 의도적으로 사용하지 않는 듯 하다. 아무리 찾아봐도 request_irq를 dump_stack 메세지에서 찾을 수 없다. 내가 본 메세지는 다음과 같다.

Jun 14 07:38:24 raspberrypi kernel: [    0.547246] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x0000001000000890
Jun 14 07:38:24 raspberrypi kernel: [    0.550250] [+][irq_debug] irq_num: 53, func: request_threaded_irq, line: 1888, caller: xhci_run+0x240/0x670
Jun 14 07:38:24 raspberrypi kernel: [    0.552941] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.19.127-v7l+ #78
Jun 14 07:38:24 raspberrypi kernel: [    0.555588] Hardware name: BCM2835
Jun 14 07:38:24 raspberrypi kernel: [    0.558290] [<c0212dd8>] (unwind_backtrace) from [<c020d3ec>] (show_stack+0x20/0x24)
Jun 14 07:38:24 raspberrypi kernel: [    0.561023] [<c020d3ec>] (show_stack) from [<c09c01dc>] (dump_stack+0xd8/0x11c)
Jun 14 07:38:24 raspberrypi kernel: [    0.563706] [<c09c01dc>] (dump_stack) from [<c0285ae0>] (request_threaded_irq+0x1b4/0x1b8)
Jun 14 07:38:24 raspberrypi kernel: [    0.566425] [<c0285ae0>] (request_threaded_irq) from [<c07b4530>] (xhci_run+0x240/0x670)
Jun 14 07:38:24 raspberrypi kernel: [    0.569178] [<c07b4530>] (xhci_run) from [<c079bd6c>] (usb_add_hcd+0x324/0x7ac)
Jun 14 07:38:24 raspberrypi kernel: [    0.571892] [<c079bd6c>] (usb_add_hcd) from [<c07afa84>] (usb_hcd_pci_probe+0x278/0x398)
Jun 14 07:38:24 raspberrypi kernel: [    0.574625] [<c07afa84>] (usb_hcd_pci_probe) from [<c07cc760>] (xhci_pci_probe+0x3c/0x180)
Jun 14 07:38:24 raspberrypi kernel: [    0.577382] [<c07cc760>] (xhci_pci_probe) from [<c067d008>] (pci_device_probe+0xb0/0x138)
Jun 14 07:38:24 raspberrypi kernel: [    0.580118] [<c067d008>] (pci_device_probe) from [<c0718f3c>] (really_probe+0x20c/0x2cc)
Jun 14 07:38:24 raspberrypi kernel: [    0.582911] [<c0718f3c>] (really_probe) from [<c07191d0>] (driver_probe_device+0x70/0x188)
Jun 14 07:38:24 raspberrypi kernel: [    0.585734] [<c07191d0>] (driver_probe_device) from [<c07193e4>] (__driver_attach+0xfc/0x100)
Jun 14 07:38:24 raspberrypi kernel: [    0.588587] [<c07193e4>] (__driver_attach) from [<c0716e48>] (bus_for_each_dev+0x84/0xc4)
Jun 14 07:38:24 raspberrypi kernel: [    0.591438] [<c0716e48>] (bus_for_each_dev) from [<c07187c8>] (driver_attach+0x2c/0x30)
Jun 14 07:38:24 raspberrypi kernel: [    0.594277] [<c07187c8>] (driver_attach) from [<c0718248>] (bus_add_driver+0x1d0/0x214)
Jun 14 07:38:24 raspberrypi kernel: [    0.597086] [<c0718248>] (bus_add_driver) from [<c0719bc4>] (driver_register+0x84/0x118)
Jun 14 07:38:24 raspberrypi kernel: [    0.599945] [<c0719bc4>] (driver_register) from [<c067c2e0>] (__pci_register_driver+0x58/0x5c)
Jun 14 07:38:24 raspberrypi kernel: [    0.602852] [<c067c2e0>] (__pci_register_driver) from [<c0e3f6cc>] (xhci_pci_init+0x68/0x6c)
Jun 14 07:38:24 raspberrypi kernel: [    0.605785] [<c0e3f6cc>] (xhci_pci_init) from [<c0203004>] (do_one_initcall+0x50/0x220)
Jun 14 07:38:24 raspberrypi kernel: [    0.608748] [<c0203004>] (do_one_initcall) from [<c0e01374>] (kernel_init_freeable+0x340/0x3e0)
Jun 14 07:38:24 raspberrypi kernel: [    0.611723] [<c0e01374>] (kernel_init_freeable) from [<c09d5590>] (kernel_init+0x18/0x128)
Jun 14 07:38:24 raspberrypi kernel: [    0.614684] [<c09d5590>] (kernel_init) from [<c02010ac>] (ret_from_fork+0x14/0x28)
Jun 14 07:38:24 raspberrypi kernel: [    0.617678] Exception stack(0xefa61fb0 to 0xefa61ff8)

일단 request_threaded_irq가 request_irq임은 확실하다.
xhci_run이 request_threaded_irq를 호출한다.
usb_add_hcd가 xhci_run을 호출한다.
… 이런 식으로 kernel_init로 간다.
결국 시스템 시작할 때 인터럽트를 등록한다.

문제가 책 예시와 다르게, 누가 request_irq를 실행하는지 모르는 점이다. dump_stack이 미리 정의되지 않은 함수는 보여주지 않는 듯 하다. 찾아보면 알겠지만 msi가 드라이버를 만들었다. xhci_run, usb_add_hcd, usb_hcd_pci_probe 등 여러 함수 중 request_irq를 콜하는 부분을 쉽게 찾을 수 없었다. 그러나 시간이 많은 나는 결국 xhci_run의 xhci_setup_msi가 requset_irq를 함을 찾아냈다.

/*
 * Set up MSI
 */
static int xhci_setup_msi(struct xhci_hcd *xhci)
{
    int ret; 
    /*   
     * TODO:Check with MSI Soc for sysdev
     */
    struct pci_dev  *pdev = to_pci_dev(xhci_to_hcd(xhci)->self.controller);

    ret = pci_alloc_irq_vectors(pdev, 1, 1, PCI_IRQ_MSI);
    if (ret < 0) { 
        xhci_dbg_trace(xhci, trace_xhci_dbg_init,
                "failed to allocate MSI entry");
        return ret; 
    }    

    ret = request_irq(pdev->irq, xhci_msi_irq,
                0, "xhci_hcd", xhci_to_hcd(xhci));
    //210611 irq 추가...
    interrupt_debug_irq_desc(pdev->irq);


    if (ret) {
        xhci_dbg_trace(xhci, trace_xhci_dbg_init,
                "disable MSI interrupt");
        pci_free_irq_vectors(pdev);
    }    

    return ret; 
}

이렇게 설정 후 컴파일 하면, 메세지가 제대로 출력된다. 교재와 다르게 인터럽트 53번으로 설정한다.

Jun 14 07:38:24 raspberrypi kernel: [    0.626769] 1fe0: 00000000 00000000 00000000 00000000 00000013 00000000
Jun 14 07:38:24 raspberrypi kernel: [    0.629855] genirq: irq_chip Brcm_MSI did not update eff. affinity mask of irq 53
Jun 14 07:38:24 raspberrypi kernel: [    0.632884] [+] irq_desc debug start
Jun 14 07:38:24 raspberrypi kernel: [    0.635920] irq num: 53 name: xhci_hcd
Jun 14 07:38:24 raspberrypi kernel: [    0.638938] dev_id:0xefa55000
Jun 14 07:38:24 raspberrypi kernel: [    0.641924] interrupt handler: xhci_msi_irq+0x0/0x20
Jun 14 07:38:24 raspberrypi kernel: [    0.644914] [-] irq_desc debug end

몇 번 해보면서 느꼈는데, 꼬리에 꼬리를 물어 원하는 부분을 찾아내는 능력이 필요해 보인다. 그래야 그 부분을 수정하여 원하는 기능을 구현할 수 있으니까.

2021-06-14

linux kernel 중 container_of 이해와 사용

container_of를 사용하여 double linked list로 연결된 task_struct가 가진 다른 멤버에 접근할 수 있다. 자세한 원리는 모르겠지만, 컴파일러가 offset을 고정시키는데, 구조체를 미리 알고 있기때문에, 거꾸로 세어 나가는 원리인 듯 하다. 이것은 기술인가? 잔머리인가? 두 번 탐색하지 않아도 되기 때문에 많은 부분에서 사용된다 한다.

유저 프로세스 raspbian_proc가 printf로 글자를 출력하고, sleep으로 3초동안 대기한다. 프린트 될 때 wake_up_process 함수를 실행한다. 이 부분에서 list_head로 연결된 next, prev task_struct를 보기로 했다. 잘 안된다.

싱글 포인터를 사용하면 next 구조체로 접근할 수 없다. double 포인터로 어떻게 어떻게 잘 구해내야 한다. 커널 패치를 하다하다 안되어, 임시로 프로그램을 만들어 gdb로 파 보았다.

#include <stdio.h>
#include <stddef.h>

// Copied from linux/kernel.h
#define container_of(ptr, type, member) ({                      \
		const typeof( ((type *)0)->member ) *__mptr = (ptr);    \
		(type *)( (char *)__mptr - offsetof(type,member) );})


struct myStruct { int a, b; struct myStruct *next; struct myStruct *prev;char name[10];};



//struct myStruct { int a, b; };

int main()
{

	//.은 구조체 내부 멤버를 지칭.
	struct myStruct var = {.a = 0, .b = 0, .next=NULL, .prev=NULL, .name="first"}; 
	struct myStruct var2 = {.a = 2, .b = 2, .next=NULL, .prev=NULL, .name="second"}; 
	struct myStruct var3 = {.a = 3, .b = 3, .next=NULL, .prev=NULL, .name="third"}; 


	// next로 기본 값 되는 듯.
	/*
	var.ptr = (struct list_head*)&(var2.ptr);
	var2.ptr = (struct list_head*)&(var3.ptr);
	var3.ptr = (struct list_head*)&(var.ptr);
	*/

	var.next = &(var2);
	var2.next = &(var3);
	var3.next = &(var);

	var.prev = &(var3);
	var2.prev = &(var);
	var3.prev = &(var2);


	//var.ptr->prev = (struct list_head*)&(var3.ptr);
	//var2.ptr->prev = (struct list_head*)&(var.ptr);
	//var3.ptr->prev = (struct list_head*)&(var2.ptr);


	//var2.ptr->prev= var3.ptr;
	//
	struct myStruct* target;
	struct myStruct** tmp;
	tmp = &(var2.next);
	tmp = &(*tmp)->next;
	printf("test name: %s, var address %p, a value = %d\n", (*tmp)->name, *tmp, (*tmp)->a);
	//var2.next를 가리키는  var3
	target=container_of((struct myStruct**)tmp, struct myStruct, next); 
	printf("test2 name: %s, var address %p, a value = %d\n", target->name, target, target->a);


	target=container_of(&var.next, struct myStruct, next); 
	printf("name: %s, var address %p, a value = %d\n", target->name, target, target->a);

	target=container_of(&var2.next, struct myStruct, next); 
	printf("name: %s, var address %p, a value = %d\n", target->name, target, target->a);

	target=container_of(&var3.next, struct myStruct, next); 
	printf("name: %s, var address %p, a value = %d\n", target->name, target, target->a);


	//prev로 검색.
	target=container_of(&var.prev, struct myStruct, prev); 
	printf("name: %s, var address %p, a value = %d\n", target->name, target, target->a);

	target=container_of(&var2.prev, struct myStruct, prev); 
	printf("name: %s, var address %p, a value = %d\n", target->name, target, target->a);

	target=container_of(&var3.prev, struct myStruct, prev); 
	printf("name: %s, var address %p, a value = %d\n", target->name, target, target->a);


	//int *memberPointer = &var.b;
//
//	int *memberPointer = &var.a;
//
//	printf("Struct addr=%p\n", &var);
//
//	struct myStruct *newSp = container_of(memberPointer, struct myStruct, b); 
//
//	printf("Struct addr new=%p\n", newSp);
//
//	if(newSp == &var)
//	{   
//		printf("It's equal.\n");
//	}   
//
	return 0;
}

pi@raspberrypi:~/RaspberryDebug/taskAddress $ ./a.out 
test name: first, var address 0xbef413e0, a value = 0
test2 name: third, var address 0xbef413a8, a value = 3
name: first, var address 0xbef413e0, a value = 0
name: second, var address 0xbef413c4, a value = 2
name: third, var address 0xbef413a8, a value = 3
name: first, var address 0xbef413e0, a value = 0
name: second, var address 0xbef413c4, a value = 2
name: third, var address 0xbef413a8, a value = 3

struct myStruct** tmp;
tmp = &(var2.next);
tmp = &(*tmp)->next;

tmp같이 이중 포인터로 접근해야 var2.next에 해당하는 var3을 target으로 받을 수 있다. 포인터 연산자 우선순위도 좀 신경써야 해서, (*tmp)를 먼저 쓰고 -> 로 next에 접근해야 한다. 너무 헷갈린다. list_head* next, prev도 더블 포인터다. 이를 gdb로 겨우 알아내고, 커널 core.c 코드를 좀 수정했다. 커널을 디버그하면 좋으나, 그런 방법은 없고, trace32나 kgdb등 방법을 찾아야 된다. 비싸거나 힘들다.

[21:52:04]>cat linux/kernel/sched/core.c  | head -2180 | tail -50
		ttwu_activate(rq, p, ENQUEUE_WAKEUP | ENQUEUE_NOCLOCK);
	}

	ttwu_do_wakeup(rq, p, 0, rf);
	ttwu_stat(p, smp_processor_id(), 0);
out:
	raw_spin_unlock(&p->pi_lock);
}

/**
 * wake_up_process - Wake up a specific process
 * @p: The process to be woken up.
 *
 * Attempt to wake up the nominated process and move it to the set of runnable
 * processes.
 *
 * Return: 1 if the process was woken up, 0 if it was already running.
 *
 * This function executes a full memory barrier before accessing the task state.
 */
int wake_up_process(struct task_struct *p)
{
	//2021. 5. 23추가
	struct task_struct* tmp;
	struct list_head **tmp2;
	if ( !strcmp (p->comm, "raspbian_proc")) {
		//printk("[+]test activated\n");
		tmp2 = (struct list_head**)(p->tasks.next);
		tmp = container_of(tmp2, struct task_struct, tasks.next);
		printk("[=]pid[%d], [%s] point %p at %p \n",
				p->pid, p->comm, p->tasks.next, &p->tasks.next);
		printk("[+]%s point %p at %p\n", tmp->comm, tmp->tasks.next, &tmp->tasks.next);
		printk("[-]%s point %p at %p\n", tmp->comm, tmp->tasks.prev, &tmp->tasks.prev);
		//printk("[==]p->task.next: %p, p: %p\n", &p->tasks.next, &p);
		//

	}

	//2021. 5. 16추가


	return try_to_wake_up(p, TASK_NORMAL, 0);
}
EXPORT_SYMBOL(wake_up_process);

int wake_up_state(struct task_struct *p, unsigned int state)
{
	return try_to_wake_up(p, state, 0);
}

pi@raspberrypi:~/RaspberryDebug/process $ ./raspbian_proc 
raspbian tracing 
raspbian tracing 
raspbian tracing

[   12.482776] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[   12.482790] Bluetooth: BNEP filters: protocol multicast
[   12.482811] Bluetooth: BNEP socket layer initialized
[   12.602761] Bluetooth: hci0: unexpected event for opcode 0x0c52
[   43.549185] [=]pid[659], [raspbian_proc] point fb675b81 at e45574a0 
[   43.549191] [+]kworker/2:4 point 1d830555 at fb675b81
[   43.549195] [-]kworker/2:4 point e45574a0 at 71182716
[   46.549300] [=]pid[659], [raspbian_proc] point fb675b81 at e45574a0 
[   46.549309] [+]kworker/2:4 point 1d830555 at fb675b81
[   46.549317] [-]kworker/2:4 point e45574a0 at 71182716
[   49.549442] [=]pid[659], [raspbian_proc] point fb675b81 at e45574a0 
[   49.549452] [+]kworker/2:4 point 1d830555 at fb675b81
[   49.549460] [-]kworker/2:4 point e45574a0 at 71182716

여러 사이트를 참조 했다.

https://kamang-it.tistory.com/entry/Cclangcontainerof%EC%99%80-offsetof%EB%A1%9C-%EB%A9%A4%EB%B2%84-%EB%B3%80%EC%88%98%EB%A1%9C-%ED%95%B4%EB%8B%B9-%EA%B5%AC%EC%A1%B0%EC%B2%B4-%EB%B0%98%ED%99%98%ED%95%98%EA%B8%B0

https://digiconfactory.tistory.com/entry/C%EC%96%B8%EC%96%B4-%EC%9D%B4%EC%A4%91-%EC%97%B0%EA%B2%B0-%EB%A6%AC%EC%8A%A4%ED%8A%B8-Doubly-Linked-List-%EC%9E%90%EB%A3%8C%EA%B5%AC%EC%A1%B0

https://stackoverflow.com/questions/21398105/accessing-structure-elements-via-double-pointers-in-c

https://doomsodradek.blogspot.com/2017/06/c-struct-warning-assignment-from.html

2021-05-23

wifi 동글(ew-7811)로 내부 망 연결

실습 라즈베리 파이를 전원만 붙여 책상에 올렸다. 처음에는 이미지를 잘못 뜨면 부팅되지 않을까 키보드, 마우스, 모니터가 필요하다 생각했다. 그러나 크로스 컴파일 삽질을 몇 번 해보니 부팅 이미지를 쉽게 만들 수 있었다. 공간(공간 = 돈)을 절약하고자 라즈베리 파이에 전원만 넣고 나머지를 싹 치웠다.

커널 패닉을 몇 번이나 보겠어? 데스크탑에서 ssh로 라즈베리 파이에 접속하여 사용하기로 했다. 유선으로 연결하면 간단한데, 공유기는 거실에 있고, 데스크탑은 다른 방에 있어 지저분하다. 게다가 데스크탑에 랜포트가 하나라 인터넷용으로 할당해야 한다. usb용 와이파이 모듈로 붙이면 간단한데, 지금 사기 아깝다. 포기하려 했으나, 과거 레고 ev3에 연결했던 와이파이 동글을 찾아냈다. 당장 레고에서 적출하여 데스크탑에 꼽았다.

https://www.edimax.com/edimax/merchandise/merchandise_detail/data/edimax/in/wireless_adapters_n150/ew-7811un/

동글로 이렇게 연결했다.

처음 동글을 연결하여, wifi login하면 내부 망으로 잘 연결된다. 문제는 이제부터..

부팅할 때 network manager가 usb 동글을 연결할 때 까지 기다린다. 매 부팅시 약 30초 동안 지연된다. ssd를 사용하지만 체감은 하드디스크 수준이다. 그냥 쓰려 했으나, 남는게 시간이라 배워도 볼 겸, 고치기로 했다.

[10:04:57]>dmesg 
[ 732.893023] rtl_usb: reg 0x82, usbctrl_vendorreq TimeOut! status:0xffffff92 value=0xa200
[ 743.132917] rtl_usb: reg 0x82, usbctrl_vendorreq TimeOut! status:0xffffff92 value=0xa300

일단 사용하는 드라이버를 찾았다.

[09:59:09]>lsusb
...
Bus 001 Device 002: ID 7392:7811 Edimax Technology Co., Ltd EW-7811Un 802.11n Wireless Adapter [Realtek RTL8188CUS]

realtek rtl8188cus 드라이버를 찾아야 한다. 인터넷에서 찾았지만 너무 오래되어 kernel 2.x대로 컴파일 해야한다. 무슨 헤더파일이 커널 업데이트 되면서 사라졌는데, 이 부분을 수정해야 컴파일 할 수 있을 것 같다. 누가??? 포기하고, rtl8188이 rtl8192 드라이버를 사용하는 듯 하여 이 드라이버를 찾아봤다.

[09:59:10]>lsmod | grep rtl_usb
rtl_usb                20480  1 rtl8192cu

드라이버를 찾아보니 kenel 5.4버전에도 잘 들어가 있다. 하드웨어 특성인 듯 하다. 아예 모듈을 부팅할 때 로딩하지 않도록 blacklist로 넣어 주기로 했다.

드라이버를 로딩 후 모듈 의존성을 만들었다. 수동으로 해야 하는지 모르겠으나, 아래 명령어로 했다.

[10:48:28]>sudo depmod

어느 모듈이 문제인지 몰라 블랙리스트에 모두 추가했다. 이후 이미지를 업데이트 했다. 해도, 안해도 상관없다는데 하는 게 좋단다.

[10:04:57]>cat /etc/modprobe.d/blacklist-usbwifi.conf 
#rtl_usb 로딩시 vendor timeout으로 부팅 지연.
#해당 드라이버를 구할 수 없어 부팅시 언로드를 기본 설정.
#로딩 후 모듈 추가.
#
blacklist rtl8192cu
blacklist rtl8xxxu
blacklist rtl8192c_common
blacklist rtlwifi
blacklist rtl_usb
blacklist mac80211
blacklist cfg80211

# update-initramfs -u

부팅은 빨리 된다. 부팅 후 필요할 때 modprobe로 로딩한다. insmod를 하면 순서대로 하지 않아 symbolic error를 낸다.

[  228.936080] rtl_usb: Unknown symbol rtl_beacon_statistic (err -2)
[  228.936107] rtl_usb: Unknown symbol ieee80211_free_hw (err -2)
[  228.936123] rtl_usb: Unknown symbol ieee80211_register_hw (err -2)
[  228.936141] rtl_usb: Unknown symbol rtl_ops (err -2)
[  228.936153] rtl_usb: Unknown symbol ieee80211_tx_status_irqsafe (err -2)
[  228.936175] rtl_usb: Unknown symbol rtl_init_rx_config (err -2)
[  228.936187] rtl_usb: Unknown symbol rtl_lps_change_work_callback (err -2)
[  228.936203] rtl_usb: Unknown symbol rtl_action_proc (err -2)
[  228.936215] rtl_usb: Unknown symbol rtl_init_core (err -2)
[  228.936231] rtl_usb: Unknown symbol ieee80211_alloc_hw_nm (err -2)
[  228.936248] rtl_usb: Unknown symbol ieee80211_unregister_hw (err -2)
[  228.936265] rtl_usb: Unknown symbol rtl_deinit_core (err -2)
[  228.936277] rtl_usb: Unknown symbol rtl_deinit_deferred_work (err -2)
[  228.936290] rtl_usb: Unknown symbol ieee80211_rx_napi (err -2)
[  235.724425] rtl_usb: Unknown symbol rtl_beacon_statistic (err -2)
[  235.724452] rtl_usb: Unknown symbol ieee80211_free_hw (err -2)
[  235.724467] rtl_usb: Unknown symbol ieee80211_register_hw (err -2)
[  235.724484] rtl_usb: Unknown symbol rtl_ops (err -2)
[  235.724497] rtl_usb: Unknown symbol ieee80211_tx_status_irqsafe (err -2)
[  235.724519] rtl_usb: Unknown symbol rtl_init_rx_config (err -2)
[  235.724531] rtl_usb: Unknown symbol rtl_lps_change_work_callback (err -2)
[  235.724546] rtl_usb: Unknown symbol rtl_action_proc (err -2)
[  235.724558] rtl_usb: Unknown symbol rtl_init_core (err -2)
[  235.724574] rtl_usb: Unknown symbol ieee80211_alloc_hw_nm (err -2)
[  235.724591] rtl_usb: Unknown symbol ieee80211_unregister_hw (err -2)
[  235.724608] rtl_usb: Unknown symbol rtl_deinit_core (err -2)
[  235.724620] rtl_usb: Unknown symbol rtl_deinit_deferred_work (err -2)
[  235.724633] rtl_usb: Unknown symbol ieee80211_rx_napi (err -2)

[10:58:11]>sudo modprobe rtl8192cu

[  171.425547] rtl8192cu: Chip version 0x10
[  174.965957] rtl8192cu: Board Type 0
[  174.974954] rtl_usb: rx_max_size 15360, rx_urb_num 8, in_ep 1
[  174.974978] rtl8192cu: Loading firmware rtlwifi/rtl8192cufw_TMSC.bin
[  174.975042] ieee80211 phy0: Selected rate control algorithm 'rtl_rc'
[  174.975494] usbcore: registered new interface driver rtl8192cu
[  174.981081] rtl8192cu 1-9:1.0 wlx801f02efe35d: renamed from wlan0
[  175.036947] rtl8192cu: MAC auto ON okay!
[  176.627123] rtl8192cu: Tx queue select: 0x05
[  187.013949] rtl_usb: reg 0x82, usbctrl_vendorreq TimeOut! status:0xffffff92 value=0xa200
[  197.253732] rtl_usb: reg 0x82, usbctrl_vendorreq TimeOut! status:0xffffff92 value=0xa300
[  207.493591] rtl_usb: reg 0x82, usbctrl_vendorreq TimeOut! status:0xffffff92 value=0xa400
[  217.733460] rtl_usb: reg 0x80, usbctrl_vendorreq TimeOut! status:0xffffff92 value=0xa500
[  230.660865] wlx801f02efe35d: authenticate with 00:07:89:9a:24:d9
[  231.013147] wlx801f02efe35d: send auth to 00:07:89:9a:24:d9 (try 1/3)
[  231.020672] wlx801f02efe35d: authenticated
[  231.021103] wlx801f02efe35d: associate with 00:07:89:9a:24:d9 (try 1/3)
[  231.041533] wlx801f02efe35d: RX AssocResp from 00:07:89:9a:24:d9 (capab=0x411 status=0 aid=7)
[  231.041542] wlx801f02efe35d: AP has invalid WMM params (AIFSN=1 for ACI 3), will use 2
[  231.185105] wlx801f02efe35d: associated
[  231.210645] IPv6: ADDRCONF(NETDEV_CHANGE): wlx801f02efe35d: link becomes ready

176초에 로딩 후 230초에 드라이버를 로딩했다. 이 하드웨어 자체가 문제있어 보인다.

2021-05-19

4장 process 로그 확인

책 “디버깅을 통해.. 리눅스 커널” 148 페이지 예제를 실행했다. 잘 따라 해야 한다. trace 를 죽이고 살리는 과정에 오타로 살짝 헷갈렸다. 책은 /sys/kernel/debug/tracing/trace를 복사하는 script를 만들었다. 디버그 메세지를 보려면 이벤트 발생 후 바로 복사해야지, 타이핑한다고 늦게 하면 이전 기록을 시스템이 지워버린다. trace 파일을 지울 수 없다. 초기화 하려면 tracing_on에 0을 다시 써줘야 한다. 아래와 같은 기록을 뽑아 냈다. 다 적을 수 없어, 중요한 부분만 추출했다. 생각이 맞는지 모르겠다.

5825  => sys_clone+0x18/0x3c
5826  => ret_fast_syscall+0x0/0x28
5827  => 0xbed826b0
5828             bash-1921  [002] .... 32848.024289: _do_fork+0x14/0x41c <-sys_clone+0x34/0x3c
5829             bash-1921  [002] .... 32848.024299: <stack trace>
5830  => _do_fork+0x18/0x41c
5831  => sys_clone+0x34/0x3c
5832  => ret_fast_syscall+0x0/0x28
5833  => 0xbed826b0
5834           <idle>-0     [000] dns. 32848.024300: sched_wakeup: comm=kworker/u8:3 pid=2958 prio=120 target_cpu=000
5835             bash-1921  [002] .... 32848.024301: copy_process.part.0+0x14/0x1ac4 <-_do_fork+0xc4/0x41c
5836           <idle>-0     [000] d... 32848.024307: sched_switch: prev_comm=swapper/0 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=kworker/u8:3 next_pid=2958 next_prio=120
5837             bash-1921  [002] .... 32848.024310: <stack trace>
5838  => copy_process.part.0+0x18/0x1ac4
5839  => _do_fork+0xc4/0x41c
5840  => sys_clone+0x34/0x3c
5841  => ret_fast_syscall+0x0/0x28
5842  => 0xbed826b0
5843     kworker/u8:3-2958  [000] d... 32848.024324: sched_switch: prev_comm=kworker/u8:3 prev_pid=2958 prev_prio=120 prev_state=I ==> next_comm=swapper/0 next_pid=0 next_prio=120
5844             bash-1921  [002] .... 32848.024940: sched_process_fork: comm=bash pid=1921 child_comm=bash child_pid=3043
5845           <idle>-0     [003] d... 32848.024981: sched_switch: prev_comm=swapper/3 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=bash next_pid=3043 next_prio=120
5846    raspbian_proc-3043  [003] d... 32848.025568: sched_switch: prev_comm=bash prev_pid=3043 prev_prio=120 prev_state=S ==> next_comm=swapper/3 next_pid=0 next_prio=120
5847           <idle>-0     [003] dnh. 32848.025595: sched_wakeup: comm=bash pid=3043 prio=120 target_cpu=003
5848           <idle>-0     [003] d... 32848.025608: sched_switch: prev_comm=swapper/3 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=bash next_pid=3043 next_prio=120
5849             bash-1921  [002] d... 32848.025727: sched_switch: prev_comm=bash prev_pid=1921 prev_prio=120 prev_state=S ==> next_comm=swapper/2 next_pid=0 next_prio=120
5850           <idle>-0     [000] dnh. 32848.026664: sched_wakeup: comm=irq/36-mmc1 pid=82 prio=49 target_cpu=000
5851           <idle>-0     [000] d... 32848.026684: sched_switch: prev_comm=swapper/0 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=irq/36-mmc1 next_pid=82 next_prio=49
5852      irq/36-mmc1-82    [000] d.s. 32848.026720: sched_wakeup: comm=irq/36-mmc1 pid=82 prio=49 target_cpu=000
5853      irq/36-mmc1-82    [000] d.s. 32848.026763: sched_wakeup: comm=irq/36-mmc1 pid=82 prio=49 target_cpu=000
5854      irq/36-mmc1-82    [000] d.s. 32848.026806: sched_wakeup: comm=irq/36-mmc1 pid=82 prio=49 target_cpu=000
5855      irq/36-mmc1-82    [000] d... 32848.026823: sched_wakeup: comm=kworker/u8:3 pid=2958 prio=120 target_cpu=000
5856      irq/36-mmc1-82    [000] d... 32848.026840: sched_switch: prev_comm=irq/36-mmc1 prev_pid=82 prev_prio=49 prev_state=S ==> next_comm=kworker/u8:3 next_pid=2958 next_prio=120
5857     kworker/u8:3-2958  [000] d.s. 32848.026900: sched_wakeup: comm=kworker/u8:3 pid=2958 prio=120 target_cpu=000
5858     kworker/u8:3-2958  [000] d.s. 32848.026946: sched_wakeup: comm=kworker/u8:3 pid=2958 prio=120 target_cpu=000
...
8445     kworker/u8:0-2918  [001] d... 32866.110752: sched_switch: prev_comm=kworker/u8:0 prev_pid=2918 prev_prio=120 prev_state=I ==> next_comm=bash next_pid=3013 next_prio=120
8446             bash-3013  [001] d... 32866.110848: signal_generate: sig=9 errno=0 code=0 comm=raspbian_proc pid=3043 grp=1 res=0
8447           <idle>-0     [003] dnh. 32866.110856: sched_wakeup: comm=raspbian_proc pid=3043 prio=120 target_cpu=003
8448           <idle>-0     [003] d... 32866.110870: sched_switch: prev_comm=swapper/3 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=raspbian_proc next_pid=3043 next_prio=120
8449    raspbian_proc-3043  [003] d... 32866.110880: signal_deliver: sig=9 errno=0 code=0 sa_handler=0 sa_flags=0
8450    raspbian_proc-3043  [003] .... 32866.110883: do_exit+0x14/0xbd4 <-do_group_exit+0x50/0xe8
8451    raspbian_proc-3043  [003] .... 32866.110909: <stack trace>
8452  => do_exit+0x18/0xbd4
8453  => do_group_exit+0x50/0xe8
8454  => get_signal+0x160/0x85c
8455  => do_signal+0x360/0x4a4
8456  => do_work_pending+0xd4/0xec
8457  => slow_work_pending+0xc/0x20
8458  => 0xb6e1969c
8459    raspbian_proc-3043  [003] .... 32866.111230: sched_process_exit: comm=raspbian_proc pid=3043 prio=120
8460    raspbian_proc-3043  [003] d... 32866.111296: signal_generate: sig=17 errno=0 code=2 comm=bash pid=1921 grp=1 res=0
8461           <idle>-0     [002] dnh. 32866.111311: sched_wakeup: comm=bash pid=1921 prio=120 target_cpu=002
8462             bash-3013  [001] dn.. 32866.111313: sched_wakeup: comm=kworker/u8:0 pid=2918 prio=120 target_cpu=001
8463           <idle>-0     [002] d... 32866.111327: sched_switch: prev_comm=swapper/2 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=bash next_pid=1921 next_prio=120
8464    raspbian_proc-3043  [003] d... 32866.111330: sched_switch: prev_comm=raspbian_proc prev_pid=3043 prev_prio=120 prev_state=Z ==> next_comm=kworker/u8:0 next_pid=2918 next_prio=120
8465           <idle>-0     [000] dnh. 32866.111359: sched_wakeup: comm=sshd pid=3010 prio=120 target_cpu=000
8466             bash-3013  [001] d... 32866.111362: sched_switch: prev_comm=bash prev_pid=3013 prev_prio=120 prev_state=S ==> next_comm=swapper/1 next_pid=0 next_prio=120
8467     kworker/u8:0-2918  [003] d... 32866.111364: sched_switch: prev_comm=kworker/u8:0 prev_pid=2918 prev_prio=120 prev_state=I ==> next_comm=swapper/3 next_pid=0 next_prio=120
8468           <idle>-0     [000] d... 32866.111374: sched_switch: prev_comm=swapper/0 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=sshd next_pid=3010 next_prio=120
8469           <idle>-0     [003] dnh. 32866.111531: sched_wakeup: comm=kworker/u8:0 pid=2918 prio=120 target_cpu=003
8470           <idle>-0     [003] d... 32866.111539: sched_switch: prev_comm=swapper/3 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=kworker/u8:0 next_pid=2918 next_prio=120
8471             sshd-3010  [000] d... 32866.111572: sched_switch: prev_comm=sshd prev_pid=3010 prev_prio=120 prev_state=S ==> next_comm=swapper/0 next_pid=0 next_prio=120

bash pid는 1921이다.
5844행에서 child_pid 3043으로 자식 프로세스를 만들었다.
5846행에서 raspbian_proce를 볼 수 있다.
이 전에 5836행에서 다음 프로세스 id 2958을 가지고 거꾸로 sys_clone -> _do-fork -> copy_process를 실행했다.
5836 행에서 next pid 2958(5857행)로 넘어가야 하는데 fork 하느라 다음 행을 실행했다.

Linux process states

As in every Unix flavour, in Linux a process can be in a number of states. It’s easiest to observe it in tools like ps or top: it’s usually in the column named S. The documentation of ps describes the possible values:

PROCESS STATE CODES
   R  running or runnable (on run queue)
   D  uninterruptible sleep (usually IO)
   S  interruptible sleep (waiting for an event to complete)
   Z  defunct/zombie, terminated but not reaped by its parent
   T  stopped, either by a job control signal or because
      it is being traced
   [...]

A process starts its life in an R “running” state and finishes after its parent reaps it from the Z “zombie” state.

8449행에서 signo 9번을 받았다.
시그널 9번을 받아 시그널 17 발생 시켰다.
slow_work_pending -> do_work_pending -> do_signal -> get_signal -> do_group_exit -> do_exit 순으로 실행한다.

2021-05-16