# Sterownik ethernetu
Krótki wstęp na [bugzilla.kernel.org](https://bugzilla.kernel.org/show_bug.cgi?id=102171).
TLDR: [ta funkcja](https://code.woboq.org/linux/linux/drivers/net/ethernet/atheros/alx/main.c.html#alx_intr_handle_misc) czasem zaspamowuje logi (`fatal interrupt 0x4001607, resetting`),
i jak się spróbuje wyłączyć ten sterownik, to system zamiera proces po procesie.
Winny jest pewnie sprzęt, ale świrująca karta sieciowa powinna wywalać
co najwyżej swój sterownik, a nie stos sieciowy, czy całe jądro.
Co robić jak żyć?
Na szczęście jest [Kdump](https://www.kernel.org/doc/html/latest/admin-guide/kdump/kdump.html)
i [crash](https://people.redhat.com/~anderson/) (dostępny pakiet na redhatach i gentoo),
żeby obejrzeć, co się dzieje.
## Co mówi nam `crash`
Pierwszy zrzut pamięci zrobiłem wykonując `modprobe -r alx`
(usunięcie modułu) i doprowadzając tym do jakiegoś `OOPS`, a że
ustawiłem
```sh
CONFIG_PANIC_ON_OOPS=y
CONFIG_PANIC_ON_OOPS_VALUE=1
```
(można to zrobić równie dobrze w linii poleceń jądra), to wysypało się.
uruchamiamy:
```sh
$ crash vmlinux alx-rmmod.core
KERNEL: vmlinux
DUMPFILE: alx-rmmod.core
CPUS: 4
DATE: Sat Apr 11 12:38:00 2020
UPTIME: 19:08:47
LOAD AVERAGE: 2.51, 2.80, 2.51
TASKS: 240
NODENAME: arusekk
RELEASE: 5.6.2-gentoo
VERSION: #4 SMP Wed Apr 8 15:40:31 CEST 2020
MACHINE: x86_64 (2494 Mhz)
MEMORY: 7.7 GB
PANIC: "Oops: 0000 [#1] SMP" (check log for details)
PID: 2418
COMMAND: "kworker/3:4"
TASK: ffff888255d62d80 [THREAD_INFO: ffff888255d62d80]
CPU: 3
STATE: TASK_RUNNING (PANIC)
```
Możemy sprawdzić, na co czekało `modprobe -r alx` (pid 6884 poznałem wpisując ps)
```
crash> bt 6884
PID: 6884 TASK: ffff888264a91080 CPU: 0 COMMAND: "modprobe"
#0 [ffffc90001c6fc40] __schedule at ffffffff8191a8c4
#1 [ffffc90001c6fcc0] schedule at ffffffff8191ad25
#2 [ffffc90001c6fcd8] schedule_timeout at ffffffff8191df34
#3 [ffffc90001c6fd50] wait_for_completion at ffffffff8191bdbe
#4 [ffffc90001c6fda8] rcu_barrier at ffffffff811096b0
#5 [ffffc90001c6fdc0] netdev_run_todo at ffffffff81830358
#6 [ffffc90001c6fe20] alx_remove at ffffffffa01a4b59 [alx]
#7 [ffffc90001c6fe38] pci_device_remove at ffffffff814ca041
#8 [ffffc90001c6fe58] device_release_driver_internal at ffffffff816f6d5c
#9 [ffffc90001c6fe78] driver_detach at ffffffff816f6e8a
##10 [ffffc90001c6fe90] bus_remove_driver at ffffffff816f5c6a
##11 [ffffc90001c6fea0] pci_unregister_driver at ffffffff814c873f
##12 [ffffc90001c6fed0] __x64_sys_delete_module at ffffffff81129dea
##13 [ffffc90001c6ff38] do_syscall_64 at ffffffff81001b21
##14 [ffffc90001c6ff50] entry_SYSCALL_64_after_hwframe at ffffffff81a00068
RIP: 00007f3376509f57 RSP: 00007ffd5b3e7e48 RFLAGS: 00000206
RAX: ffffffffffffffda RBX: 0000555d882d5b70 RCX: 00007f3376509f57
RDX: 0000000000000000 RSI: 0000000000000800 RDI: 0000555d882d5bd8
RBP: 0000555d882d5b70 R8: 0000000000000000 R9: 0000000000000000
R10: fffffffffffffcf9 R11: 0000000000000206 R12: 0000555d882d5bd8
R13: 0000000000000000 R14: 0000000000000000 R15: 0000555d882d5b70
ORIG_RAX: 00000000000000b0 CS: 0033 SS: 002b
```
No fajnie, to teraz sprawdźmy, skąd się wziął popłoch:
```
crash> bt -p
PID: 2418 TASK: ffff888255d62d80 CPU: 3 COMMAND: "kworker/3:4"
#0 [ffffc90002697bf8] machine_kexec at ffffffff81040103
#1 [ffffc90002697c40] __crash_kexec at ffffffff8112f008
#2 [ffffc90002697d08] crash_kexec at ffffffff8112fc80
#3 [ffffc90002697d18] oops_end at ffffffff8101514e
#4 [ffffc90002697d38] no_context at ffffffff81047f43
#5 [ffffc90002697da0] page_fault at ffffffff81a00ecf
[exception RIP: alx_reinit_rings+39]
RIP: ffffffffa01a6177 RSP: ffffc90002697e58 RFLAGS: 00010246
RAX: 0000000000000000 RBX: ffff888262589880 RCX: 0000000000000000
RDX: 0000000000000000 RSI: 0000000000000002 RDI: ffff888262589880
RBP: ffff888262589880 R8: ffff888266000240 R9: ffff888266000300
R10: 0000000000000000 R11: ffffffff822241c8 R12: ffff8882674e1600
R13: 0000000000000000 R14: ffff8882674e5400 R15: 0000000000000000
ORIG_RAX: ffffffffffffffff CS: 0010 SS: 0018
#6 [ffffc90002697e60] alx_activate at ffffffffa01a62a9 [alx]
#7 [ffffc90002697e70] alx_reset at ffffffffa01a66d5 [alx]
#8 [ffffc90002697e80] process_one_work at ffffffff810be9b7
#9 [ffffc90002697eb8] worker_thread at ffffffff810bf3d5
##10 [ffffc90002697f10] kthread at ffffffff810c5c5a
##11 [ffffc90002697f50] ret_from_fork at ffffffff81a0015f
```
Jak widać, jest to wątek jądra, jakiś `worker_thread` obsługujący reset urządzenia.
Przekonajmy się, co to za kod się wyłożył.
```c
crash> add-symbol-file /usr/src/linux-5.6.2-gentoo/drivers/net/ethernet/atheros/alx/alx.ko 0xffffffffa01a4000
add symbol table from file "/usr/src/linux-5.6.2-gentoo/drivers/net/ethernet/atheros/alx/alx.ko" at
.text_addr = 0xffffffffa01a4000
Reading symbols from /usr/src/linux-5.6.2-gentoo/drivers/net/ethernet/atheros/alx/alx.ko...done.
crash> disassemble /m alx_reinit_rings
Dump of assembler code for function alx_reinit_rings:
451 static void alx_init_ring_ptrs(struct alx_priv *alx)
452 {
453 struct alx_hw *hw = &alx->hw;
454 u32 addr_hi = ((u64)alx->descmem.dma) >> 32;
455 struct alx_napi *np;
456 int i;
457
458 for (i = 0; i < alx->num_napi; i++) {
0xffffffffa01a6165 <+21>: test %eax,%eax
0xffffffffa01a6167 <+23>: jle 0xffffffffa01a6221 <alx_reinit_rings+209>
0xffffffffa01a616d <+29>: xor %edx,%edx
0xffffffffa01a6211 <+193>: add $0x1,%rdx
0xffffffffa01a6215 <+197>: cmp %edx,0x278(%rbp)
0xffffffffa01a621b <+203>: jg 0xffffffffa01a616f <alx_reinit_rings+31>
459 np = alx->qnapi[i];
0xffffffffa01a616f <+31>: mov 0x230(%rbp,%rdx,8),%rax
460 if (np->txq) {
0xffffffffa01a6177 <+39>: mov 0x190(%rax),%rcx
```
Rejestr `rax` (wskazujący na np) zawiera zero, stąd też nie możemy odczytać, co w nim jest.
## Prawdziwa przyczyna
Wnioskuję łatwo, że rejestr `rbp` wskazuje na `struct alx_priv`
```c
crash> ptype (struct alx_priv*)0xffff888262589880
type = struct alx_priv {
struct net_device *dev;
struct alx_hw hw;
int num_vec;
struct {
dma_addr_t dma;
void *virt;
unsigned int size;
} descmem;
struct alx_napi *qnapi[8];
int num_txq;
int num_rxq;
int num_napi;
spinlock_t irq_lock;
u32 int_mask;
unsigned int tx_ringsz;
unsigned int rx_ringsz;
unsigned int rxbuf_size;
struct work_struct link_check_wk;
struct work_struct reset_wk;
u16 msg_enable;
spinlock_t stats_lock;
} *
crash> p ((struct alx_priv*)0xffff888262589880)->qnapi
$1 = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}
```
No to widzimy, że ktoś wyczyścił tablicę `qnapi`, kiedy my jeszcze wykonujemy `alx_activate`.
I w tym problem, że w ogóle je wykonujemy.
## Kod sterownika
```sh
$ cd /usr/src/linux-5.6.2-gentoo/drivers/net/ethernet/atheros/alx
```
Interesuje nas tu tylko `main.c`. Zajmijmy się póki co wątkiem przerwania (tym, który dokonał
dereferencji zera). Ze stosu wywołań widać, że wykonuje się w kontekście zadania `alx_reset`.
Jedyne odwołanie do `alx_reset` to przypisanie go do obsługi zadania `reset_wk`, ustawianego w `alx_probe`.
```c=1830
INIT_WORK(&alx->reset_wk, alx_reset);
```
Ta jest kolejkowana przez
```c=212
static void alx_schedule_reset(struct alx_priv *alx)
{
schedule_work(&alx->reset_wk);
}
```
Wywołaną przez
```c=331
static bool alx_intr_handle_misc(struct alx_priv *alx, u32 intr)
{
struct alx_hw *hw = &alx->hw;
if (intr & ALX_ISR_FATAL) {
netif_warn(alx, hw, alx->dev,
"fatal interrupt 0x%x, resetting\n", intr);
alx_schedule_reset(alx);
return true;
}
```
w kontekście przerwania sprzętowego.
Teraz przejdźmy do wątku `modprobe -r alx`. Wyzerował on `qnapi`, które jest zerowane tylko
w `alx_free_napis`, które wykonywane jest tylko przez `alx_stop` i podczas błędów inicjalizacji.
```c=1856
static void alx_remove(struct pci_dev *pdev)
{
struct alx_priv *alx = pci_get_drvdata(pdev);
struct alx_hw *hw = &alx->hw;
cancel_work_sync(&alx->link_check_wk);
cancel_work_sync(&alx->reset_wk);
/* restore permanent mac address */
alx_set_macaddr(hw, hw->perm_addr);
unregister_netdev(alx->dev);
/* dalej nie dochodzi */
```
Tu pojawiają się kolejne pliki z kodu źródłowego jądra: `net/core/dev.c`
```c=9985
void unregister_netdev(struct net_device *dev)
{
rtnl_lock();
unregister_netdevice(dev);
rtnl_unlock();
}
```
Tu wisi proces czekając na nigdy:
```c=9571
/* The sequence is:
*
* rtnl_lock();
* ...
* register_netdevice(x1);
* register_netdevice(x2);
* ...
* unregister_netdevice(y1);
* unregister_netdevice(y2);
* ...
* rtnl_unlock();
* free_netdev(y1);
* free_netdev(y2);
*
* We are invoked by rtnl_unlock().
* This allows us to deal with problems:
* 1) We can delete sysfs objects which invoke hotplug
* without deadlocking with linkwatch via keventd.
* 2) Since we run with the RTNL semaphore not held, we can sleep
* safely in order to wait for the netdev refcnt to drop to zero.
*
* We must not return until all unregister events added during
* the interval the lock was held have been completed.
*/
void netdev_run_todo(void)
{
struct list_head list;
/* Snapshot list, allow later requests */
list_replace_init(&net_todo_list, &list);
__rtnl_unlock();
/* Wait for rcu callbacks to finish before next phase */
if (!list_empty(&list))
rcu_barrier(); /* <==== */
```
Więc interesuje nas poprzednia funkcja (z `include/linux/netdevice.h`)
```c=2713
static inline void unregister_netdevice(struct net_device *dev)
{
unregister_netdevice_queue(dev, NULL);
}
```
znów `net/core/dev.c`
```c=9940
void unregister_netdevice_queue(struct net_device *dev, struct list_head *head)
{
ASSERT_RTNL();
if (head) {
list_move_tail(&dev->unreg_list, head);
} else {
rollback_registered(dev);
/* Finish processing unregister after unlock */
net_set_todo(dev);
}
}
```
dalej:
```c=8850
static void rollback_registered(struct net_device *dev)
{
LIST_HEAD(single);
list_add(&dev->unreg_list, &single);
rollback_registered_many(&single);
list_del(&single);
}
```
czyli
```c=8759
static void rollback_registered_many(struct list_head *head)
{
struct net_device *dev, *tmp;
LIST_HEAD(close_head);
BUG_ON(dev_boot_phase);
ASSERT_RTNL();
list_for_each_entry_safe(dev, tmp, head, unreg_list) {
/* Some devices call without registering
* for initialization unwind. Remove those
* devices and proceed with the remaining.
*/
if (dev->reg_state == NETREG_UNINITIALIZED) {
pr_debug("unregister_netdevice: device %s/%p never was registered\n",
dev->name, dev);
WARN_ON(1);
list_del(&dev->unreg_list);
continue;
}
dev->dismantle = true;
BUG_ON(dev->reg_state != NETREG_REGISTERED);
}
/* If device is running, close it first. */
list_for_each_entry(dev, head, unreg_list)
list_add_tail(&dev->close_list, &close_head);
dev_close_many(&close_head, true);
/* dalej nieistotne */
```
co z kolei okazuje się wykonywać `ndo_stop()`
```c=1483
static void __dev_close_many(struct list_head *head)
{
struct net_device *dev;
ASSERT_RTNL();
might_sleep();
list_for_each_entry(dev, head, close_list) {
/* Temporarily disable netpoll until the interface is down */
netpoll_poll_disable(dev);
call_netdevice_notifiers(NETDEV_GOING_DOWN, dev);
clear_bit(__LINK_STATE_START, &dev->state);
/* Synchronize to scheduled poll. We cannot touch poll list, it
* can be even on different cpu. So just clear netif_running().
*
* dev->stop() will invoke napi_disable() on all of it's
* napi_struct instances on this device.
*/
smp_mb__after_atomic(); /* Commit netif_running(). */
}
dev_deactivate_many(head);
list_for_each_entry(dev, head, close_list) {
const struct net_device_ops *ops = dev->netdev_ops;
/*
* Call the device specific close. This cannot fail.
* Only if device is UP
*
* We allow it to be called even after a DETACH hot-plug
* event.
*/
if (ops->ndo_stop)
ops->ndo_stop(dev); /* <===== TUTAJ */
dev->flags &= ~IFF_UP;
netpoll_poll_enable(dev);
}
}
static void __dev_close(struct net_device *dev)
{
LIST_HEAD(single);
list_add(&dev->close_list, &single);
__dev_close_many(&single);
list_del(&single);
}
void dev_close_many(struct list_head *head, bool unlink)
{
struct net_device *dev, *tmp;
/* Remove the devices that don't need to be closed */
list_for_each_entry_safe(dev, tmp, head, close_list)
if (!(dev->flags & IFF_UP))
list_del_init(&dev->close_list);
__dev_close_many(head);
list_for_each_entry_safe(dev, tmp, head, close_list) {
rtmsg_ifinfo(RTM_NEWLINK, dev, IFF_UP|IFF_RUNNING, GFP_KERNEL);
call_netdevice_notifiers(NETDEV_DOWN, dev);
if (unlink)
list_del_init(&dev->close_list);
}
}
```
Za to nasze `ndo_stop` to `alx_stop` (powrót do drivers/net/ethernet/atheros/alx/main.c):
```c=1673
static const struct net_device_ops alx_netdev_ops = {
.ndo_open = alx_open,
.ndo_stop = alx_stop,
```
```c=1340
static int alx_stop(struct net_device *netdev)
{
__alx_stop(netdev_priv(netdev));
return 0;
}
```
```c=1250
static void __alx_stop(struct alx_priv *alx)
{
alx_halt(alx);
alx_free_irq(alx);
alx_free_rings(alx);
alx_free_napis(alx); /* <=== to on dealokuje rzeczy */
}
```
Uff. Gdzie zatem jest błąd?
W pewnym sensie w `alx_remove`, w pewnym w `alx_(schedule_)reset`.
Przypomnijmy kod `alx_remove`:
```c=1856
static void alx_remove(struct pci_dev *pdev)
{
struct alx_priv *alx = pci_get_drvdata(pdev);
struct alx_hw *hw = &alx->hw;
cancel_work_sync(&alx->link_check_wk);
cancel_work_sync(&alx->reset_wk);
/* restore permanent mac address */
alx_set_macaddr(hw, hw->perm_addr);
unregister_netdev(alx->dev);
/* dalej nie dochodzi */
```
Otóż programista prawdobodobnie nie był świadomy,
że `cancel_work_sync` nie chroni nas przed przyszłym `schedule_work`.
```c=212
static void alx_schedule_reset(struct alx_priv *alx)
{
schedule_work(&alx->reset_wk);
}
```
Należałoby wprowadzić jakieś pole, w którym zapisywalibyśmy, że sterownik jest w trakcie wyłączania.
[FreeBSD](http://bxr.su/FreeBSD/sys/dev/alc/if_alc.c#alc_int_task) rozwiązuje ten problem nieco inaczej.
## Rzeczywista przyczyna spamu `fatal int fatal interrupt 0x4001607, resetting`
To jest trudniejsze, nie pokażę, dlaczego, bo nie wiem.
```sh
$ crash vmlinux alx-sysrq.core
KERNEL: vmlinux
DUMPFILE: alx-sysrq.core
CPUS: 4
DATE: Mon Apr 13 21:07:33 2020
UPTIME: 10:09:46
LOAD AVERAGE: 1.89, 3.07, 3.54
TASKS: 111
NODENAME: arusekk
RELEASE: 5.6.2-gentoo
VERSION: #4 SMP Wed Apr 8 15:40:31 CEST 2020
MACHINE: x86_64 (2494 Mhz)
MEMORY: 7.7 GB
PANIC: "Kernel panic - not syncing: sysrq triggered crash"
PID: 0
COMMAND: "swapper/0"
TASK: ffffffff8220f4c0 (1 of 4) [THREAD_INFO: ffffffff8220f4c0]
CPU: 0
STATE: TASK_RUNNING (PANIC)
```
```c
crash> add-symbol-file /usr/src/linux-5.6.2-gentoo/drivers/net/ethernet/atheros/alx/alx.ko 0xffffffffa001a000
add symbol table from file "/usr/src/linux-5.6.2-gentoo/drivers/net/ethernet/atheros/alx/alx.ko" at
.text_addr = 0xffffffffa001a000
Reading symbols from /usr/src/linux-5.6.2-gentoo/drivers/net/ethernet/atheros/alx/alx.ko...done.
```
Wygląda na to, że urządzenie zgłasza co chwilę NMI, że jest w złym stanie, a wszystkie rejestry
ma wypełnione jedynkami. Jednak z jakiegoś powodu automatyczny reset zaprogramowany w module nie pomaga.
## Błędy (?) znalezione przy okazji
Być może jest to jakiś błąd jądra, bo `cp /proc/vmcore /mnt/dane/krasze/alx-rmmod` nie działa,
read zawodzi z ENOMEM (dziwne, bo czyta tylko po 4KiB na raz do pliku).
Napisałem na szybko program, który robi `mem = mmap(NULL, size, PROT_READ, MAP_SHARED, vmcore_fd, 0)`
i `write(STDOUT_FILENO, mem, size)`, zadziałał.
Inny błąd, który znalazłem (akurat robiąc CTFa i próbując uruchomić Netscape 0.9 z 1994),
to że moduł `ia32_aout` mapuje kod binarek ZMAGIC (format a.out) bez prawa do wykonania.
Jak znajdę, o co chodzi w którejś z tych spraw, i naprawię, to może zgłoszę pierwszego
patcha do jądra linuksa :)
Sign in with Wallet
Connect another wallet