mdadm marca o hdd com defeito mesmo que esteja em estado de saúde puro?

4

Eu tenho meu NAS personalizado configurado para desativar unidades após 20 minutos de inatividade.

Neste momento, verifiquei /proc/mdstat e notei que uma unidade foi marcada como falhada, no entanto, a SMART mostra que a unidade está em boas condições de saúde. Por isso, suspeito que o pensamento de md-raid estava demorando demais e marcou o fracasso da campanha.

A adição e a reconstrução também não parecem ser um problema.

dmesg mostra as seguintes linhas interessantes que não consigo encontrar muito no googling.

[97144.228682] sd 0:0:2:0: attempting task abort! scmd(ffff97f7b14ce948)
[97144.228688] sd 0:0:2:0: [sdc] tag#0 CDB: opcode=0x12 12 00 00 00 24 00
[97144.228692] scsi target0:0:2: handle(0x000c), sas_address(0x5001438020b9ee12), phy(18)
[97144.228694] scsi target0:0:2: enclosure_logical_id(0x5001438020b9ee25), slot(49)
[97148.184253] sd 0:0:2:0: task abort: SUCCESS scmd(ffff97f7b14ce948)
[97148.235864] mpt2sas_cm0: log_info(0x31110101): originator(PL), code(0x11), sub_code(0x0101)
--- last message repeated a couple dozen times ---
[97148.490304] sd 0:0:2:0: [sdc] tag#16 UNKNOWN(0x2003) Result: hostbyte=0x0b driverbyte=0x00
[97148.490308] mpt2sas_cm0: log_info(0x31110101): originator(PL), code(0x11), sub_code(0x0101)
[97148.490310] sd 0:0:2:0: [sdc] tag#13 UNKNOWN(0x2003) Result: hostbyte=0x0b driverbyte=0x00
[97148.490315] sd 0:0:2:0: [sdc] tag#13 CDB: opcode=0x88 88 00 00 00 00 00 0d 6e af f0 00 00 00 10 00 00
[97148.490317] mpt2sas_cm0: log_info(0x31110101): originator(PL), code(0x11), sub_code(0x0101)
[97148.490321] print_req_error: I/O error, dev sdc, sector 225357808
[97148.490326] mpt2sas_cm0: log_info(0x31110101): originator(PL), code(0x11), sub_code(0x0101)
[97148.490331] sd 0:0:2:0: [sdc] tag#16 CDB: opcode=0x88 88 00 00 00 00 00 0d 6e b0 18 00 00 00 20 00 00
[97148.490334] mpt2sas_cm0: log_info(0x31110101): originator(PL), code(0x11), sub_code(0x0101)
[97148.490337] print_req_error: I/O error, dev sdc, sector 225357848
[97148.490341] mpt2sas_cm0: log_info(0x31110101): originator(PL), code(0x11), sub_code(0x0101)
[97148.490354] mpt2sas_cm0: log_info(0x31110101): originator(PL), code(0x11), sub_code(0x0101)
[97148.490358] mpt2sas_cm0: log_info(0x31110101): originator(PL), code(0x11), sub_code(0x0101)
[97148.490366] mpt2sas_cm0: log_info(0x31110101): originator(PL), code(0x11), sub_code(0x0101)
[97148.490370] sd 0:0:2:0: [sdc] tag#15 UNKNOWN(0x2003) Result: hostbyte=0x0b driverbyte=0x00
[97148.490374] mpt2sas_cm0: log_info(0x31110101): originator(PL), code(0x11), sub_code(0x0101)
[97148.490378] sd 0:0:2:0: [sdc] tag#15 CDB: opcode=0x88 88 00 00 00 00 00 0d 6e ae 68 00 00 00 08 00 00
[97148.490380] print_req_error: I/O error, dev sdc, sector 225357416
[97148.490383] mpt2sas_cm0: log_info(0x31110101): originator(PL), code(0x11), sub_code(0x0101)
[97148.490392] mpt2sas_cm0: log_info(0x31110101): originator(PL), code(0x11), sub_code(0x0101)
[97148.490399] mpt2sas_cm0: log_info(0x31110101): originator(PL), code(0x11), sub_code(0x0101)
[97148.490403] sd 0:0:2:0: [sdc] tag#14 UNKNOWN(0x2003) Result: hostbyte=0x0b driverbyte=0x00
[97148.490407] sd 0:0:2:0: [sdc] tag#14 CDB: opcode=0x88 88 00 00 00 00 00 0d 6e ad 90 00 00 00 30 00 00
[97148.490409] print_req_error: I/O error, dev sdc, sector 225357200
[97148.490435] sd 0:0:2:0: [sdc] tag#11 UNKNOWN(0x2003) Result: hostbyte=0x0b driverbyte=0x00
[97148.490439] sd 0:0:2:0: [sdc] tag#11 CDB: opcode=0x88 88 00 00 00 00 00 0d 6e ad c8 00 00 00 58 00 00
[97148.490441] print_req_error: I/O error, dev sdc, sector 225357256
[97148.490450] sd 0:0:2:0: [sdc] tag#10 UNKNOWN(0x2003) Result: hostbyte=0x0b driverbyte=0x00
[97148.490454] sd 0:0:2:0: [sdc] tag#10 CDB: opcode=0x88 88 00 00 00 00 00 0d 6e ad 00 00 00 00 50 00 00
[97148.490456] print_req_error: I/O error, dev sdc, sector 225357056
[97148.490464] sd 0:0:2:0: [sdc] tag#9 UNKNOWN(0x2003) Result: hostbyte=0x0b driverbyte=0x00
[97148.490468] sd 0:0:2:0: [sdc] tag#9 CDB: opcode=0x35 35 00 00 00 00 00 00 00 00 00
[97148.490472] print_req_error: I/O error, dev sdc, sector 16
[97148.490474] md: super_written gets error=10
[97148.490477] md/raid:md0: Disk failure on sdc, disabling device.
               md/raid:md0: Operation continuing on 3 devices.
