Discuta este tópico no fórum

Se este conteúdo te ajudou, deixe um presente!

domingo, 28 de abril de 2013

OpenWRT: Passo a passo da solução de um bug no kernel

Este post será mais um relato do que tenho feito nos últimos dias em relação a um bug muito estranho mas também poderá passar o caminho das pedras se alguém quiser se aventurar mais abaixo neste mundo Linux.

Um problema que encontrei após a configuração do HD externo pela USB foi que algumas partições não apareciam. Meu disco era grande e tinha este formato:

  • sda: disco de 1.5TB
    • sda1: partição primária NTFS de 60GB
    • sda2: partição estendida com o restante do disco
      • sda5: partição lógica ext4 com 1TB
      • sda6: partição lógica swap de 4GB
      • sda7: partição lógica ext4 com 60GB

Se não conhece o básico da estrutura da tabela de partições da MBR, o que é uma partição primária, estendida e lógica, wikipedia é sua amiga.

Nada muito anormal e nunca tive problemas durante anos de uso do disco. Porém, ao conectar no OpenWRT, a partição sda6 e sda7 não apareciam. Cumé? Como em geral acontece, os logs dão uma dica. Esta é a mensagem do kernel:

[  173.870000] sd 1:0:0:0: [sdb] No Caching mode page present
[  173.870000] sd 1:0:0:0: [sdb] Assuming drive cache: write through

[  180.330000]  sdb: sdb1 sdb2 < sdb5 >

[  180.340000] sdb: partition table partially beyond EOD, enabling native capacity

[  180.350000] sd 1:0:0:0: [sdb] No Caching mode page present
[  180.360000] sd 1:0:0:0: [sdb] Assuming drive cache: write through
[  180.370000]  sdb: sdb1 sdb2 < sdb5 >
[  180.370000] sdb: partition table partially beyond EOD, truncated
[  180.380000] sd 1:0:0:0: [sdb] No Caching mode page present
[  180.390000] sd 1:0:0:0: [sdb] Assuming drive cache: write through
[  180.400000] sd 1:0:0:0: [sdb] Attached SCSI disk
Bem, o que era possível entender era que, por algum motivo, o Linux no OpenWRT estava achando que uma partição estava além do fim do disco (EOD). Ele tentava ativar uma "native capacity", que não resolvia, e depois truncava o disco. No final de contas, eu ficava com as partições até a sda5.

Agora vem a beleza do software livre: eu tenho o fonte :-) Fazendo uma busca textual simples pela mensagem, eu encontrei este trecho de código:
linux-3.3.8/block/partition-generic.c:

int rescan_partitions(struct gendisk *disk, struct block_device *bdev)
{
(...)
    state = check_partition(disk, bdev))
(...)
    /*
     * If any partition code tried to read beyond EOD, try
     * unlocking native capacity even if partition table is
     * successfully read as we could be missing some partitions.
     */
    if (state->access_beyond_eod) {
        printk(KERN_WARNING
               "%s: partition table partially beyond EOD, ",
               disk->disk_name);
        if (disk_unlock_native_capacity(disk))
            goto rescan;
    }
(...)
}
Bem, alguma coisa no check_partition(disk, bdev) estava marcando o estado state->access_beyond_eod e gerando a mensagem. Buscando pelo texto access_beyond_eod, achei que ele somente era definido por este código:
linux-3.3.8/block/partitions/check.h:
static inline void *read_part_sector(struct parsed_partitions *state,
                     sector_t n, Sector *p)
{
    if (n >= get_capacity(state->bdev->bd_disk)) {
        state->access_beyond_eod = true;
        return NULL;
    }

    return read_dev_sector(state->bdev, n, p);
}
Pelo código, somente será marcado access_beyond_eod se o setor lido for maior que o tamanho do disco. Agora, quem está errado? O setor? O tamanho do disco? O tamanho do disco parecia estar correto pois ele era apresentado corretamente nas mensagens de kernel e no arquivo /proc/partitions. Deve ser o setor então. Mas ele está errado no disco ou tratado incorretamente?

