OpenWRT/LEDE: Debugando código dentro do roteador (e corrigindo bugs)

Mais um artigo da série OpenWRT/LEDE.

Fazer o debug de um programa muda a forma de desenvolvimento de um código. É imensamente melhor do que usar printf ao longo do código. Você pode ver os valores de qualquer variável, adicionar paradas condicionais, ver onde ele engasgou, etc. Para tudo isto, basta compilar seu código com os símbolos de debug, acesso ao código fonte (ajuda) e um debugger.

Uma das coisas que eu acho fantástico no mundo Linux é, diante de um problema, instalar os símbolos, código fonte e disparar um debugger. Isto com o processo rodado! Apesar dos programas instalados não conterem os símbolos, normalmente a distribuição fornece estes símbolos em um pacote a parte. Eu parto de um processo problemático em execução para um passo a passo dentro do código em poucos minutos. Fantástico!

Agora voltamos ao tema do artigo: como posso "debugar" dentro do OpenWRT/LEDE? Temos os símbolos nos executáveis? Não, são removidos antes de serem empacotados pelo sstrip. Mesmo que não fossem, normalmente você não teria espaço no roteador para instalar um executável com os símbolos de debug e mais o código fonte (ao menos que tenha expandido o disco com uma unidade externa). O gdb seria até pequeno, mas é sem símbolos e o fonte ele não tem muita utilidade. Mesmo se tivesse tudo isso, ainda debugar pelo gdb remotamente não é a forma mais amigável para este trabalho. Para coisas maiores, uma interface gráfica pode deixar o trabalho mais agradável.

Felizmente o OpenWRT/LEDE já está preparado para esta interação. Vamos tomar como exemplo o sane-backends, pacote que mantenho no OpenWRT/LEDE. Ele estava com um comportamento engraçado. O scanner aparecia na listagem mas sempre falhava ao escanear. Rodando localmente um escaneamento, eu obtinha:

root@router.lan3:~# scanimage >/dev/null
Trace/breakpoint trap

Parei o xinetd (que estava aguardando pelos pedidos do saned) e rodei o saned em modo debug. Novamente, o famigerado erro:

root@router.lan3:~# saned -d 128

[saned] main: starting debug mode (level 2)

[saned] saned (AF-indep+IPv6) from sane-backends 1.0.25 starting up

[saned] do_bindings: [0] bind failed: Address in use

[saned] check_host: access by remote host: ::ffff:192.168.3.20

[saned] init: access granted to luizluca@::ffff:192.168.3.20

Trace/breakpoint trap

Não fui apresentado, mas pelo nome, parece algo explicitamente introduzido. Alguma verificação falhou e abortou o programa. Sem mais informações por meio de mensagens, resta o debug do código.

O primeiro passo é ter os fontes e os códigos compilados. Provavelmente tudo isso se aplica caso opte por usar o SDK, mas vou, a princípio considerar que você está usando a árvore completa do projeto. Você precisa dos fontes e configurar o ambiente para compilar, ao menos, o sane-backend. Esta preparação já foi feita em outro artigo sobre compilação a partir dos fontes.

No roteador, eu irei debugar o programa saned, que não contém informações de debug. No pacote, ele é bem reduzido (menos que 33 kbytes):

$ tar --to-stdout -xzf bin/packages/mips_24kc/packages/sane-daemon_1.0.25-2_mips_24kc.ipk ./data.tar.gz | tar tzv ./usr/sbin/saned

-rwxr-xr-x root/root     32900 2017-03-12 22:40 ./usr/sbin/saned

Porém, antes de ser limpo pelo sstrip, ele tinha:

$ stat -c "%A %U %G %y %s %n" staging_dir/target-mips_24kc_musl-1.1.16/root-ar71xx/usr/sbin/saned
-rwxr-xr-x luizluca deluca 2017-03-12 22:40:49.510354194 -0300 44200 staging_dir/target-mips_24kc_musl-1.1.16/root-ar71xx/usr/sbin/saned

Agora vamos recompilar o pacote com os símbolos. Você pode fazer isso adicionando a opção no menuconfig para incluir os símbolo de debug em toda a árvore. Eu prefiro adicionar pontualmente os símbolos em alguns pacotes. Para isto, basta incluir a configuração extra na chamada do make:

$ make -j5 package/sane-backends/{clean,compile} CONFIG_DEBUG=y

Adicione ainda um V=s se quiser ver muitas letrinhas passando (ou precisar resolver problemas de compilação). Se fizer, observe um -g3 a mais nos argumentos do gcc.