[97148.490496] sd 0:0:2:0: [sdc] tag#8 UNKNOWN(0x2003) Result: hostbyte=0x0b driverbyte=0x00
[97148.490500] sd 0:0:2:0: [sdc] tag#8 CDB: opcode=0x88 88 00 00 00 00 00 0d 6e b0 40 00 00 00 20 00 00
[97148.490502] print_req_error: I/O error, dev sdc, sector 225357888
[97148.490510] sd 0:0:2:0: [sdc] tag#7 UNKNOWN(0x2003) Result: hostbyte=0x0b driverbyte=0x00
[97148.490514] sd 0:0:2:0: [sdc] tag#7 CDB: opcode=0x88 88 00 00 00 00 00 0d 6e af b8 00 00 00 30 00 00
[97148.490516] print_req_error: I/O error, dev sdc, sector 225357752
[97148.490524] sd 0:0:2:0: [sdc] tag#6 UNKNOWN(0x2003) Result: hostbyte=0x0b driverbyte=0x00
[97148.490528] sd 0:0:2:0: [sdc] tag#6 CDB: opcode=0x88 88 00 00 00 00 00 0d 6e b0 00 00 00 00 08 00 00
[97148.490530] print_req_error: I/O error, dev sdc, sector 225357824

Existe um valor de tempo limite que posso aumentar para que o md-raid espere alguns minutos para que as unidades fiquem on-line?
Quaisquer outras opções para evitar isso no futuro (além de manter minhas unidades girando 24/7 porque eu também quero dormir de vez em quando)?

Atualização 2017-10-07

Atualização do firmware do controlador (é uma cruzada do Perc H310 para o modo de TI 9211-8i), atualizar o firmware do expansor SAS e aumentar o tempo limite parece ter reduzido bastante a frequência de erros acima, mas eles ainda acontecem e em algumas ocasiões md -raid ainda falha a unidade.

Eu decodifiquei o código de erro do SAS:

Value           31110101h
Type:           30000000h       SAS
Origin:         01000000h       PL
Code:           00110000h       PL_LOGINFO_CODE_RESET See Sub-Codes below (PL_LOGINFO_SUB_CODE)
Sub Code:       00000100h       PL_LOGINFO_SUB_CODE_OPEN_FAILURE
SubSub Code:    00000001h       PL_LOGINFO_SUB_CODE_OPEN_FAILURE_NO_DEST_TIMEOUT

Para o qual não consegui encontrar nada além de uma breve descrição online (em um pdf do LSI de 2009):

Failed to open connection with error Open Reject (No Destination). Retried for 50milliseconds.

Após alguns testes adicionais (provocando o problema com hdparm -y ... para girar as unidades para baixo e hddtemp ... para girá-las com um comando simples), achei o tempo limite um pouco acima de 11 segundos, o que é estranho porque a única as configurações de tempo limite restantes em um valor de 10 são tempos limite genéricos de E / S para dispositivos "sequenciais", "removíveis" e "desconhecidos".

Atualização 2017-10-08

Aqui está a topologia da minha configuração:

Dell Perc H310 (LSISAS2008: FWVersion(20.00.07.00), ChipRevision(0x03), BiosVersion(07.39.02.00)) (flashed to 9211-8i IT-mode)
    '- HP SAS Expander card (FW 2.10)
        |- Hitachi HDS72404 } md0
        |- Hitachi HDS72404 } md0
        |- HGST HDN724040AL } md0
        |- HGST HDN724040AL } md0
        |- ST8000AS0002-1NA (btrfs)
        |- ST8000AS0002-1NA (btrfs)
        '- ST8000AS0002-1NA (xfs)

As quatro unidades Hitachi / HGST compreendem a matriz md-raid, as unidades da Seagate não estão relacionadas ao md-raid, mas também são afetadas pelo problema raiz (mas o btrfs não parece se importar tanto).

Aqui está o que eu fiz até agora, depois de muitas horas de pesquisa e experimentação, e não ajudou muito:

Execute o seguinte código na inicialização, aumentando alguns tempos limite de mpt2sas :

for f in /sys/block/sd?/device/timeout; do
        echo 90 > "$f"
done

for f in /sys/block/sd?/device/eh_timeout; do
        echo 90 > "$f"
done