Para sanar a primeira dúvida, com ajuda da santa wikipedia, fiz um script para interpretar as tabelas de partição na MBR e na partição estendida. Neste ponto, tentando isolar o problema, já tinha apagado as partições 6 e 7, criado uma nova 6 com 1MB, reduzido a partição 1 e criado uma partição 3 entre as partições primárias 1 e 2. Nada disto alterou o resultado. O script mostrou estas informações:
Checking /dev/sdb...

Checking /dev/sdb1...present
Primary Entry: 0001010007FEFFFF3F000000C1676007
Start(CHS): (010100)
End  (CHS): (FEFFFF)
Code      : 07
Start(LBA): 63 (3F000000)
Size(sect): 123758529 sectors, 63364 Mbytes (C1676007)
Checking /dev/sdb2...present
Primary Entry: 00FEFFFF0FFEFFFF1A5E8007E62913A7
Start(CHS): (FEFFFF)
End  (CHS): (FEFFFF)
Code      : 0F
Start(LBA): 125853210 (1A5E8007)
Size(sect): 2803050982 sectors, 1435162 Mbytes (E62913A7)
Extended partition detected! Reading logical partitions...
Checking /dev/sdb5...present

Primary Entry: 00FEFFFF83FEFFFF3F0000002C140080
Active? no
Start(CHS): (FEFFFF)
End  (CHS): (FEFFFF)
Code      : 83
Start(LBA): 63 (3F000000)
Size(sect): 2147488812 sectors, 1099514 Mbytes (2C140080)
Secondary Entry: 00FEFFFF05FEFFFF6B1400807B150000
Next ERB(LBA): 2147488875 (6B140080)
Size(sect): 5499 sectors, 2 Mbytes (7B150000)
Checking /dev/sdb6...present

Primary Entry: 00FEFFFF83FEFFFF7B0D000000080000
Active? no
Start(CHS): (FEFFFF)
End  (CHS): (FEFFFF)
Code      : 83
Start(LBA): 3451 (7B0D0000)
Size(sect): 2048 sectors, 1 Mbytes (00080000)
Secondary Entry: 00000000000000000000000000000000
This is the last logical partition!


Checking /dev/sdb3...present
Primary Entry: 00FEFFFF82FEFFFF0068600700F01F00
Start(CHS): (FEFFFF)
End  (CHS): (FEFFFF)
Code      : 82
Start(LBA): 123758592 (00686007)
Size(sect): 2093056 sectors, 1071 Mbytes (00F01F00)
Checking /dev/sdb4...not present
Em resumo, por encontrar todas as partições, e com o tamanho correto, o disco estava íntegro. Era problema na leitura ou interpretação dos dados pelo kernel. Seria bem mais fácil o disco estar errado... Neste ponto, eu abri um bug para o OpenWRT mas continuei a investigar por conta própria.

O passo seguinte é adicionar mais informações de debug de dentro do kernel. A maneira mais simples é adicionar alguns "printk" (printf do kernel) em pontos estratégicos. Mas primeiro, é necessário encontrar estes pontos.

Meu disco, por ser menor que 2TB, ainda usa tabela de partições MS-DOS. Como o problema ocorre a partir da segunda partição lógica, o código deve estar na parte que lê os dados da partição estendida. O código é este:
linux-3.3.8/block/partitions/msdos.c
static void parse_extended(struct parsed_partitions *state,
                sector_t first_sector, sector_t first_size)
    this_sector = first_sector;

    while (1) {
(...)
        data = read_part_sector(state, this_sector, &sect);
(...)

        p = (struct partition *) (data + 0x1be);
(...)

        for (i=0; i<4; i++, p++)
            if (nr_sects(p) && is_extended_partition(p))
                break;
(...)
         this_sector = first_sector + start_sect(p) * sector_size
                   }
(...)
}
Olha a função read_part_sector que pode marcar access_beyond_eod ali no começo! Para conseguir entender o código, é necessário conhecer a estrutura das partições estendidas. Em resumo, a partição estendida possui uma tabela de partição própria (ERB), onde a primeira entrada descreve a primeira partição lógica e a segunda entrada aponta para a próxima tabela de partição. Voltando as aulas de estrutura de dados, é uma lista ligada/encadeada. Eu coloquei printk ao longo de toda esta função para descobrir o que não estava legal. A parte estranha foi justamente esta última, que soma a posição relativa da próxima tabela de partição com o início da partição estendida:

[   98.230000] parse_extended: sector_size = 1

[   98.230000] parse_extended: start_sect(p) = 2147488875
[   98.230000] parse_extended: start_sect(p)*sector_size = 2147488875
[   98.240000] parse_extended: first_sector = 125853210
[   98.250000] parse_extended: first_sector + start_sect(p) * sector_size = this_sector = 18446744071687926405
O que?! 2147488875 + 125853210 = 18446744071687926405 ?? O que aconteceu com  2273342085? Agora que tinha algo mais palpável, mandei diretamente para a lista de desenvolvimento do OpenWRT. Com ajuda de outros desenvolvedores, descobrimos o problema.

Em primeiro lugar, um pouco de contextualização. Todas as variáveis na expressão problemática são do tipo sector_t, que para meu caso é representado por um u64 (valor inteiro sem sinal de 64 bits). Não deveria ter problemas para as grandezas envolvidas pois vai até 18446744073709551615. Além disto, os setores em uma partição MS-DOS são representados por inteiros sem sinal de 32-bit. Então o 64-bit estão sobrando. Por que o problema? Olhando o binário da resposta correta, 2273342085, e a errada, podemos ver uma coisa em comum:

2273342085(b10)           = 0000000000000000000000 1000101011000000111110(b2)
18446744071687926405(b10) = 1111111111111111111111 1000101011000000111110(b2)

Os bits mais significativos ficaram todos 1 quando o correto seria 0. Uma possível causa deste monte de '1' é de um resultado da conversão de um inteiro com sinal 32-bit para 64-bit. Voltando a aula de análise numérica (wikipedia para relembrar?), os números inteiros com sinal serão negativos quando o primeiro bit for 1. Porém, não é simplesmente colocar um bit na frente. O sistema mais usado atualmente é o complemento para dois. O número negativo é a negação dos bits do mesmo número positivo, mas deslocando em um para não ter zero positivo e negativo. O que importa para este problema é que, para converter um número para outro igual com mais bits, basta completar os bits mais significativos com o valor do primeiro bit. A tabela seguinte mostra exemplo desta conversão de 4-bit para 8-bit:

Decimal
4-bit
8-bit
+3
0011
00000011
+2
0010
00000010
+1
0001
00000001
0
0000
00000000
−1
1111
11111111
−2
1110
11111110
−3
1101
11111101


E o mesmo vale de 32-bit para 64-bit. Como o primeiro bit de 2273342085 é 1, se este fosse um número negativo, ao converter para 64-bit, todos seus primeiros bits serão 1. Mas eu não tinha falado que as variáveis daquela expressão problemática são sem sinal? O compilador se perdeu? Só uma forma de dizer isto: olhando o assembly gerado.

Recompilando o kernel com informações de debug ativadas, é possível extrair o assembly em conjunto com o código em C. A arquitetura do roteador é MIPS. Enfim as aulas de assembly da faculdade com o MIPS servem para alguma coisa! O resultado é este:

this_sector = first_sector + start_sect(p) * sector_size;
 344:   02e00013        mtlo    s7
 348:   00052a00        sll     a1,a1,0x8
 34c:   00031c00        sll     v1,v1,0x10
 350:   00a31825        or      v1,a1,v1
 354:   90850008        lbu     a1,8(a0)
 358:   9084000b        lbu     a0,11(a0)
 35c:   02c00011        mthi    s6
 360:   00651825        or      v1,v1,a1
 364:   00042600        sll     a0,a0,0x18
 368:   00641825        or      v1,v1,a0
 36c:   70720000        madd    v1,s2
 370:   00005812        mflo    t3
 374:   afab004c        sw      t3,76(sp)
 378:   00005010        mfhi    t2
 37c:   afaa0048        sw      t2,72(sp)