O resultado é um executável relativamente maior:

$ stat -c "%A %U %G %y %s %n" staging_dir/target-mips_24kc_musl-1.1.16/root-ar71xx/usr/sbin/saned -rwxr-xr-x luizluca deluca 2017-03-12 23:56:52.157169597 -0300 188296 staging_dir/target-mips_24kc_musl-1.1.16/root-ar71xx/usr/sbin/saned

Mas o ipkg continua exatamente igual, pois os símbolos ainda foram removidos antes do empacotamento.

No meu caso, uso o driver hplip. Então, incluí em todo o processo anterior este pacote. Além de adicionar no menuconfig, o make ficou assim:

$ make -j5 package/{sane-backends,hplip}/clean package/{sane-backends,hplip}/compile CONFIG_DEBUG=y

Tudo pronto, agora vamos ao roteador. Vou instalar o gdbserver. Como o nome já diz, é um servidor do gdb, permitindo que um gdb na minha máquina use um executável rodando em uma máquina remota.

root@router.lan3:~# opkg install gdbserver

E agora, repito o comando do saned mas pelo gdbserver:

root@router.lan3:~# gdbserver :9000 /usr/sbin/saned -d 128Process /usr/sbin/saned created; pid = 4391Listening on port 9000

A princípio, ele inicia o processo parado, aguardando a conexão do gdb e sua autorização para continuar. No lado do computador, o OpenWRT/LEDE já fornece um "facilitador" para configurar o gdb remoto:

$ ./scripts/remote-gdb router:9000 staging_dir/target-mips_24kc_musl-1.1.16/root-ar71xx/usr/sbin/saned

Pronto! Estou com o debugger na mão. Peço ao gdb para parar ao receber qualquer sinal ("catch signal all"). Depois, libero a execução ("cont") até chegar em algo interessante.

Thread 1 "saned" hit Catchpoint 1 (signal SIGTRAP), memcpy (__n=270, __os=0x77dc3a76 <ms+770086>, __od=0x77dc3a74 <ms+770084>)    at /home/luizluca/prog-local/lede/17.01/staging_dir/toolchain-mips_24kc_gcc-5.4.0_musl-1.1.16/include/fortify/string.h:4848 __builtin_trap();

(gdb) bt#0  memcpy (__n=270, __os=0x77dc3a76 <ms+770086>, __od=0x77dc3a74 <ms+770084>) at /home/luizluca/prog-local/lede/17.01/staging_dir/toolchain-mips_24kc_gcc-5.4.0_musl-1.1.16/include/fortify/string.h:48#1  device_id (fd=1,     buffer=0x77dc3a74 <ms+770084> "\001\020MFG:HP;MDL:Officejet J4660 series;CMD:MLC,PCL,PML,DW-PCL,DESKJET,DYN;1284.4DL:4d,4e,1;CLS:PRINTER;DES:CB786A;SN:BR145GF09J052W;S:038000C484001021002c1f0005cc2d8002b;J:", ' ' <repete 20 vezes>, ";Z:0102,050"..., size=1024) at io/hpmud/musb.c:773#2  0x77cbe5cd in musb_open (pd=<optimized out>) at io/hpmud/musb.c:1160#3  0x77cb8067 in hpmud_open_device (uri=<optimized out>, iomode=HPMUD_DOT4_MODE, dd=0x41b0a4) at io/hpmud/hpmud.c:539#4  0x77ebbc51 in sclpml_open (device=0x418a96 "/usb/Officejet_J4660_series?serial=BR145GF09J052W", pHandle=0x7ffffaf4) at scan/sane/sclpml.c:2016#5  0x77eb02f7 in sane_hpaio_open (devicename=0x418a96 "/usb/Officejet_J4660_series?serial=BR145GF09J052W", pHandle=0x7ffffaf4) at scan/sane/hpaio.c:267#6  0x77f3f673 in sane_dll_open (full_name=<optimized out>, meta_handle=0x0) at dll.c:1201#7  0x77f31e97 in sane_open (name=<optimized out>, h=<optimized out>) at dll-s.c:23#8  0x00403391 in process_request (w=0x418198 <wire>) at saned.c:1916#9  0x00403a99 in handle_connection (fd=<optimized out>) at saned.c:2283#10 0x00402031 in run_standalone (argv=<optimized out>, argc=3) at saned.c:3167#11 main (argc=<optimized out>, argv=<optimized out>) at saned.c:3345