for f in /sys/class/scsi_disk/*/manage_start_stop; do
        echo 1 > "$f"
done

Atualizei meu firmware de HBA e expansor.

Defina todos os tempos limite no utilitário de configuração do BIOS do HBA para 90 segundos.

No entanto, os tempos limite ainda acontecem de forma bastante previsível durante o despertar do disco rígido (rotação) a partir do modo de espera após 11 a 12 segundos. (Estou suspeitando de um tempo limite de 10 segundos, já que é o padrão para muitos timeouts, com algum atraso extra.)

Atualização de 2017-10-10

Eu agora escrevi um script que verifica continuamente dmesg para dispositivos descartados e automaticamente emite mdadm --manage /dev/md0 --re-add /dev/sdx para eles. Com a recuperação de bitmap com intenção de gravação, agora leva alguns segundos em vez de um dia. Mas isso não pode ser a solução adequada para esse problema.

Eu também acabei de escrever para a Broadcom, talvez eles possam ajudar.

Atualização de 2017-10-11

Estou no processo de depuração do meu kernel para possíveis problemas:

--drive put to standby with hdparm -y--
18:16:35 sd 0:0:1:0: [sdb] sd_open
18:16:35 sd 0:0:1:0: scsi_block_when_processing_errors: rtn: 1
18:16:35 sd 0:0:1:0: scsi_block_when_processing_errors: rtn: 1
18:16:35 sd 0:0:1:0: [sdb] tag#0 Send: scmd 0xffff989bc94ea548
18:16:35 sd 0:0:1:0: [sdb] tag#0 CDB: ATA command pass through(16) 85 06 20 00 00 00 00 00 00 00 00 00 00 40 e0 00
18:16:35 SCSI DEBUG: scsi_check_sense() scsi_check_sense 442 
18:16:35 SCSI DEBUG: scsi_check_sense() continuing default behaviour past line 484 
18:16:35 sd 0:0:1:0: [sdb] tag#0 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK
18:16:35 sd 0:0:1:0: [sdb] tag#0 CDB: ATA command pass through(16) 85 06 20 00 00 00 00 00 00 00 00 00 00 40 e0 00
18:16:35 sd 0:0:1:0: [sdb] tag#0 Sense Key : Recovered Error [current] [descriptor] 
18:16:35 sd 0:0:1:0: [sdb] tag#0 Add. Sense: ATA pass through information available
18:16:35 sd 0:0:1:0: [sdb] tag#0 scsi host busy 1 failed 0
18:16:35 sd 0:0:1:0: Notifying upper driver of completion (result 8000002)
18:16:35 sd 0:0:1:0: [sdb] sd_release
18:16:35 sd 0:0:1:0: [sdb] sd_check_events
18:16:35 sd 0:0:1:0: scsi_block_when_processing_errors: rtn: 1
18:16:35 sd 0:0:1:0: tag#0 Send: scmd 0xffff989bc866e148
18:16:35 sd 0:0:1:0: tag#0 CDB: Test Unit Ready 00 00 00 00 00 00
18:16:35 SCSI DEBUG: scsi_check_sense() scsi_check_sense 442 
18:16:35 SCSI DEBUG: scsi_check_sense()=>SUCCESS [nasty midlayer TURs] 
18:16:35 sd 0:0:1:0: tag#0 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK
18:16:35 sd 0:0:1:0: tag#0 CDB: Test Unit Ready 00 00 00 00 00 00
18:16:35 sd 0:0:1:0: tag#0 Sense Key : Unit Attention [current] 
18:16:35 sd 0:0:1:0: tag#0 Add. Sense: Power on, reset, or bus device reset occurred
18:16:35 sd 0:0:1:0: tag#0 scsi host busy 1 failed 0
18:16:35 sd 0:0:1:0: Notifying upper driver of completion (result 8000002)
18:16:35 sd 0:0:1:0: tag#0 Send: scmd 0xffff989bc866e148
18:16:35 sd 0:0:1:0: tag#0 CDB: Test Unit Ready 00 00 00 00 00 00
18:16:35 SCSI DEBUG: scsi_check_sense() scsi_check_sense 442 
18:16:35 SCSI DEBUG: scsi_check_sense()=>SUCCESS [nasty midlayer TURs] 
18:16:35 sd 0:0:1:0: tag#0 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK
18:16:35 sd 0:0:1:0: tag#0 CDB: Test Unit Ready 00 00 00 00 00 00
18:16:35 sd 0:0:1:0: tag#0 Sense Key : Not Ready [current] 
18:16:35 sd 0:0:1:0: tag#0 Add. Sense: Logical unit not ready, initializing command required
18:16:35 sd 0:0:1:0: tag#0 scsi host busy 1 failed 0
18:16:35 sd 0:0:1:0: Notifying upper driver of completion (result 8000002)
--command executed on drive with hddtemp--
18:16:45 sd 0:0:1:0: [sdb] sd_open
18:16:45 sd 0:0:1:0: scsi_block_when_processing_errors: rtn: 1
18:16:45 sd 0:0:1:0: scsi_block_when_processing_errors: rtn: 1
18:16:45 sd 0:0:1:0: scsi_block_when_processing_errors: rtn: 1
18:16:45 sd 0:0:1:0: [sdb] tag#0 Send: scmd 0xffff989bc8669548
18:16:45 sd 0:0:1:0: [sdb] tag#0 CDB: Inquiry 12 00 00 00 24 00
18:16:45 sd 0:0:1:0: [sdb] tag#0 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK
18:16:45 sd 0:0:1:0: [sdb] tag#0 CDB: Inquiry 12 00 00 00 24 00
18:16:45 sd 0:0:1:0: [sdb] tag#0 scsi host busy 1 failed 0
18:16:45 sd 0:0:1:0: Notifying upper driver of completion (result 0)
18:16:45 sd 0:0:1:0: scsi_block_when_processing_errors: rtn: 1
18:16:45 sd 0:0:1:0: [sdb] tag#0 Send: scmd 0xffff989bc8669548
18:16:45 sd 0:0:1:0: [sdb] tag#0 CDB: ATA command pass through(16) 85 08 2e 00 00 00 00 00 00 00 00 00 00 00 ec 00
18:16:45 SCSI DEBUG: scsi_check_sense() scsi_check_sense 442 
18:16:45 SCSI DEBUG: scsi_check_sense() continuing default behaviour past line 484 
18:16:45 sd 0:0:1:0: [sdb] tag#0 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK
18:16:45 sd 0:0:1:0: [sdb] tag#0 CDB: ATA command pass through(16) 85 08 2e 00 00 00 00 00 00 00 00 00 00 00 ec 00
18:16:45 sd 0:0:1:0: [sdb] tag#0 Sense Key : Recovered Error [current] [descriptor] 
18:16:45 sd 0:0:1:0: [sdb] tag#0 Add. Sense: ATA pass through information available
18:16:45 sd 0:0:1:0: [sdb] tag#0 scsi host busy 1 failed 0
18:16:45 sd 0:0:1:0: Notifying upper driver of completion (result 8000002)
18:16:45 sd 0:0:1:0: scsi_block_when_processing_errors: rtn: 1
18:16:45 sd 0:0:1:0: [sdb] tag#0 Send: scmd 0xffff989bc8669548
18:16:45 sd 0:0:1:0: [sdb] tag#0 CDB: ATA command pass through(16) 85 08 2e 00 00 00 00 00 00 00 00 00 00 00 ec 00
18:16:45 SCSI DEBUG: scsi_check_sense() scsi_check_sense 442 
18:16:45 SCSI DEBUG: scsi_check_sense() continuing default behaviour past line 484 
18:16:45 sd 0:0:1:0: [sdb] tag#0 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK
18:16:45 sd 0:0:1:0: [sdb] tag#0 CDB: ATA command pass through(16) 85 08 2e 00 00 00 00 00 00 00 00 00 00 00 ec 00
18:16:45 sd 0:0:1:0: [sdb] tag#0 Sense Key : Recovered Error [current] [descriptor] 
18:16:45 sd 0:0:1:0: [sdb] tag#0 Add. Sense: ATA pass through information available
18:16:45 sd 0:0:1:0: [sdb] tag#0 scsi host busy 1 failed 0
18:16:45 sd 0:0:1:0: Notifying upper driver of completion (result 8000002)
18:16:45 sd 0:0:1:0: scsi_block_when_processing_errors: rtn: 1
18:16:45 sd 0:0:1:0: scsi_block_when_processing_errors: rtn: 1
18:16:45 sd 0:0:1:0: scsi_block_when_processing_errors: rtn: 1
18:16:45 sd 0:0:1:0: [sdb] tag#0 Send: scmd 0xffff989bc8669548
18:16:45 sd 0:0:1:0: [sdb] tag#0 CDB: ATA command pass through(16) 85 06 20 00 d8 00 00 00 00 00 4f 00 c2 00 b0 00
18:16:53 sd 0:0:1:0: [sdb] tag#0 Done: TIMEOUT_ERROR Result: hostbyte=DID_OK driverbyte=DRIVER_OK
18:16:53 sd 0:0:1:0: [sdb] tag#0 CDB: ATA command pass through(16) 85 06 20 00 d8 00 00 00 00 00 4f 00 c2 00 b0 00
18:16:53 sd 0:0:1:0: [sdb] tag#0 scsi host busy 1 failed 0
18:16:53 sd 0:0:1:0: [sdb] tag#0 abort scheduled
18:16:53 sd 0:0:1:0: [sdb] tag#0 aborting command
18:16:53 sd 0:0:1:0: attempting task abort! scmd(ffff989bc8669548)
18:16:53 sd 0:0:1:0: [sdb] tag#0 CDB: ATA command pass through(16) 85 06 20 00 d8 00 00 00 00 00 4f 00 c2 00 b0 00
18:16:53 scsi target0:0:1: handle(0x000a), sas_address(0x5001438020b9ee10), phy(16)
18:16:53 scsi target0:0:1: enclosure_logical_id(0x5001438020b9ee25), slot(51)
18:16:57 sd 0:0:1:0: task abort: SUCCESS scmd(ffff989bc8669548)
18:16:57 sd 0:0:1:0: [sdb] tag#0 finish aborted command
18:16:57 sd 0:0:1:0: Notifying upper driver of completion (result 30000)
18:16:57 sd 0:0:1:0: [sdb] sd_release
18:16:57 sd 0:0:1:0: [sdb] sd_check_events
18:16:57 sd 0:0:1:0: scsi_block_when_processing_errors: rtn: 1
18:16:57 sd 0:0:1:0: tag#0 Send: scmd 0xffff989bd1de9148
18:16:57 sd 0:0:1:0: tag#0 CDB: Test Unit Ready 00 00 00 00 00 00
18:16:57 mpt2sas_cm0: log_info(0x31110101): originator(PL), code(0x11), sub_code(0x0101)
18:16:57 sd 0:0:1:0: tag#0 Done: NEEDS_RETRY Result: hostbyte=DID_SOFT_ERROR driverbyte=DRIVER_OK
18:16:57 sd 0:0:1:0: tag#0 CDB: Test Unit Ready 00 00 00 00 00 00
18:16:57 sd 0:0:1:0: tag#0 scsi host busy 1 failed 0
18:16:57 sd 0:0:1:0: tag#0 Inserting command ffff989bd1de9148 into mlqueue
18:16:57 sd 0:0:1:0: unblocking device at zero depth
18:16:57 sd 0:0:1:0: tag#0 Send: scmd 0xffff989bd1de9148
18:16:58 mpt2sas_cm0: log_info(0x31110101): originator(PL), code(0x11), sub_code(0x0101)
18:16:57 sd 0:0:1:0: tag#0 CDB: Test Unit Ready 00 00 00 00 00 00
18:16:58 sd 0:0:1:0: tag#0 Done: NEEDS_RETRY Result: hostbyte=DID_SOFT_ERROR driverbyte=DRIVER_OK
18:16:58 sd 0:0:1:0: tag#0 CDB: Test Unit Ready 00 00 00 00 00 00
18:16:58 sd 0:0:1:0: tag#0 scsi host busy 1 failed 0
18:16:58 sd 0:0:1:0: tag#0 Inserting command ffff989bd1de9148 into mlqueue
18:16:58 sd 0:0:1:0: unblocking device at zero depth
18:16:58 sd 0:0:1:0: tag#0 Send: scmd 0xffff989bd1de9148
18:16:58 sd 0:0:1:0: tag#0 CDB: Test Unit Ready 00 00 00 00 00 00
18:16:58 mpt2sas_cm0: log_info(0x31110101): originator(PL), code(0x11), sub_code(0x0101)
18:16:58 sd 0:0:1:0: tag#0 Done: NEEDS_RETRY Result: hostbyte=DID_SOFT_ERROR driverbyte=DRIVER_OK
18:16:58 sd 0:0:1:0: tag#0 CDB: Test Unit Ready 00 00 00 00 00 00
18:16:58 sd 0:0:1:0: tag#0 scsi host busy 1 failed 0
18:16:58 sd 0:0:1:0: tag#0 Inserting command ffff989bd1de9148 into mlqueue
18:16:58 sd 0:0:1:0: unblocking device at zero depth
18:16:58 sd 0:0:1:0: tag#0 Send: scmd 0xffff989bd1de9148
18:16:58 sd 0:0:1:0: tag#0 CDB: Test Unit Ready 00 00 00 00 00 00
18:16:58 mpt2sas_cm0: log_info(0x31110101): originator(PL), code(0x11), sub_code(0x0101)
18:16:58 sd 0:0:1:0: tag#0 Done: NEEDS_RETRY Result: hostbyte=DID_SOFT_ERROR driverbyte=DRIVER_OK
18:16:58 sd 0:0:1:0: tag#0 CDB: Test Unit Ready 00 00 00 00 00 00
18:16:58 sd 0:0:1:0: tag#0 scsi host busy 1 failed 0
18:16:58 sd 0:0:1:0: tag#0 Inserting command ffff989bd1de9148 into mlqueue
18:16:58 sd 0:0:1:0: unblocking device at zero depth
18:16:58 sd 0:0:1:0: tag#0 Send: scmd 0xffff989bd1de9148
18:16:58 sd 0:0:1:0: tag#0 CDB: Test Unit Ready 00 00 00 00 00 00
18:16:58 mpt2sas_cm0: log_info(0x31110101): originator(PL), code(0x11), sub_code(0x0101)
18:16:58 sd 0:0:1:0: tag#0 Done: NEEDS_RETRY Result: hostbyte=DID_SOFT_ERROR driverbyte=DRIVER_OK
18:16:58 sd 0:0:1:0: tag#0 CDB: Test Unit Ready 00 00 00 00 00 00
18:16:58 sd 0:0:1:0: tag#0 scsi host busy 1 failed 0
18:16:58 sd 0:0:1:0: tag#0 Inserting command ffff989bd1de9148 into mlqueue
18:16:58 sd 0:0:1:0: unblocking device at zero depth
18:16:58 sd 0:0:1:0: tag#0 Send: scmd 0xffff989bd1de9148
18:16:58 sd 0:0:1:0: tag#0 CDB: Test Unit Ready 00 00 00 00 00 00
18:16:58 mpt2sas_cm0: log_info(0x31110101): originator(PL), code(0x11), sub_code(0x0101)
18:16:58 sd 0:0:1:0: tag#0 Done: SUCCESS Result: hostbyte=DID_SOFT_ERROR driverbyte=DRIVER_OK
18:16:58 sd 0:0:1:0: tag#0 CDB: Test Unit Ready 00 00 00 00 00 00
18:16:58 sd 0:0:1:0: tag#0 scsi host busy 1 failed 0
18:16:58 sd 0:0:1:0: Notifying upper driver of completion (result b0000)
18:16:58 sd 0:0:1:0: device_block, handle(0x000a)
18:16:59 sd 0:0:1:0: device_unblock and setting to running, handle(0x000a)

O que eu acho especialmente preocupante é

18:16:53 sd 0:0:1:0: [sdb] tag#0 Done: TIMEOUT_ERROR Result: hostbyte=DID_OK driverbyte=DRIVER_OK

levando imediatamente a

18:16:53 sd 0:0:1:0: [sdb] tag#0 abort scheduled
18:16:53 sd 0:0:1:0: [sdb] tag#0 aborting command

Gostaria de saber onde esse tempo limite está definido e como alterá-lo.

Atualização 2017-10-13

Por depuração, encontrei os seguintes tempos limite em prática:

  • 7s
  • 15s
  • 20s
  • 90s (como definido em /sys/block/sd?/device/timeout )
  • 180s (parece ser o dobro da configuração anterior)

Tempos limite adicionais são definidos nas fontes do kernel:

./include/linux/blkdev.h :

#define BLK_DEFAULT_SG_TIMEOUT  (60 * HZ)
#define BLK_MIN_SG_TIMEOUT  (7 * HZ)

./include/scsi/scsi.h :

#define FORMAT_UNIT_TIMEOUT     (2 * 60 * 60 * HZ)
#define START_STOP_TIMEOUT      (60 * HZ)
#define MOVE_MEDIUM_TIMEOUT     (5 * 60 * HZ)
#define READ_ELEMENT_STATUS_TIMEOUT (5 * 60 * HZ)
#define READ_DEFECT_DATA_TIMEOUT    (60 * HZ )

Estes são aplicados em ./block/scsi_ioctl.c functions sg_scsi_ioctl(...) e blk_fill_sghdr_rq(...) .

Isso explica de onde vem o tempo limite curto de 7s ( BLK_MIN_SG_TIMEOUT ).

Os tempos limite dos 15s e 20s parecem vir de sg_io_hdr*->timeout em blk_fill_sghdr_rq(...) , mas não consigo descobrir onde foi definido anteriormente.

    
por Cobra_Fast 04.10.2017 / 06:18

0 respostas