A parte que importa está em destaque. A instrução madd é a soma entre dois números inteiros com sinal. O correto deveria ser maddu. Então o compilador acha que isto é um inteiro com sinal? Beleza, compilador com bug, joga fora e pega outro.... não é tão simples assim. Não existe outro compilador que possa ser usado além do gcc para compilar o kernel (llvm está quase lá, mas não para MIPS). Será mesmo problema do compilador? Pode ser, mas pode também ter alguma ajuda do código. Voltando a linha problemática, fora as variáveis locais, existe uma chamada externa para start_sect. Este é o código:
linux-3.3.8/block/partitions/msdos.c:
static inline sector_t start_sect(struct partition *p)
{
    return (sector_t)get_unaligned_le32(&p->start_sect);
}
Ele pega a posição do setor inicial na lista de entradas da tabela de partição, que representa em um número 32-bit, com formato big endian, na mesma ordem usada em protocolos de rede. Este buffer de 4 bytes é passado para a função get_unaligned_le32, que converte para o formato de número 32-bit na ordem da máquina. A implementação desta função depende de cada arquitetura. Em processadores x86, existe uma instrução do processador para fazer isto. Para MIPS, é feiro por código:
linux-3.3.8/include/linux/unaligned/le_byteshift.h:
static inline u32 __get_unaligned_le32(const u8 *p)
{
    return p[0] |p[1] << 8 | p[2] << 16 | p[3] << 24;
}
O código é simples: ele pega cada um dos 4 bytes do buffer 32-bit, desloca cada um para a sua posição correta usando o operador left shift e junta tudo com o operador ou. E qual o problema disto? Existe um não aparente. A especificação C99 define que:


   The integer promotions are performed on each of the operands. The type of the result is
   that of the promoted left operand. If the value of the right operand is negative or is
   greater than or equal to the width of the promoted left operand, the behavior is undefined.

Então, se o lado esquerdo possuir menos ou o mesmo número de bits deslocados pelo lado direito do operador, o comportamento não é definido, que em miúdos quer dizer, se você fizer isto, não sei o que vai acontecer. Nisto, o compilador se perdeu e, por algum motivo, ignorou o fato das variáveis serem sem sinal. Pode ser que ele ainda estivesse considerando operações para variáveis sem sinal 8-bit, onde não importa muito se você está usando um operador 32-bit com ou sem sinal. A solução é ligeiramente simples: converter o tipo do lado esquerdo antes de aplicar o operador. Fica assim:
linux-3.3.8/include/linux/unaligned/le_byteshift.h:
static inline u32 __get_unaligned_le32(const u8 *p)
{
    return p[0] | (u32)p[1] << 8 | (u32)p[2] << 16 | (u32)p[3] << 24;
}

E o código assembly indica que o compilador, agora, assume que aquela soma é entre variáveis sem sinal:

 this_sector = first_sector + start_sect(p) * sector_size;
 344:   02e00013        mtlo    s7
 348:   00052a00        sll     a1,a1,0x8
 34c:   00031c00        sll     v1,v1,0x10
 350:   00a31825        or      v1,a1,v1
 354:   90850008        lbu     a1,8(a0)
 358:   9084000b        lbu     a0,11(a0)
 35c:   02c00011        mthi    s6
 360:   00651825        or      v1,v1,a1
 364:   00042600        sll     a0,a0,0x18
 368:   00641825        or      v1,v1,a0
 36c:   70720001        maddu   v1,s2
 370:   00005812        mflo    t3
 374:   afab004c        sw      t3,76(sp)
 378:   00005010        mfhi    t2
 37c:   afaa0048        sw      t2,72(sp)
Note que a instrução mudou de madd para maddu. Provavelmente foram alteradas outras instruções no código mas ao menos agora sei que o compilador está tratando como número sem sinal.

Adicionado o patch ao kernel, recompilando a imagem e instalando, volto a ter acesso a todas as partições do disco!

Acredito que este problema ainda era desconhecido por ser raro juntar uma arquitetura vulnerável ao problema com ao menos uma partição lógica iniciada além do setor 4294967296 (ou 1 TB) na partição. O mundo x86 não é afetado pois a função __get_unaligned_le32 é implementada diretamente por uma instrução do processador.


Agora falta apenas submeter oficialmente o patch para o Openwrt e para o kernel oficial. Enfim, a culpa era do kernel Linux e compilador, não diretamente do OpenWRT.

Até a próxima!

Nenhum comentário:

Postar um comentário