В предыдущей статье я писал, что смог откомпилировать ядро линукс, но при запуске в плате Марсоход2 он как-то странно виснет.
Пришло время разобраться с этим. Проблема похоже серьезная. Даже не понятно с какой стороны подступиться. Ведь причина подвисания может быть где угодно:
- Может быть аппаратная проблема? Работает ли процессор или в некоторых случаях сбоит? Работает ли правильно контроллер памяти SDRAM?
- Может быть проблема в компиляторе? Ведь похоже, что я использую одну из последних версий компилятора, не такую, какая была в оригинале у автора проекта Amber.
- Может я все же не правильно сконфигурировал ядро? Или есть ошибки в каких-то драйверах?
Какие вообще есть способы разбираться со всем этим?
К сожалению у нас нет возможности для внутрисхемной пошаговой отладки процессора Amber. Многие современные микропроцессоры позволяют производить отладку программ в реальном устройстве скажем, через разъем JTAG. Эта аппаратная возможность у нас в проекте не реализована.
Наверное самый простой способ «отладки» - это вставлять в программу контрольные сообщения. Ядро Linux ведь то же своего рода программа. И сообщения из ядра можно легко выводить на консоль функцией printk(…). Эта функция – полный аналог обычной для языка C printf(…). Если программа будет выводить много разных сообщений по ходу выполнения а потом внезапно повиснет, то тогда можно по последнему перед повисанием сообщению понять примерно, где находится проблемный участок кода. Потом в этом проблемном участке кода добавлять новых сообщений. И так до тех пор, пока причина сбоя программы не будет найдена.
Именно с этого метода поиска неисправности я и начал свои исследования. Метод довольно простой, но не быстрый. Пришлось сделать очень много итераций «добавил printk в код драйверов Linux» => «скомпилировал Linux» => «загрузил образ в плату» и если непонятна проблема, то опять начинай сначала. В конце концов я подобрался к довольно странной ситуации. Вот смотрите. Я изменил в файле исходников ядра Linux arch/arm/kernel/process.c функцию arch_kernel_thread:
pid_t arch_kernel_thread(int (*fn)(void *), void *arg, unsigned long flags)
{
pid_t __ret;
printk("arch_kernel_thread\n");
__asm__ __volatile__(
"orr r0, %1, %2 @ kernel_thread sys_clone \n\
mov r1, #0 \n\
"__syscall(clone)" \n\
movs %0, r0 @ if we are the child \n\
bne 1f \n\
mov fp, #0 @ ensure that fp is zero \n\
mov r0, %4 \n\
mov lr, pc \n\
mov pc, %3 \n\
b sys_exit \n\
1: "
: "=&r" (__ret)
: "Ir" (flags), "I" (CLONE_VM), "r" (fn), "r" (arg)
: "r0", "r1", "lr");
printk("arch_kernel_thread exit\n");
return __ret;
}
Я добавил сюда при входе в функцию printk и на выходе из функции printk. Таким образом сообщения из функции должны идти парами «вошел-вышел». Сама эта функция делает системный вызов и в конце концов попадает в функцию do_fork из файла ядра Linux kernel/fork.c
int do_fork(unsigned long clone_flags, unsigned long stack_start,
struct pt_regs *regs, unsigned long stack_size)
{
int retval;
struct task_struct *p;
struct completion vfork;
if ((clone_flags & (CLONE_NEWNS|CLONE_FS)) == (CLONE_NEWNS|CLONE_FS))
return -EINVAL;
retval = -EPERM;
printk("do_fork enter\n");
………………
//здесь еще код
………………
printk("do_fork exit\n");
}
Функцию do_fork я так же исправил добавив printk на входе в фунцию и на выходе из нее.
Откомпилировал ядро. Испытываю его в плате Марсоход2. Что я вижу? Функция do_fork вызывается несколько раз, и несколько раз успешно. Я вижу, что сообщения printk идут как и положено парами:
Однако последний раз, перед тем, как повиcнуть ядру линукс эта парность вызовов нарушается. Причем получается, что из функции do_fork процессор выходит, а вот назад в вызвавшую ее arch_kernel_thread не возвращается:
И вот как такое вообще может быть?
После довольно долгих попыток понять проблему я уж было совсем отчаялся, но потом, поразмыслив, решил провести полную симуляцию старта Linux в процессоре с помощью Icarus Verilog. Посмотрим, если ли эта проблема в симуляторе.
Идея симуляции может показаться фантастической – я собираюсь провести длительную Verilog симуляцию очень сложной системы с процессором, исполняющим многие тысячи команд из памяти SDRAM.
На самом деле ничего космического здесь нет. Я ведь уже симулировал запуск программы hello-world на процессоре Amber. В случае с запуском и симуляцией линукс будет примерно так же, но чуть сложнее testbench.
- Сейчас мне нужно сделать полную модель системы: процессор, boot-rom, память, последовательный порт. Модель системы – это и есть testbench. От тестбенча hello-world будет отличие – нужно вставить в модель системы еще модель самой микросхемы SDRAM. Где ее взять? Самое простое – это попробовать использовать какую-то из моделей, которые есть «в комплекте» с компонентом SDRAM, который я взял на opencores. Но я так делать не стал, а пошел на сайт компании Micron (у нас ведь на плате Марсоход2 стоит микроновская микросхема памяти) и стал искать там. Выбирайте чип памяти на странице компании Микрон и там на каждую микросхему производитель дает Verilog модель. Вот это правильный подход. Я скачал модель mt48lc4m16a2.v. Теперь этот файл есть в моем проекте на GitHub.
Обратите внимание, что модель может вести лог обращений к памяти. Для этого можно в коде verilog модели исправить строку
wire Debug = 1'b0;
на
wire Debug = 1'b1;
- Тестбенч при старте должен сделать две важных вещи – считать с диска образ boot-loader.mem и разместить его в статической памяти модуля boot_mem32 и затем считать с диска образ линукса vmlinux.mem и поместить его в модель памяти SDRAM. В модели памяти mt48lc4m16a2 есть имитация массивов ячеек памяти:
reg [data_bits - 1 : 0] Bank0 [0 : mem_sizes];
reg [data_bits - 1 : 0] Bank1 [0 : mem_sizes];
reg [data_bits - 1 : 0] Bank2 [0 : mem_sizes];
reg [data_bits - 1 : 0] Bank3 [0 : mem_sizes];
Вот в эти банки по нужным адресам и нужно разместить исполняемый образ Linux для симуляции.
- Обычный boot-loader из папки sw/boot-loader-8М для нашей цели симуляции Linux не подходит. Ведь если он стартует, то потом ожидает ввода команд с консоли:
Amber Boot Loader v20091124203711
Commands
l : Load elf file
b <address> : Load binary file to <address>
d <start address> <num bytes> : Dump mem
h : Print help message
j <address> : Execute loaded elf, jumping to <address>
p <address> : Print ascii mem until first 0
r <address> : Read mem
s : Core status
w <address> <value> : Write mem
Ready
>
Поэтому, слегка модифицирую его код (файл sw/boot-loader-8M/start.S) – он после старта сразу будет переходить к исполнению кода по адресу 0x80000 и там, уже в памяти SDRAM будет образ Linux, загруженный тестбенчем.
.extern main
@bl main
mov r0,#0x80000
@ jump to program at r0
.globl _jump_to_program
_jump_to_program:
@ ----------------------------------------------
@ Copy ATAG structure to AdrBootParams
@ ----------------------------------------------
ldr r1, AdrBootParams
ldr r2, AdrATAGBase
ldr r3, AdeEndATAG
1: cmp r2, r3
beq 2f
ldr r4, [r2], #4
str r4, [r1], #4
b 1b
Комментирую строку переход на процедуру main и в регистр r0 загружаю адрес образа 0x8000 линукс, который сразу начнет исполняться.
- Как получить vmlinux.mem? Это текстовый файл вида «@адрес: значение» для симуляции средствами верилог. В папке проекта sw/tools есть специальная утилита amber-elfsplitter. Вот с помощью этой утилиты конвертирую образ vmlinux в файл типа mem. Из командной строки шелла вызываю:
$AMBER_BASE/sw/tools/amber-elfsplitter vmlinux > vmlinux.mem
Получается файл вот такого вида:
// Section name .init
// Type SHT_PROGBITS, Size 0x10000, Start address 0x00080000, File offset 0x8000, boffset 0
@00080000 e35f0402
@00080004 b59ff034
@00080008 e3300000
@0008000c 1b000013
@00080010 e28f0028
@00080014 e990203c
@00080018 e3a00000
@0008001c e1520003
@00080020 34820004
@00080024 3afffffc
….
- Еще нам нужно иметь дизассемблированный образ Linux, чтобы как-то ориентироваться в ходе исполнения команд процессором. Получаю его вот так (так же из командной строки):
arm-none-linux-gnueabi-objdump -C -S -EL vmlinux > vmlinux.dis
Получается файл вот такого вида:
vmlinux-org: file format elf32-littlearm
Disassembly of section .init:
02080000 <__init_begin>:
2080000: e35f0402 cmp pc, #33554432 ; 0x2000000
2080004: b59ff034 ldrlt pc, [pc, #52] ; 2080040 <LC0>
2080008: e3300000 teq r0, #0
208000c: 1b000013 blne 2080060 <oldparams>
2080010: e28f0028 add r0, pc, #40 ; 0x28
2080014: e990203c ldmib r0, {r2, r3, r4, r5, sp}
2080018: e3a00000 mov r0, #0
208001c: e1520003 cmp r2, r3
2080020: 34820004 strcc r0, [r2], #4
...........
- Я хочу, чтобы тестбенч писал в лог файл последовательность исполнения всех инструкций и состояния регистров процессора после каждой команды. Это будет делать вот такой фрагмент кода тестбенча на Verilog:
integer ena_rec = 0;
integer prev_a = 0;
always @(posedge u_system.u_amber.i_clk)
begin
if( u_system.u_amber.u_execute.i_pc_wen &&
u_system.u_amber.i_system_rdy &&
!u_system.u_amber.fetch_stall &&
u_system.u_amber.u_decode.instruction_address != prev_a
)
begin
prev_a = u_system.u_amber.u_decode.instruction_address; if(u_system.u_amber.u_decode.instruction_address==32'h209c9f4)
begin
ena_rec = ena_rec+1;
$display("do_fork %d",ena_rec);
$fdisplay(log_file,"do_fork");
end
if(ena_rec==5)
begin
$dumpon;
end
if(ena_rec!=0)
begin
$fdisplay(log_file,"#%08X:%08X",
u_system.u_amber.u_decode.instruction_address,
u_system.u_amber.u_decode.instruction
);
$fdisplay(log_file," %08X %08X %08X %08X %08X %08X %08X %08X",
u_system.u_amber.u_execute.u_register_bank.r0,
u_system.u_amber.u_execute.u_register_bank.r1,
u_system.u_amber.u_execute.u_register_bank.r2,
u_system.u_amber.u_execute.u_register_bank.r3,
u_system.u_amber.u_execute.u_register_bank.r4,
u_system.u_amber.u_execute.u_register_bank.r5,
u_system.u_amber.u_execute.u_register_bank.r6,
u_system.u_amber.u_execute.u_register_bank.r7
);
$fdisplay(log_file," %08X %08X %08X %08X %08X %08X %08X %08X",
u_system.u_amber.u_execute.u_register_bank.r8,
u_system.u_amber.u_execute.u_register_bank.r9,
u_system.u_amber.u_execute.u_register_bank.r10,
u_system.u_amber.u_execute.u_register_bank.r11,
u_system.u_amber.u_execute.u_register_bank.r12,
u_system.u_amber.u_execute.u_register_bank.r13_svc, u_system.u_amber.u_execute.u_register_bank.r14_svc,
u_system.u_amber.u_execute.u_register_bank.r15
);
end
end
end
Лог файл при этом будет выглядеть вот так:
#021426e0:e8a013f8
021d8340 021f0360 00000008 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000008 021f1f1c 021f0338 021f1ef8 2209ca73 008509b9
#021426e4:e2522020
021d8360 021f0360 00000008 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000008 021f1f1c 00000000 021f1ef8 2209ca73 008509ba
#021426e8:aafffffb
021d8360 021f0360 00000008 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000008 021f1f1c 00000000 021f1ef8 2209ca73 008509bb
#021426ec:e3720010
021d8360 021f0360 ffffffe8 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000008 021f1f1c 00000000 021f1ef8 2209ca73 008509bc
#021426f0:a8b10078
021d8360 021f0360 ffffffe8 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000008 021f1f1c 00000000 021f1ef8 2209ca73 008509bd
#021426fc:e2922014
021d8360 021f0360 ffffffe8 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000008 021f1f1c 00000000 021f1ef8 2209ca73 008509c0
Здесь видно текущий адрес и исполняемую команду а так же текущее состояние регистров процессора.
Поскольку объем логов может оказаться просто гигантским, то я решил искусственно ограничить их. Запись в лог файл начинается только после того, как процессор доберется до адреса 32'h209c9f4 – я подсмотрел его в дизассемблерном файле vmlinux.dis. Это адрес процедуры do_fork.
Запись в VCD файл состояния всех сигналов в системе вообще начинается только с 5-го вызова do_fork.
Даже в этом случае объем VCD файла у меня состовляет больше 200Мбайт. А файл лога больше 50-ти Мбайт. Кстати сама симуляция занимает что-то около часа на моем ноутбуке.
Итак, запуская симулятор Icarus Verilog с моим тестбенчем для Amber Linux я увидел, что система так же виснет, как и в реальной плате!
Посмотрите:
Первое, что бросается в глаза – микроновская модель памяти выдает сообщения об ошибках обращения к памяти tRAS violation during precharge. Это не очень хорошо - или даже очень плохо. Видимо используемый контроллер SDRAM содержит ошибку? Не понятно влияет ли это как-то на работоспособность системы. Возможно что и не влияет – ведь в принципе система работает и ядро Линукс в общем-то то грузится, как раз до того самого места, до 5-го вызовы функции do_fork.
Теперь у меня есть возможность досконально изучить, что же происходит. Я могу смотреть лог файл с последовательностью исполненных инструкций. Я могу рассматривать VCD файл в GTKWave. Дело не очень простое, но если задаться целью, то разобраться можно.
Просматривая временные диаграммы сигналов в GTKWave я обратил внимание, что начиная где-то после 74-й микросекунды процессор Amber ARM переходит в какое-то неопределенное состояние. В регистре r3 появляется значение xxx и сигнал i_fetch_stall становится неопределенным – видите красные области на снимке c GTKWave? Впрочем, это не единственные сигналы, значение которых далее симулятор не может вычислить. Как раз в этом месте происходят какие-то непредсказуемые вещи.
Мне потребовалось довольно много времени чтобы понять, что же происходит. И в конце концов я нашел проблему. Посмотрите это код:
209ca48: ebffe357 bl 20957ac <alloc_task_struct>
209ca4c: e2504000 subs r4, r0, #0
209ca50: 03e0700b mvneq r7, #11
209ca54: 0a0001e7 beq 209d1f8 <do_fork+0x804>
209ca58: ebfffe5f bl 209c3dc <get_current>
209ca5c: e1a05000 mov r5, r0
209ca60: e1a00004 mov r0, r4
209ca64: e1a01005 mov r1, r5
209ca68: e3a02fda mov r2, #872 ; 0x368
209ca6c: eb02970b bl 21426a0 <memcpy>
209ca70: e1a04000 mov r4, r0
209ca74: e59031e0 ldr r3, [r0, #480] ; 0x1e0
209ca78: e593c004 ldr ip, [r3, #4]
209ca7c: e5902214 ldr r2, [r0, #532] ; 0x214
209ca80: e15c0002 cmp ip, r2
Этот фрагмент дизассемблированного кода ядра Linux соответствует фрагменту кода функции do_fork:
p = alloc_task_struct();
if (!p)
goto fork_out;
*p = *current;
retval = -EAGAIN;
/*
* Check if we are over our maximum process limit, but be sure to
* exclude root. This is needed to make it possible for login and
* friends to set the per-user process limit to something lower
* than the amount of processes root is running. -- Rik
*/
if (atomic_read(&p->user->processes) >= p->rlim[RLIMIT_NPROC].rlim_cur
&& p->user != &root_user
&& !capable(CAP_SYS_ADMIN) && !capable(CAP_SYS_RESOURCE))
goto bad_fork_free;
Собственно регистр r3 "портится" при исполнении команды по адресу 0x9ca74 на команде «ldr r3, [r0, #480]». Даже скорее не так. Значение регистра r3 не портится, а в него загружается указатель "в никуда". Дальше он используется как указатель, но только по этому адресу в памяти нет ничего определенного, ранее туда ничего не было записано. После того, как процессор читает из этой ячейки памяти некоторое случайное значение дальше поведение программы естественно становится непредсказуемым.
И все из-за того, что... функция memcpy, копирующая блок памяти, в некоторых случаях портит регистр r0! А имеет ли право вызываемая функция портить значение регистров или нет? Это конечно зависит от используемых компиляторов, от того как они формируют и передают функциям параметры.
Теперь еще вопрос - а что с другими функциями? Они так же будут у меня портить регистры? Не понятно..
По крайней мере я взял и исправил в ядре Linux файл arch/arm/lib/memcpy.S. Теперь я в функции memcpy сохраняю на стеке еще регистры r0-r3 и восстанавливаю их со стека при выходе из нее.
Убрал все мои вспомогательные отладочные вызовы pkintk из функции do_fork и прочих. Перекомпилировал ядро. Пробую в плате Марсоход2 и - случилось чудо:
Linux почти стартует! Теперь он уже не виснет после "Starting kswapd" как раньше!
Ну, не совсем стартует - все же остается проблема с initrd.
Но это уже совсем другая история.
Я надеюсь и это починим!
PS: тестбенч и всякие вспомогательные файлы для этой симуляции есть в проекте на GitHub.
Подробнее...