Hum... fortify... O LEDE introduziu opções de compilação que restringem alguns comportamentos inseguros (_FORTITY_SOURCE), "fortificando" o programa contra ataques. Pela pilha, isso foi dentro do hplip. Acho que ele tem algum problema...

A chamada em questão foi em io/hpmud/musb.c, linha 773:

 771     if (len > 2)

 772         len -= 2;

 773     memcpy(buffer, buffer+2, len);    /* remove length */

 774     buffer[len]=0;

 775     DBG("read actual device_id successfully fd=%d len=%d\n", fd, len);

Opa! Copiando o buffer sobre ele mesmo para tirar os dois primeiros bytes? OK, mas não usando memcpy! Muito feio! Isto nunca era para dar certo... O memcpy simplesmente copia de um lado para outro, desconsiderando sobreposição. Isto quer dizer, pode copiar do começo ao fim (ou o inverso), em blocos de vários bytes, etc. Foi sorte ter funcionado até agora (e funcionou?). A alternativa correta é o memmove, que verifica possíveis sobreposições e decide se copia de trás para frente, ou do início ao fim. Caso não tenha sobreposições, simplesmente chama o memcpy. E  claro que temos sobreposições aqui!

Vamos tentar a última versão 3.16.11 do hplip? Não, ainda está lá o memcpy. Vamos precisar fazer um patch.

A melhor forma de trabalhar com patches dos programas empacotados no OpenWRT/LEDE é pelo quilt. Ele gerencia os patches de forma menos dolorida, em especial para atualizar os endereços depois de uma mudança de versão, onde os "hunks" funcionaram. Como acabei de atualizar a versão do hplip, devem ocorrer mudanças nos fontes e os patches existentes precisam ser atualizados:

$ make package/hplip/{clean,prepare} QUILT=y
$ cd build_dir/target-mips_24kc_musl-1.1.16/hplip-3.16.11
$ quilt push
Aplicando caminho 010-libusb_fix.patch
patching file configure.in
Hunk #1 succeeded at 561 (offset 38 lines).
Agora no caminho 010-libusb_fix.patch 

$ quilt refresh # atualizar o endereço do patch
Patch atualizado 010-libusb_fix.patch

Tudo certo até aqui. Patch atualizado sem esforço.

$ quilt push
Aplicando caminho 020-remove_cups_dep_on_scan.patch
patching file scan/sane/hpaio.c
Hunk #2 FAILED at 172.
Hunk #3 FAILED at 232.
Hunk #4 FAILED at 259.
3 out of 4 hunks FAILED -- rejects in file scan/sane/hpaio.c
patching file Makefile.am
Hunk #1 succeeded at 60 with fuzz 1 (offset 1 line).
Caminho 020-remove_cups_dep_on_scan.patch não aplica (force com -f)

Hum... conflito. Preciso intervir manualmente.

$ quilt push -fAplicando caminho 020-remove_cups_dep_on_scan.patchpatching file scan/sane/hpaio.cHunk #2 FAILED at 172.Hunk #3 FAILED at 232.Hunk #4 FAILED at 259.3 out of 4 hunks FAILED -- saving rejects to file scan/sane/hpaio.c.rejpatching file Makefile.amHunk #1 succeeded at 60 with fuzz 1 (offset 1 line).Caminho 020-remove_cups_dep_on_scan.patch aplicado (forçado; necessita ser atualizado)
$ quilt edit scan/sane/hpaio.c<faz a mágica para resolver o conflito...>$ quilt refresh

Agora vamos, enfim, fazer o novo patch:

$ quilt new 030-replace_unsafe_memcpy_with_memmove.patch$ quilt edit io/hpmud/musb.c<troca o memcpy por memmove>$ quilt refresh

De volta a raiz do projeto, pedimos que ele atualize os patches: 

make package/hplip/update QUILT=y

E, por fim, limpar e recompilar:

make package/hplip/{clean,compile} CONFIG_DEBUG=y

Tudo compilado, só copiar, instalar e testar

$ scp bin/packages/mips_24kc/packages/hplip-* root@router:/tmp

root@router.lan3:~# opkg install /tmp/*hplip*

Upgrading hplip-common on root from 3.15.7-1 to 3.16.11-1...

Upgrading hplip-sane on root from 3.15.7-1 to 3.16.11-1...

Configuring hplip-common.

Configuring hplip-sane.

root@router.lan3:~# 

E...

Infelizmente, o "funcionar" é não mostram uma mensagem de erro e não abortar o processo. Não faz muito sentido colar a saída.

Agora, para a cereja do bolo, bug submetido ao hplip.

Até a próxima. Happy Hacking!