| 2021-10-12 22:14:27 |
Mauricio Faria de Oliveira |
bug |
|
|
added bug |
| 2021-10-12 22:18:45 |
Mauricio Faria de Oliveira |
merge proposal linked |
|
https://code.launchpad.net/~mfo/ufw/+git/ufw/+merge/410091 |
|
| 2021-10-12 22:21:52 |
Mauricio Faria de Oliveira |
bug task added |
|
ufw (Ubuntu) |
|
| 2021-10-12 22:22:07 |
Mauricio Faria de Oliveira |
nominated for series |
|
Ubuntu Focal |
|
| 2021-10-12 22:22:07 |
Mauricio Faria de Oliveira |
bug task added |
|
ufw (Ubuntu Focal) |
|
| 2021-10-12 22:22:07 |
Mauricio Faria de Oliveira |
nominated for series |
|
Ubuntu Impish |
|
| 2021-10-12 22:22:07 |
Mauricio Faria de Oliveira |
bug task added |
|
ufw (Ubuntu Impish) |
|
| 2021-10-12 22:22:07 |
Mauricio Faria de Oliveira |
nominated for series |
|
Ubuntu Bionic |
|
| 2021-10-12 22:22:07 |
Mauricio Faria de Oliveira |
bug task added |
|
ufw (Ubuntu Bionic) |
|
| 2021-10-12 22:22:07 |
Mauricio Faria de Oliveira |
nominated for series |
|
Ubuntu Hirsute |
|
| 2021-10-12 22:22:07 |
Mauricio Faria de Oliveira |
bug task added |
|
ufw (Ubuntu Hirsute) |
|
| 2021-10-12 22:33:38 |
Mauricio Faria de Oliveira |
description |
[Impact]
A system with rootfs on iSCSI stops booting when ufw.service starts.
The kernel logs iSCSI command/reset timeout until I/O fails and the
root filesystem/journal break.
The issue is that ufw_start() sets the default policy _first_, then
adds rules _later_.
So, a default INPUT policy of DROP (default setting in ufw) prevents
further access to the root filesystem (blocks incoming iSCSI traffic)
thus any rules that could help are not loaded (nor anything else.)
[Fix]
The fix is to set default policy after loading rules in ufw_start().
That seems to be OK as `ip[6]tables-restore -n/--noflush` is used,
and per iptables source, that only sets the chain policy.
The comparison of `iptables -L` before/after shows no differences
(verified on a local rootfs); `run_tests.sh` has 0 skipped/errors.
------------------------
Functional tests summary
------------------------
Attempted: 22 (3339 individual tests)
Skipped: 0
Errors: 0
[ufw info]
# ufw --version
ufw 0.36
Copyright 2008-2015 Canonical Ltd.
# lsb_release -cs
focal
[Boot Log]
[ 232.168355] iBFT detected.
Begin: Running /scripts/init-premount ... done.
Begin: Mounting root file system ... Begin: Running /scripts/local-top ...
Setting up software interface enp45s0f0np0
...
[ 254.644505] Loading iSCSI transport class v2.0-870.
[ 254.714938] iscsi: registered transport (tcp)
[ 254.780129] scsi host12: iSCSI Initiator over TCP/IP
...
[ 255.433491] sd 12:0:0:1: [sda] 251658240 512-byte logical blocks: (129 GB/120 GiB)
...
[ 256.379550] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null)
...
[ 266.620860] systemd[1]: Starting Uncomplicated firewall...
Starting Uncomplicated firewall...
...
[ 298.491560] session1: iscsi_eh_cmd_timed_out scsi cmd 00000000310a6696 timedout
[ 298.580803] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 298.656262] session1: iscsi_eh_cmd_timed_out scsi cmd 0000000094ad9246 timedout
[ 298.745237] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 298.745270] session1: iscsi_eh_abort aborting sc 00000000310a6696
[ 298.899644] session1: iscsi_eh_abort aborting [sc 00000000310a6696 itt 0x13]
[ 298.985788] session1: iscsi_exec_task_mgmt_fn tmf set timeout
[ 302.075554] session1: iscsi_eh_cmd_timed_out scsi cmd 000000001a9458b5 timedout
[ 302.164786] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 314.107541] session1: iscsi_tmf_timedout tmf timedout
[ 314.169797] connection1:0: detected conn error (1021)
[ 314.232266] session1: iscsi_eh_abort abort failed [sc 00000000310a6696 itt 0x13]
[ 314.323531] session1: iscsi_eh_abort aborting sc 0000000094ad9246
[ 314.399640] session1: iscsi_eh_abort sc never reached iscsi layer or it completed.
[ 314.495578] session1: iscsi_eh_abort aborting sc 000000001a9458b5
[ 314.571554] session1: iscsi_eh_abort sc never reached iscsi layer or it completed.
[ 314.664050] session1: iscsi_eh_device_reset LU Reset [sc 00000000310a6696 lun 1]
[ 314.755773] session1: iscsi_eh_device_reset dev reset result = FAILED
[ 314.834736] session1: iscsi_eh_target_reset tgt Reset [sc 00000000310a6696 tgt <...>]
[ 314.954144] session1: iscsi_eh_target_reset tgt <...> reset result = FAILED
[ 315.063456] connection1:0: detected conn error (1021)
[ 315.125743] session1: iscsi_eh_session_reset wait for relogin
[ 398.843556] INFO: task systemd:1 blocked for more than 120 seconds.
...
[ 401.039006] INFO: task jbd2/sda1-8:2522 blocked for more than 123 seconds.
...
[ 402.483917] INFO: task iptables-restor:2648 blocked for more than 124 seconds.
...
[ 435.707549] session1: session recovery timed out after 120 secs
[ 435.780058] session1: iscsi_eh_session_reset failing session reset: Could not log back into <...> [age 0]
[ 435.920710] sd 12:0:0:1: Device offlined - not ready after error recovery
[ 436.003563] sd 12:0:0:1: [sda] tag#105 FAILED Result: hostbyte=DID_TRANSPORT_DISRUPTED driverbyte=DRIVER_OK cmd_age=169s
[ 436.015520] sd 12:0:0:1: rejecting I/O to offline device
[ 436.134354] sd 12:0:0:1: [sda] tag#105 CDB: Read(10) 28 00 00 05 8d d8 00 00 08 00
[ 436.198807] blk_update_request: I/O error, dev sda, sector 360816 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.198818] blk_update_request: I/O error, dev sda, sector 2324480 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
[ 436.198852] EXT4-fs warning (device sda1): htree_dirblock_to_tree:1004: inode #1398: lblock 0: comm systemd: error -5 reading directory block
[ 436.290259] blk_update_request: I/O error, dev sda, sector 363992 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.417093] Buffer I/O error on dev sda1, logical block 262144, lost sync page write
[ 436.417103] blk_update_request: I/O error, dev sda, sector 364040 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.417130] JBD2: Error -5 detected when updating journal superblock for sda1-8.
[ 436.417132] Aborting journal on device sda1-8. |
[Impact]
A system with rootfs on iSCSI stops booting when ufw.service starts.
The kernel logs iSCSI command/reset timeout until I/O fails and the
root filesystem/journal break.
The issue is that ufw_start() sets the default policy _first_, then
adds rules _later_.
So, a default INPUT policy of DROP (default setting in ufw) prevents
further access to the root filesystem (blocks incoming iSCSI traffic)
thus any rules that could help are not loaded (nor anything else.)
[Fix]
The fix is to set default policy after loading rules in ufw_start().
That seems to be OK as `ip[6]tables-restore -n/--noflush` is used,
and per iptables source, that only sets the chain policy.
This allows the system to boot due to the RELATED,ESTABLISHED rule,
that is introduced by before.rules in INPUT/ufw-before-input chain.
The comparison of `iptables -L` before/after shows no differences
(verified on a local rootfs); `run_tests.sh` has 0 skipped/errors.
------------------------
Functional tests summary
------------------------
Attempted: 22 (3339 individual tests)
Skipped: 0
Errors: 0
[ufw info]
# ufw --version
ufw 0.36
Copyright 2008-2015 Canonical Ltd.
# lsb_release -cs
focal
[Boot Log]
[ 232.168355] iBFT detected.
Begin: Running /scripts/init-premount ... done.
Begin: Mounting root file system ... Begin: Running /scripts/local-top ...
Setting up software interface enp45s0f0np0
...
[ 254.644505] Loading iSCSI transport class v2.0-870.
[ 254.714938] iscsi: registered transport (tcp)
[ 254.780129] scsi host12: iSCSI Initiator over TCP/IP
...
[ 255.433491] sd 12:0:0:1: [sda] 251658240 512-byte logical blocks: (129 GB/120 GiB)
...
[ 256.379550] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null)
...
[ 266.620860] systemd[1]: Starting Uncomplicated firewall...
Starting Uncomplicated firewall...
...
[ 298.491560] session1: iscsi_eh_cmd_timed_out scsi cmd 00000000310a6696 timedout
[ 298.580803] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 298.656262] session1: iscsi_eh_cmd_timed_out scsi cmd 0000000094ad9246 timedout
[ 298.745237] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 298.745270] session1: iscsi_eh_abort aborting sc 00000000310a6696
[ 298.899644] session1: iscsi_eh_abort aborting [sc 00000000310a6696 itt 0x13]
[ 298.985788] session1: iscsi_exec_task_mgmt_fn tmf set timeout
[ 302.075554] session1: iscsi_eh_cmd_timed_out scsi cmd 000000001a9458b5 timedout
[ 302.164786] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 314.107541] session1: iscsi_tmf_timedout tmf timedout
[ 314.169797] connection1:0: detected conn error (1021)
[ 314.232266] session1: iscsi_eh_abort abort failed [sc 00000000310a6696 itt 0x13]
[ 314.323531] session1: iscsi_eh_abort aborting sc 0000000094ad9246
[ 314.399640] session1: iscsi_eh_abort sc never reached iscsi layer or it completed.
[ 314.495578] session1: iscsi_eh_abort aborting sc 000000001a9458b5
[ 314.571554] session1: iscsi_eh_abort sc never reached iscsi layer or it completed.
[ 314.664050] session1: iscsi_eh_device_reset LU Reset [sc 00000000310a6696 lun 1]
[ 314.755773] session1: iscsi_eh_device_reset dev reset result = FAILED
[ 314.834736] session1: iscsi_eh_target_reset tgt Reset [sc 00000000310a6696 tgt <...>]
[ 314.954144] session1: iscsi_eh_target_reset tgt <...> reset result = FAILED
[ 315.063456] connection1:0: detected conn error (1021)
[ 315.125743] session1: iscsi_eh_session_reset wait for relogin
[ 398.843556] INFO: task systemd:1 blocked for more than 120 seconds.
...
[ 401.039006] INFO: task jbd2/sda1-8:2522 blocked for more than 123 seconds.
...
[ 402.483917] INFO: task iptables-restor:2648 blocked for more than 124 seconds.
...
[ 435.707549] session1: session recovery timed out after 120 secs
[ 435.780058] session1: iscsi_eh_session_reset failing session reset: Could not log back into <...> [age 0]
[ 435.920710] sd 12:0:0:1: Device offlined - not ready after error recovery
[ 436.003563] sd 12:0:0:1: [sda] tag#105 FAILED Result: hostbyte=DID_TRANSPORT_DISRUPTED driverbyte=DRIVER_OK cmd_age=169s
[ 436.015520] sd 12:0:0:1: rejecting I/O to offline device
[ 436.134354] sd 12:0:0:1: [sda] tag#105 CDB: Read(10) 28 00 00 05 8d d8 00 00 08 00
[ 436.198807] blk_update_request: I/O error, dev sda, sector 360816 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.198818] blk_update_request: I/O error, dev sda, sector 2324480 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
[ 436.198852] EXT4-fs warning (device sda1): htree_dirblock_to_tree:1004: inode #1398: lblock 0: comm systemd: error -5 reading directory block
[ 436.290259] blk_update_request: I/O error, dev sda, sector 363992 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.417093] Buffer I/O error on dev sda1, logical block 262144, lost sync page write
[ 436.417103] blk_update_request: I/O error, dev sda, sector 364040 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.417130] JBD2: Error -5 detected when updating journal superblock for sda1-8.
[ 436.417132] Aborting journal on device sda1-8. |
|
| 2021-10-13 17:22:45 |
Jamie Strandboge |
ufw: status |
New |
Fix Committed |
|
| 2021-10-13 18:58:29 |
Mauricio Faria de Oliveira |
merge proposal linked |
|
https://code.launchpad.net/~mfo/ufw/+git/ufw/+merge/410152 |
|
| 2021-10-23 19:45:12 |
Launchpad Janitor |
ufw (Ubuntu): status |
New |
Fix Released |
|
| 2021-10-25 17:30:57 |
Mauricio Faria de Oliveira |
ufw (Ubuntu Bionic): status |
New |
In Progress |
|
| 2021-10-25 17:30:58 |
Mauricio Faria de Oliveira |
ufw (Ubuntu Bionic): importance |
Undecided |
Medium |
|
| 2021-10-25 17:31:00 |
Mauricio Faria de Oliveira |
ufw (Ubuntu Bionic): assignee |
|
Mauricio Faria de Oliveira (mfo) |
|
| 2021-10-25 17:31:03 |
Mauricio Faria de Oliveira |
ufw (Ubuntu Focal): status |
New |
In Progress |
|
| 2021-10-25 17:31:07 |
Mauricio Faria de Oliveira |
ufw (Ubuntu Focal): importance |
Undecided |
Medium |
|
| 2021-10-25 17:31:09 |
Mauricio Faria de Oliveira |
ufw (Ubuntu Focal): assignee |
|
Mauricio Faria de Oliveira (mfo) |
|
| 2021-10-25 17:31:12 |
Mauricio Faria de Oliveira |
ufw (Ubuntu Hirsute): status |
New |
In Progress |
|
| 2021-10-25 17:31:14 |
Mauricio Faria de Oliveira |
ufw (Ubuntu Hirsute): importance |
Undecided |
Medium |
|
| 2021-10-25 17:31:16 |
Mauricio Faria de Oliveira |
ufw (Ubuntu Hirsute): assignee |
|
Mauricio Faria de Oliveira (mfo) |
|
| 2021-10-25 17:31:19 |
Mauricio Faria de Oliveira |
ufw (Ubuntu Impish): status |
New |
In Progress |
|
| 2021-10-25 17:31:21 |
Mauricio Faria de Oliveira |
ufw (Ubuntu Impish): importance |
Undecided |
Medium |
|
| 2021-10-25 17:31:24 |
Mauricio Faria de Oliveira |
ufw (Ubuntu Impish): assignee |
|
Mauricio Faria de Oliveira (mfo) |
|
| 2021-10-25 21:30:33 |
Mauricio Faria de Oliveira |
tags |
|
sts sts-sponsor-mfo |
|
| 2021-10-27 18:22:52 |
Mauricio Faria de Oliveira |
description |
[Impact]
A system with rootfs on iSCSI stops booting when ufw.service starts.
The kernel logs iSCSI command/reset timeout until I/O fails and the
root filesystem/journal break.
The issue is that ufw_start() sets the default policy _first_, then
adds rules _later_.
So, a default INPUT policy of DROP (default setting in ufw) prevents
further access to the root filesystem (blocks incoming iSCSI traffic)
thus any rules that could help are not loaded (nor anything else.)
[Fix]
The fix is to set default policy after loading rules in ufw_start().
That seems to be OK as `ip[6]tables-restore -n/--noflush` is used,
and per iptables source, that only sets the chain policy.
This allows the system to boot due to the RELATED,ESTABLISHED rule,
that is introduced by before.rules in INPUT/ufw-before-input chain.
The comparison of `iptables -L` before/after shows no differences
(verified on a local rootfs); `run_tests.sh` has 0 skipped/errors.
------------------------
Functional tests summary
------------------------
Attempted: 22 (3339 individual tests)
Skipped: 0
Errors: 0
[ufw info]
# ufw --version
ufw 0.36
Copyright 2008-2015 Canonical Ltd.
# lsb_release -cs
focal
[Boot Log]
[ 232.168355] iBFT detected.
Begin: Running /scripts/init-premount ... done.
Begin: Mounting root file system ... Begin: Running /scripts/local-top ...
Setting up software interface enp45s0f0np0
...
[ 254.644505] Loading iSCSI transport class v2.0-870.
[ 254.714938] iscsi: registered transport (tcp)
[ 254.780129] scsi host12: iSCSI Initiator over TCP/IP
...
[ 255.433491] sd 12:0:0:1: [sda] 251658240 512-byte logical blocks: (129 GB/120 GiB)
...
[ 256.379550] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null)
...
[ 266.620860] systemd[1]: Starting Uncomplicated firewall...
Starting Uncomplicated firewall...
...
[ 298.491560] session1: iscsi_eh_cmd_timed_out scsi cmd 00000000310a6696 timedout
[ 298.580803] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 298.656262] session1: iscsi_eh_cmd_timed_out scsi cmd 0000000094ad9246 timedout
[ 298.745237] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 298.745270] session1: iscsi_eh_abort aborting sc 00000000310a6696
[ 298.899644] session1: iscsi_eh_abort aborting [sc 00000000310a6696 itt 0x13]
[ 298.985788] session1: iscsi_exec_task_mgmt_fn tmf set timeout
[ 302.075554] session1: iscsi_eh_cmd_timed_out scsi cmd 000000001a9458b5 timedout
[ 302.164786] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 314.107541] session1: iscsi_tmf_timedout tmf timedout
[ 314.169797] connection1:0: detected conn error (1021)
[ 314.232266] session1: iscsi_eh_abort abort failed [sc 00000000310a6696 itt 0x13]
[ 314.323531] session1: iscsi_eh_abort aborting sc 0000000094ad9246
[ 314.399640] session1: iscsi_eh_abort sc never reached iscsi layer or it completed.
[ 314.495578] session1: iscsi_eh_abort aborting sc 000000001a9458b5
[ 314.571554] session1: iscsi_eh_abort sc never reached iscsi layer or it completed.
[ 314.664050] session1: iscsi_eh_device_reset LU Reset [sc 00000000310a6696 lun 1]
[ 314.755773] session1: iscsi_eh_device_reset dev reset result = FAILED
[ 314.834736] session1: iscsi_eh_target_reset tgt Reset [sc 00000000310a6696 tgt <...>]
[ 314.954144] session1: iscsi_eh_target_reset tgt <...> reset result = FAILED
[ 315.063456] connection1:0: detected conn error (1021)
[ 315.125743] session1: iscsi_eh_session_reset wait for relogin
[ 398.843556] INFO: task systemd:1 blocked for more than 120 seconds.
...
[ 401.039006] INFO: task jbd2/sda1-8:2522 blocked for more than 123 seconds.
...
[ 402.483917] INFO: task iptables-restor:2648 blocked for more than 124 seconds.
...
[ 435.707549] session1: session recovery timed out after 120 secs
[ 435.780058] session1: iscsi_eh_session_reset failing session reset: Could not log back into <...> [age 0]
[ 435.920710] sd 12:0:0:1: Device offlined - not ready after error recovery
[ 436.003563] sd 12:0:0:1: [sda] tag#105 FAILED Result: hostbyte=DID_TRANSPORT_DISRUPTED driverbyte=DRIVER_OK cmd_age=169s
[ 436.015520] sd 12:0:0:1: rejecting I/O to offline device
[ 436.134354] sd 12:0:0:1: [sda] tag#105 CDB: Read(10) 28 00 00 05 8d d8 00 00 08 00
[ 436.198807] blk_update_request: I/O error, dev sda, sector 360816 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.198818] blk_update_request: I/O error, dev sda, sector 2324480 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
[ 436.198852] EXT4-fs warning (device sda1): htree_dirblock_to_tree:1004: inode #1398: lblock 0: comm systemd: error -5 reading directory block
[ 436.290259] blk_update_request: I/O error, dev sda, sector 363992 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.417093] Buffer I/O error on dev sda1, logical block 262144, lost sync page write
[ 436.417103] blk_update_request: I/O error, dev sda, sector 364040 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.417130] JBD2: Error -5 detected when updating journal superblock for sda1-8.
[ 436.417132] Aborting journal on device sda1-8. |
[Impact]
A system with rootfs on iSCSI stops booting when ufw.service starts.
The kernel logs iSCSI command/reset timeout until I/O fails and the
root filesystem/journal break.
The issue is that ufw_start() sets the default policy _first_, then
adds rules _later_.
So, a default INPUT policy of DROP (default setting in ufw) prevents
further access to the root filesystem (blocks incoming iSCSI traffic)
thus any rules that could help are not loaded (nor anything else.)
[Fix]
The fix is to set default policy after loading rules in ufw_start().
That seems to be OK as `ip[6]tables-restore -n/--noflush` is used,
and per iptables source, that only sets the chain policy.
This allows the system to boot due to the RELATED,ESTABLISHED rule,
that is introduced by before.rules in INPUT/ufw-before-input chain.
The comparison of `iptables -L` before/after shows no differences
(verified on a local rootfs); `run_tests.sh` has 0 skipped/errors.
[Test Steps]
* Install Ubuntu on an iSCSI (or other network-based) root filesystem.
* sudo ufw enable
* sudo reboot
* Observed: system boot stalls once ufw.service starts (see below.)
* Expected: system boot should move on.
[Regression Potential]
* Potential regressions would be observed on ufw start/reload,
when iptables rules are configured.
* The resulting iptables configuration has been compared
before/after the change, with identical rules on both.
[ufw info]
# ufw --version
ufw 0.36
Copyright 2008-2015 Canonical Ltd.
# lsb_release -cs
focal
[Boot Log]
[ 232.168355] iBFT detected.
Begin: Running /scripts/init-premount ... done.
Begin: Mounting root file system ... Begin: Running /scripts/local-top ...
Setting up software interface enp45s0f0np0
...
[ 254.644505] Loading iSCSI transport class v2.0-870.
[ 254.714938] iscsi: registered transport (tcp)
[ 254.780129] scsi host12: iSCSI Initiator over TCP/IP
...
[ 255.433491] sd 12:0:0:1: [sda] 251658240 512-byte logical blocks: (129 GB/120 GiB)
...
[ 256.379550] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null)
...
[ 266.620860] systemd[1]: Starting Uncomplicated firewall...
Starting Uncomplicated firewall...
...
[ 298.491560] session1: iscsi_eh_cmd_timed_out scsi cmd 00000000310a6696 timedout
[ 298.580803] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 298.656262] session1: iscsi_eh_cmd_timed_out scsi cmd 0000000094ad9246 timedout
[ 298.745237] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 298.745270] session1: iscsi_eh_abort aborting sc 00000000310a6696
[ 298.899644] session1: iscsi_eh_abort aborting [sc 00000000310a6696 itt 0x13]
[ 298.985788] session1: iscsi_exec_task_mgmt_fn tmf set timeout
[ 302.075554] session1: iscsi_eh_cmd_timed_out scsi cmd 000000001a9458b5 timedout
[ 302.164786] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 314.107541] session1: iscsi_tmf_timedout tmf timedout
[ 314.169797] connection1:0: detected conn error (1021)
[ 314.232266] session1: iscsi_eh_abort abort failed [sc 00000000310a6696 itt 0x13]
[ 314.323531] session1: iscsi_eh_abort aborting sc 0000000094ad9246
[ 314.399640] session1: iscsi_eh_abort sc never reached iscsi layer or it completed.
[ 314.495578] session1: iscsi_eh_abort aborting sc 000000001a9458b5
[ 314.571554] session1: iscsi_eh_abort sc never reached iscsi layer or it completed.
[ 314.664050] session1: iscsi_eh_device_reset LU Reset [sc 00000000310a6696 lun 1]
[ 314.755773] session1: iscsi_eh_device_reset dev reset result = FAILED
[ 314.834736] session1: iscsi_eh_target_reset tgt Reset [sc 00000000310a6696 tgt <...>]
[ 314.954144] session1: iscsi_eh_target_reset tgt <...> reset result = FAILED
[ 315.063456] connection1:0: detected conn error (1021)
[ 315.125743] session1: iscsi_eh_session_reset wait for relogin
[ 398.843556] INFO: task systemd:1 blocked for more than 120 seconds.
...
[ 401.039006] INFO: task jbd2/sda1-8:2522 blocked for more than 123 seconds.
...
[ 402.483917] INFO: task iptables-restor:2648 blocked for more than 124 seconds.
...
[ 435.707549] session1: session recovery timed out after 120 secs
[ 435.780058] session1: iscsi_eh_session_reset failing session reset: Could not log back into <...> [age 0]
[ 435.920710] sd 12:0:0:1: Device offlined - not ready after error recovery
[ 436.003563] sd 12:0:0:1: [sda] tag#105 FAILED Result: hostbyte=DID_TRANSPORT_DISRUPTED driverbyte=DRIVER_OK cmd_age=169s
[ 436.015520] sd 12:0:0:1: rejecting I/O to offline device
[ 436.134354] sd 12:0:0:1: [sda] tag#105 CDB: Read(10) 28 00 00 05 8d d8 00 00 08 00
[ 436.198807] blk_update_request: I/O error, dev sda, sector 360816 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.198818] blk_update_request: I/O error, dev sda, sector 2324480 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
[ 436.198852] EXT4-fs warning (device sda1): htree_dirblock_to_tree:1004: inode #1398: lblock 0: comm systemd: error -5 reading directory block
[ 436.290259] blk_update_request: I/O error, dev sda, sector 363992 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.417093] Buffer I/O error on dev sda1, logical block 262144, lost sync page write
[ 436.417103] blk_update_request: I/O error, dev sda, sector 364040 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.417130] JBD2: Error -5 detected when updating journal superblock for sda1-8.
[ 436.417132] Aborting journal on device sda1-8. |
|
| 2021-10-27 18:23:33 |
Mauricio Faria de Oliveira |
description |
[Impact]
A system with rootfs on iSCSI stops booting when ufw.service starts.
The kernel logs iSCSI command/reset timeout until I/O fails and the
root filesystem/journal break.
The issue is that ufw_start() sets the default policy _first_, then
adds rules _later_.
So, a default INPUT policy of DROP (default setting in ufw) prevents
further access to the root filesystem (blocks incoming iSCSI traffic)
thus any rules that could help are not loaded (nor anything else.)
[Fix]
The fix is to set default policy after loading rules in ufw_start().
That seems to be OK as `ip[6]tables-restore -n/--noflush` is used,
and per iptables source, that only sets the chain policy.
This allows the system to boot due to the RELATED,ESTABLISHED rule,
that is introduced by before.rules in INPUT/ufw-before-input chain.
The comparison of `iptables -L` before/after shows no differences
(verified on a local rootfs); `run_tests.sh` has 0 skipped/errors.
[Test Steps]
* Install Ubuntu on an iSCSI (or other network-based) root filesystem.
* sudo ufw enable
* sudo reboot
* Observed: system boot stalls once ufw.service starts (see below.)
* Expected: system boot should move on.
[Regression Potential]
* Potential regressions would be observed on ufw start/reload,
when iptables rules are configured.
* The resulting iptables configuration has been compared
before/after the change, with identical rules on both.
[ufw info]
# ufw --version
ufw 0.36
Copyright 2008-2015 Canonical Ltd.
# lsb_release -cs
focal
[Boot Log]
[ 232.168355] iBFT detected.
Begin: Running /scripts/init-premount ... done.
Begin: Mounting root file system ... Begin: Running /scripts/local-top ...
Setting up software interface enp45s0f0np0
...
[ 254.644505] Loading iSCSI transport class v2.0-870.
[ 254.714938] iscsi: registered transport (tcp)
[ 254.780129] scsi host12: iSCSI Initiator over TCP/IP
...
[ 255.433491] sd 12:0:0:1: [sda] 251658240 512-byte logical blocks: (129 GB/120 GiB)
...
[ 256.379550] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null)
...
[ 266.620860] systemd[1]: Starting Uncomplicated firewall...
Starting Uncomplicated firewall...
...
[ 298.491560] session1: iscsi_eh_cmd_timed_out scsi cmd 00000000310a6696 timedout
[ 298.580803] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 298.656262] session1: iscsi_eh_cmd_timed_out scsi cmd 0000000094ad9246 timedout
[ 298.745237] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 298.745270] session1: iscsi_eh_abort aborting sc 00000000310a6696
[ 298.899644] session1: iscsi_eh_abort aborting [sc 00000000310a6696 itt 0x13]
[ 298.985788] session1: iscsi_exec_task_mgmt_fn tmf set timeout
[ 302.075554] session1: iscsi_eh_cmd_timed_out scsi cmd 000000001a9458b5 timedout
[ 302.164786] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 314.107541] session1: iscsi_tmf_timedout tmf timedout
[ 314.169797] connection1:0: detected conn error (1021)
[ 314.232266] session1: iscsi_eh_abort abort failed [sc 00000000310a6696 itt 0x13]
[ 314.323531] session1: iscsi_eh_abort aborting sc 0000000094ad9246
[ 314.399640] session1: iscsi_eh_abort sc never reached iscsi layer or it completed.
[ 314.495578] session1: iscsi_eh_abort aborting sc 000000001a9458b5
[ 314.571554] session1: iscsi_eh_abort sc never reached iscsi layer or it completed.
[ 314.664050] session1: iscsi_eh_device_reset LU Reset [sc 00000000310a6696 lun 1]
[ 314.755773] session1: iscsi_eh_device_reset dev reset result = FAILED
[ 314.834736] session1: iscsi_eh_target_reset tgt Reset [sc 00000000310a6696 tgt <...>]
[ 314.954144] session1: iscsi_eh_target_reset tgt <...> reset result = FAILED
[ 315.063456] connection1:0: detected conn error (1021)
[ 315.125743] session1: iscsi_eh_session_reset wait for relogin
[ 398.843556] INFO: task systemd:1 blocked for more than 120 seconds.
...
[ 401.039006] INFO: task jbd2/sda1-8:2522 blocked for more than 123 seconds.
...
[ 402.483917] INFO: task iptables-restor:2648 blocked for more than 124 seconds.
...
[ 435.707549] session1: session recovery timed out after 120 secs
[ 435.780058] session1: iscsi_eh_session_reset failing session reset: Could not log back into <...> [age 0]
[ 435.920710] sd 12:0:0:1: Device offlined - not ready after error recovery
[ 436.003563] sd 12:0:0:1: [sda] tag#105 FAILED Result: hostbyte=DID_TRANSPORT_DISRUPTED driverbyte=DRIVER_OK cmd_age=169s
[ 436.015520] sd 12:0:0:1: rejecting I/O to offline device
[ 436.134354] sd 12:0:0:1: [sda] tag#105 CDB: Read(10) 28 00 00 05 8d d8 00 00 08 00
[ 436.198807] blk_update_request: I/O error, dev sda, sector 360816 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.198818] blk_update_request: I/O error, dev sda, sector 2324480 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
[ 436.198852] EXT4-fs warning (device sda1): htree_dirblock_to_tree:1004: inode #1398: lblock 0: comm systemd: error -5 reading directory block
[ 436.290259] blk_update_request: I/O error, dev sda, sector 363992 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.417093] Buffer I/O error on dev sda1, logical block 262144, lost sync page write
[ 436.417103] blk_update_request: I/O error, dev sda, sector 364040 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.417130] JBD2: Error -5 detected when updating journal superblock for sda1-8.
[ 436.417132] Aborting journal on device sda1-8. |
[Impact]
A system with rootfs on iSCSI stops booting when ufw.service starts.
The kernel logs iSCSI command/reset timeout until I/O fails and the
root filesystem/journal break.
The issue is that ufw_start() sets the default policy _first_, then
adds rules _later_.
So, a default INPUT policy of DROP (default setting in ufw) prevents
further access to the root filesystem (blocks incoming iSCSI traffic)
thus any rules that could help are not loaded (nor anything else.)
[Fix]
The fix is to set default policy after loading rules in ufw_start().
That seems to be OK as `ip[6]tables-restore -n/--noflush` is used,
and per iptables source, that only sets the chain policy.
This allows the system to boot due to the RELATED,ESTABLISHED rule,
that is introduced by before.rules in INPUT/ufw-before-input chain.
The comparison of `iptables -L` before/after shows no differences
(verified on a local rootfs); `run_tests.sh` has 0 skipped/errors.
[Test Steps]
* Install Ubuntu on an iSCSI (or other network-based) root filesystem.
* sudo ufw enable
* sudo reboot
* Observed: system boot stalls once ufw.service starts (see below.)
* Expected: system boot should move on.
[Regression Potential]
* Potential regressions would be observed on ufw start/reload,
when iptables rules are configured.
* The resulting iptables configuration has been compared
before/after the change, with identical rules on both.
[Other Info]
* Fixed in Debian and Jammy.
[ufw info]
# ufw --version
ufw 0.36
Copyright 2008-2015 Canonical Ltd.
# lsb_release -cs
focal
[Boot Log]
[ 232.168355] iBFT detected.
Begin: Running /scripts/init-premount ... done.
Begin: Mounting root file system ... Begin: Running /scripts/local-top ...
Setting up software interface enp45s0f0np0
...
[ 254.644505] Loading iSCSI transport class v2.0-870.
[ 254.714938] iscsi: registered transport (tcp)
[ 254.780129] scsi host12: iSCSI Initiator over TCP/IP
...
[ 255.433491] sd 12:0:0:1: [sda] 251658240 512-byte logical blocks: (129 GB/120 GiB)
...
[ 256.379550] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null)
...
[ 266.620860] systemd[1]: Starting Uncomplicated firewall...
Starting Uncomplicated firewall...
...
[ 298.491560] session1: iscsi_eh_cmd_timed_out scsi cmd 00000000310a6696 timedout
[ 298.580803] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 298.656262] session1: iscsi_eh_cmd_timed_out scsi cmd 0000000094ad9246 timedout
[ 298.745237] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 298.745270] session1: iscsi_eh_abort aborting sc 00000000310a6696
[ 298.899644] session1: iscsi_eh_abort aborting [sc 00000000310a6696 itt 0x13]
[ 298.985788] session1: iscsi_exec_task_mgmt_fn tmf set timeout
[ 302.075554] session1: iscsi_eh_cmd_timed_out scsi cmd 000000001a9458b5 timedout
[ 302.164786] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 314.107541] session1: iscsi_tmf_timedout tmf timedout
[ 314.169797] connection1:0: detected conn error (1021)
[ 314.232266] session1: iscsi_eh_abort abort failed [sc 00000000310a6696 itt 0x13]
[ 314.323531] session1: iscsi_eh_abort aborting sc 0000000094ad9246
[ 314.399640] session1: iscsi_eh_abort sc never reached iscsi layer or it completed.
[ 314.495578] session1: iscsi_eh_abort aborting sc 000000001a9458b5
[ 314.571554] session1: iscsi_eh_abort sc never reached iscsi layer or it completed.
[ 314.664050] session1: iscsi_eh_device_reset LU Reset [sc 00000000310a6696 lun 1]
[ 314.755773] session1: iscsi_eh_device_reset dev reset result = FAILED
[ 314.834736] session1: iscsi_eh_target_reset tgt Reset [sc 00000000310a6696 tgt <...>]
[ 314.954144] session1: iscsi_eh_target_reset tgt <...> reset result = FAILED
[ 315.063456] connection1:0: detected conn error (1021)
[ 315.125743] session1: iscsi_eh_session_reset wait for relogin
[ 398.843556] INFO: task systemd:1 blocked for more than 120 seconds.
...
[ 401.039006] INFO: task jbd2/sda1-8:2522 blocked for more than 123 seconds.
...
[ 402.483917] INFO: task iptables-restor:2648 blocked for more than 124 seconds.
...
[ 435.707549] session1: session recovery timed out after 120 secs
[ 435.780058] session1: iscsi_eh_session_reset failing session reset: Could not log back into <...> [age 0]
[ 435.920710] sd 12:0:0:1: Device offlined - not ready after error recovery
[ 436.003563] sd 12:0:0:1: [sda] tag#105 FAILED Result: hostbyte=DID_TRANSPORT_DISRUPTED driverbyte=DRIVER_OK cmd_age=169s
[ 436.015520] sd 12:0:0:1: rejecting I/O to offline device
[ 436.134354] sd 12:0:0:1: [sda] tag#105 CDB: Read(10) 28 00 00 05 8d d8 00 00 08 00
[ 436.198807] blk_update_request: I/O error, dev sda, sector 360816 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.198818] blk_update_request: I/O error, dev sda, sector 2324480 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
[ 436.198852] EXT4-fs warning (device sda1): htree_dirblock_to_tree:1004: inode #1398: lblock 0: comm systemd: error -5 reading directory block
[ 436.290259] blk_update_request: I/O error, dev sda, sector 363992 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.417093] Buffer I/O error on dev sda1, logical block 262144, lost sync page write
[ 436.417103] blk_update_request: I/O error, dev sda, sector 364040 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.417130] JBD2: Error -5 detected when updating journal superblock for sda1-8.
[ 436.417132] Aborting journal on device sda1-8. |
|
| 2021-10-27 18:24:35 |
Mauricio Faria de Oliveira |
description |
[Impact]
A system with rootfs on iSCSI stops booting when ufw.service starts.
The kernel logs iSCSI command/reset timeout until I/O fails and the
root filesystem/journal break.
The issue is that ufw_start() sets the default policy _first_, then
adds rules _later_.
So, a default INPUT policy of DROP (default setting in ufw) prevents
further access to the root filesystem (blocks incoming iSCSI traffic)
thus any rules that could help are not loaded (nor anything else.)
[Fix]
The fix is to set default policy after loading rules in ufw_start().
That seems to be OK as `ip[6]tables-restore -n/--noflush` is used,
and per iptables source, that only sets the chain policy.
This allows the system to boot due to the RELATED,ESTABLISHED rule,
that is introduced by before.rules in INPUT/ufw-before-input chain.
The comparison of `iptables -L` before/after shows no differences
(verified on a local rootfs); `run_tests.sh` has 0 skipped/errors.
[Test Steps]
* Install Ubuntu on an iSCSI (or other network-based) root filesystem.
* sudo ufw enable
* sudo reboot
* Observed: system boot stalls once ufw.service starts (see below.)
* Expected: system boot should move on.
[Regression Potential]
* Potential regressions would be observed on ufw start/reload,
when iptables rules are configured.
* The resulting iptables configuration has been compared
before/after the change, with identical rules on both.
[Other Info]
* Fixed in Debian and Jammy.
[ufw info]
# ufw --version
ufw 0.36
Copyright 2008-2015 Canonical Ltd.
# lsb_release -cs
focal
[Boot Log]
[ 232.168355] iBFT detected.
Begin: Running /scripts/init-premount ... done.
Begin: Mounting root file system ... Begin: Running /scripts/local-top ...
Setting up software interface enp45s0f0np0
...
[ 254.644505] Loading iSCSI transport class v2.0-870.
[ 254.714938] iscsi: registered transport (tcp)
[ 254.780129] scsi host12: iSCSI Initiator over TCP/IP
...
[ 255.433491] sd 12:0:0:1: [sda] 251658240 512-byte logical blocks: (129 GB/120 GiB)
...
[ 256.379550] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null)
...
[ 266.620860] systemd[1]: Starting Uncomplicated firewall...
Starting Uncomplicated firewall...
...
[ 298.491560] session1: iscsi_eh_cmd_timed_out scsi cmd 00000000310a6696 timedout
[ 298.580803] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 298.656262] session1: iscsi_eh_cmd_timed_out scsi cmd 0000000094ad9246 timedout
[ 298.745237] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 298.745270] session1: iscsi_eh_abort aborting sc 00000000310a6696
[ 298.899644] session1: iscsi_eh_abort aborting [sc 00000000310a6696 itt 0x13]
[ 298.985788] session1: iscsi_exec_task_mgmt_fn tmf set timeout
[ 302.075554] session1: iscsi_eh_cmd_timed_out scsi cmd 000000001a9458b5 timedout
[ 302.164786] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 314.107541] session1: iscsi_tmf_timedout tmf timedout
[ 314.169797] connection1:0: detected conn error (1021)
[ 314.232266] session1: iscsi_eh_abort abort failed [sc 00000000310a6696 itt 0x13]
[ 314.323531] session1: iscsi_eh_abort aborting sc 0000000094ad9246
[ 314.399640] session1: iscsi_eh_abort sc never reached iscsi layer or it completed.
[ 314.495578] session1: iscsi_eh_abort aborting sc 000000001a9458b5
[ 314.571554] session1: iscsi_eh_abort sc never reached iscsi layer or it completed.
[ 314.664050] session1: iscsi_eh_device_reset LU Reset [sc 00000000310a6696 lun 1]
[ 314.755773] session1: iscsi_eh_device_reset dev reset result = FAILED
[ 314.834736] session1: iscsi_eh_target_reset tgt Reset [sc 00000000310a6696 tgt <...>]
[ 314.954144] session1: iscsi_eh_target_reset tgt <...> reset result = FAILED
[ 315.063456] connection1:0: detected conn error (1021)
[ 315.125743] session1: iscsi_eh_session_reset wait for relogin
[ 398.843556] INFO: task systemd:1 blocked for more than 120 seconds.
...
[ 401.039006] INFO: task jbd2/sda1-8:2522 blocked for more than 123 seconds.
...
[ 402.483917] INFO: task iptables-restor:2648 blocked for more than 124 seconds.
...
[ 435.707549] session1: session recovery timed out after 120 secs
[ 435.780058] session1: iscsi_eh_session_reset failing session reset: Could not log back into <...> [age 0]
[ 435.920710] sd 12:0:0:1: Device offlined - not ready after error recovery
[ 436.003563] sd 12:0:0:1: [sda] tag#105 FAILED Result: hostbyte=DID_TRANSPORT_DISRUPTED driverbyte=DRIVER_OK cmd_age=169s
[ 436.015520] sd 12:0:0:1: rejecting I/O to offline device
[ 436.134354] sd 12:0:0:1: [sda] tag#105 CDB: Read(10) 28 00 00 05 8d d8 00 00 08 00
[ 436.198807] blk_update_request: I/O error, dev sda, sector 360816 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.198818] blk_update_request: I/O error, dev sda, sector 2324480 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
[ 436.198852] EXT4-fs warning (device sda1): htree_dirblock_to_tree:1004: inode #1398: lblock 0: comm systemd: error -5 reading directory block
[ 436.290259] blk_update_request: I/O error, dev sda, sector 363992 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.417093] Buffer I/O error on dev sda1, logical block 262144, lost sync page write
[ 436.417103] blk_update_request: I/O error, dev sda, sector 364040 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.417130] JBD2: Error -5 detected when updating journal superblock for sda1-8.
[ 436.417132] Aborting journal on device sda1-8. |
[Impact]
A system with rootfs on iSCSI stops booting when ufw.service starts.
The kernel logs iSCSI command/reset timeout until I/O fails and the
root filesystem/journal break.
The issue is that ufw_start() sets the default policy _first_, then
adds rules _later_.
So, a default INPUT policy of DROP (default setting in ufw) prevents
further access to the root filesystem (blocks incoming iSCSI traffic)
thus any rules that could help are not loaded (nor anything else.)
[Fix]
The fix is to set default policy after loading rules in ufw_start().
That seems to be OK as `ip[6]tables-restore -n/--noflush` is used,
and per iptables source, that only sets the chain policy.
This allows the system to boot due to the RELATED,ESTABLISHED rule,
that is introduced by before.rules in INPUT/ufw-before-input chain.
The comparison of `iptables -L` before/after shows no differences
(verified on a local rootfs); `run_tests.sh` has 0 skipped/errors.
[Test Steps]
* Install Ubuntu on an iSCSI (or other network-based) root filesystem.
(e.g., Oracle Cloud's bare-metal 'BM.Standard1.36' shape.)
* sudo ufw enable
* sudo reboot
* Observed: system boot stalls once ufw.service starts (see below.)
* Expected: system boot should move on.
[Regression Potential]
* Potential regressions would be observed on ufw start/reload,
when iptables rules are configured.
* The resulting iptables configuration has been compared
before/after the change, with identical rules on both.
[Other Info]
* Fixed in Debian and Jammy.
[ufw info]
# ufw --version
ufw 0.36
Copyright 2008-2015 Canonical Ltd.
# lsb_release -cs
focal
[Boot Log]
[ 232.168355] iBFT detected.
Begin: Running /scripts/init-premount ... done.
Begin: Mounting root file system ... Begin: Running /scripts/local-top ...
Setting up software interface enp45s0f0np0
...
[ 254.644505] Loading iSCSI transport class v2.0-870.
[ 254.714938] iscsi: registered transport (tcp)
[ 254.780129] scsi host12: iSCSI Initiator over TCP/IP
...
[ 255.433491] sd 12:0:0:1: [sda] 251658240 512-byte logical blocks: (129 GB/120 GiB)
...
[ 256.379550] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null)
...
[ 266.620860] systemd[1]: Starting Uncomplicated firewall...
Starting Uncomplicated firewall...
...
[ 298.491560] session1: iscsi_eh_cmd_timed_out scsi cmd 00000000310a6696 timedout
[ 298.580803] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 298.656262] session1: iscsi_eh_cmd_timed_out scsi cmd 0000000094ad9246 timedout
[ 298.745237] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 298.745270] session1: iscsi_eh_abort aborting sc 00000000310a6696
[ 298.899644] session1: iscsi_eh_abort aborting [sc 00000000310a6696 itt 0x13]
[ 298.985788] session1: iscsi_exec_task_mgmt_fn tmf set timeout
[ 302.075554] session1: iscsi_eh_cmd_timed_out scsi cmd 000000001a9458b5 timedout
[ 302.164786] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 314.107541] session1: iscsi_tmf_timedout tmf timedout
[ 314.169797] connection1:0: detected conn error (1021)
[ 314.232266] session1: iscsi_eh_abort abort failed [sc 00000000310a6696 itt 0x13]
[ 314.323531] session1: iscsi_eh_abort aborting sc 0000000094ad9246
[ 314.399640] session1: iscsi_eh_abort sc never reached iscsi layer or it completed.
[ 314.495578] session1: iscsi_eh_abort aborting sc 000000001a9458b5
[ 314.571554] session1: iscsi_eh_abort sc never reached iscsi layer or it completed.
[ 314.664050] session1: iscsi_eh_device_reset LU Reset [sc 00000000310a6696 lun 1]
[ 314.755773] session1: iscsi_eh_device_reset dev reset result = FAILED
[ 314.834736] session1: iscsi_eh_target_reset tgt Reset [sc 00000000310a6696 tgt <...>]
[ 314.954144] session1: iscsi_eh_target_reset tgt <...> reset result = FAILED
[ 315.063456] connection1:0: detected conn error (1021)
[ 315.125743] session1: iscsi_eh_session_reset wait for relogin
[ 398.843556] INFO: task systemd:1 blocked for more than 120 seconds.
...
[ 401.039006] INFO: task jbd2/sda1-8:2522 blocked for more than 123 seconds.
...
[ 402.483917] INFO: task iptables-restor:2648 blocked for more than 124 seconds.
...
[ 435.707549] session1: session recovery timed out after 120 secs
[ 435.780058] session1: iscsi_eh_session_reset failing session reset: Could not log back into <...> [age 0]
[ 435.920710] sd 12:0:0:1: Device offlined - not ready after error recovery
[ 436.003563] sd 12:0:0:1: [sda] tag#105 FAILED Result: hostbyte=DID_TRANSPORT_DISRUPTED driverbyte=DRIVER_OK cmd_age=169s
[ 436.015520] sd 12:0:0:1: rejecting I/O to offline device
[ 436.134354] sd 12:0:0:1: [sda] tag#105 CDB: Read(10) 28 00 00 05 8d d8 00 00 08 00
[ 436.198807] blk_update_request: I/O error, dev sda, sector 360816 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.198818] blk_update_request: I/O error, dev sda, sector 2324480 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
[ 436.198852] EXT4-fs warning (device sda1): htree_dirblock_to_tree:1004: inode #1398: lblock 0: comm systemd: error -5 reading directory block
[ 436.290259] blk_update_request: I/O error, dev sda, sector 363992 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.417093] Buffer I/O error on dev sda1, logical block 262144, lost sync page write
[ 436.417103] blk_update_request: I/O error, dev sda, sector 364040 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.417130] JBD2: Error -5 detected when updating journal superblock for sda1-8.
[ 436.417132] Aborting journal on device sda1-8. |
|
| 2021-10-27 18:40:13 |
Mauricio Faria de Oliveira |
description |
[Impact]
A system with rootfs on iSCSI stops booting when ufw.service starts.
The kernel logs iSCSI command/reset timeout until I/O fails and the
root filesystem/journal break.
The issue is that ufw_start() sets the default policy _first_, then
adds rules _later_.
So, a default INPUT policy of DROP (default setting in ufw) prevents
further access to the root filesystem (blocks incoming iSCSI traffic)
thus any rules that could help are not loaded (nor anything else.)
[Fix]
The fix is to set default policy after loading rules in ufw_start().
That seems to be OK as `ip[6]tables-restore -n/--noflush` is used,
and per iptables source, that only sets the chain policy.
This allows the system to boot due to the RELATED,ESTABLISHED rule,
that is introduced by before.rules in INPUT/ufw-before-input chain.
The comparison of `iptables -L` before/after shows no differences
(verified on a local rootfs); `run_tests.sh` has 0 skipped/errors.
[Test Steps]
* Install Ubuntu on an iSCSI (or other network-based) root filesystem.
(e.g., Oracle Cloud's bare-metal 'BM.Standard1.36' shape.)
* sudo ufw enable
* sudo reboot
* Observed: system boot stalls once ufw.service starts (see below.)
* Expected: system boot should move on.
[Regression Potential]
* Potential regressions would be observed on ufw start/reload,
when iptables rules are configured.
* The resulting iptables configuration has been compared
before/after the change, with identical rules on both.
[Other Info]
* Fixed in Debian and Jammy.
[ufw info]
# ufw --version
ufw 0.36
Copyright 2008-2015 Canonical Ltd.
# lsb_release -cs
focal
[Boot Log]
[ 232.168355] iBFT detected.
Begin: Running /scripts/init-premount ... done.
Begin: Mounting root file system ... Begin: Running /scripts/local-top ...
Setting up software interface enp45s0f0np0
...
[ 254.644505] Loading iSCSI transport class v2.0-870.
[ 254.714938] iscsi: registered transport (tcp)
[ 254.780129] scsi host12: iSCSI Initiator over TCP/IP
...
[ 255.433491] sd 12:0:0:1: [sda] 251658240 512-byte logical blocks: (129 GB/120 GiB)
...
[ 256.379550] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null)
...
[ 266.620860] systemd[1]: Starting Uncomplicated firewall...
Starting Uncomplicated firewall...
...
[ 298.491560] session1: iscsi_eh_cmd_timed_out scsi cmd 00000000310a6696 timedout
[ 298.580803] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 298.656262] session1: iscsi_eh_cmd_timed_out scsi cmd 0000000094ad9246 timedout
[ 298.745237] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 298.745270] session1: iscsi_eh_abort aborting sc 00000000310a6696
[ 298.899644] session1: iscsi_eh_abort aborting [sc 00000000310a6696 itt 0x13]
[ 298.985788] session1: iscsi_exec_task_mgmt_fn tmf set timeout
[ 302.075554] session1: iscsi_eh_cmd_timed_out scsi cmd 000000001a9458b5 timedout
[ 302.164786] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 314.107541] session1: iscsi_tmf_timedout tmf timedout
[ 314.169797] connection1:0: detected conn error (1021)
[ 314.232266] session1: iscsi_eh_abort abort failed [sc 00000000310a6696 itt 0x13]
[ 314.323531] session1: iscsi_eh_abort aborting sc 0000000094ad9246
[ 314.399640] session1: iscsi_eh_abort sc never reached iscsi layer or it completed.
[ 314.495578] session1: iscsi_eh_abort aborting sc 000000001a9458b5
[ 314.571554] session1: iscsi_eh_abort sc never reached iscsi layer or it completed.
[ 314.664050] session1: iscsi_eh_device_reset LU Reset [sc 00000000310a6696 lun 1]
[ 314.755773] session1: iscsi_eh_device_reset dev reset result = FAILED
[ 314.834736] session1: iscsi_eh_target_reset tgt Reset [sc 00000000310a6696 tgt <...>]
[ 314.954144] session1: iscsi_eh_target_reset tgt <...> reset result = FAILED
[ 315.063456] connection1:0: detected conn error (1021)
[ 315.125743] session1: iscsi_eh_session_reset wait for relogin
[ 398.843556] INFO: task systemd:1 blocked for more than 120 seconds.
...
[ 401.039006] INFO: task jbd2/sda1-8:2522 blocked for more than 123 seconds.
...
[ 402.483917] INFO: task iptables-restor:2648 blocked for more than 124 seconds.
...
[ 435.707549] session1: session recovery timed out after 120 secs
[ 435.780058] session1: iscsi_eh_session_reset failing session reset: Could not log back into <...> [age 0]
[ 435.920710] sd 12:0:0:1: Device offlined - not ready after error recovery
[ 436.003563] sd 12:0:0:1: [sda] tag#105 FAILED Result: hostbyte=DID_TRANSPORT_DISRUPTED driverbyte=DRIVER_OK cmd_age=169s
[ 436.015520] sd 12:0:0:1: rejecting I/O to offline device
[ 436.134354] sd 12:0:0:1: [sda] tag#105 CDB: Read(10) 28 00 00 05 8d d8 00 00 08 00
[ 436.198807] blk_update_request: I/O error, dev sda, sector 360816 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.198818] blk_update_request: I/O error, dev sda, sector 2324480 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
[ 436.198852] EXT4-fs warning (device sda1): htree_dirblock_to_tree:1004: inode #1398: lblock 0: comm systemd: error -5 reading directory block
[ 436.290259] blk_update_request: I/O error, dev sda, sector 363992 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.417093] Buffer I/O error on dev sda1, logical block 262144, lost sync page write
[ 436.417103] blk_update_request: I/O error, dev sda, sector 364040 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.417130] JBD2: Error -5 detected when updating journal superblock for sda1-8.
[ 436.417132] Aborting journal on device sda1-8. |
[Impact]
A system with rootfs on iSCSI stops booting when ufw.service starts.
The kernel logs iSCSI command/reset timeout until I/O fails and the
root filesystem/journal break.
The issue is that ufw_start() sets the default policy _first_, then
adds rules _later_.
So, a default INPUT policy of DROP (default setting in ufw) prevents
further access to the root filesystem (blocks incoming iSCSI traffic)
thus any rules that could help are not loaded (nor anything else.)
[Fix]
The fix is to set default policy after loading rules in ufw_start().
That seems to be OK as `ip[6]tables-restore -n/--noflush` is used,
and per iptables source, that only sets the chain policy.
This allows the system to boot due to the RELATED,ESTABLISHED rule,
that is introduced by before.rules in INPUT/ufw-before-input chain.
The comparison of `iptables -L` before/after shows no differences
(verified on a local rootfs); `run_tests.sh` has 0 skipped/errors.
[Test Steps]
* Install Ubuntu on an iSCSI (or other network-based) root filesystem.
(e.g., Oracle Cloud's bare-metal 'BM.Standard1.36' shape.)
* sudo ufw enable
* Observed: system may stall immediately if no prior iptables rules.
* Expected: system continues working.
* sudo reboot
* Observed: system boot stalls once ufw.service starts (see below.)
* Expected: system boot should move on.
[Regression Potential]
* Potential regressions would be observed on ufw start/reload,
when iptables rules are configured.
* The resulting iptables configuration has been compared
before/after the change, with identical rules on both.
[Other Info]
* Fixed in Debian and Jammy.
[ufw info]
# ufw --version
ufw 0.36
Copyright 2008-2015 Canonical Ltd.
# lsb_release -cs
focal
[Boot Log]
[ 232.168355] iBFT detected.
Begin: Running /scripts/init-premount ... done.
Begin: Mounting root file system ... Begin: Running /scripts/local-top ...
Setting up software interface enp45s0f0np0
...
[ 254.644505] Loading iSCSI transport class v2.0-870.
[ 254.714938] iscsi: registered transport (tcp)
[ 254.780129] scsi host12: iSCSI Initiator over TCP/IP
...
[ 255.433491] sd 12:0:0:1: [sda] 251658240 512-byte logical blocks: (129 GB/120 GiB)
...
[ 256.379550] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null)
...
[ 266.620860] systemd[1]: Starting Uncomplicated firewall...
Starting Uncomplicated firewall...
...
[ 298.491560] session1: iscsi_eh_cmd_timed_out scsi cmd 00000000310a6696 timedout
[ 298.580803] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 298.656262] session1: iscsi_eh_cmd_timed_out scsi cmd 0000000094ad9246 timedout
[ 298.745237] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 298.745270] session1: iscsi_eh_abort aborting sc 00000000310a6696
[ 298.899644] session1: iscsi_eh_abort aborting [sc 00000000310a6696 itt 0x13]
[ 298.985788] session1: iscsi_exec_task_mgmt_fn tmf set timeout
[ 302.075554] session1: iscsi_eh_cmd_timed_out scsi cmd 000000001a9458b5 timedout
[ 302.164786] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 314.107541] session1: iscsi_tmf_timedout tmf timedout
[ 314.169797] connection1:0: detected conn error (1021)
[ 314.232266] session1: iscsi_eh_abort abort failed [sc 00000000310a6696 itt 0x13]
[ 314.323531] session1: iscsi_eh_abort aborting sc 0000000094ad9246
[ 314.399640] session1: iscsi_eh_abort sc never reached iscsi layer or it completed.
[ 314.495578] session1: iscsi_eh_abort aborting sc 000000001a9458b5
[ 314.571554] session1: iscsi_eh_abort sc never reached iscsi layer or it completed.
[ 314.664050] session1: iscsi_eh_device_reset LU Reset [sc 00000000310a6696 lun 1]
[ 314.755773] session1: iscsi_eh_device_reset dev reset result = FAILED
[ 314.834736] session1: iscsi_eh_target_reset tgt Reset [sc 00000000310a6696 tgt <...>]
[ 314.954144] session1: iscsi_eh_target_reset tgt <...> reset result = FAILED
[ 315.063456] connection1:0: detected conn error (1021)
[ 315.125743] session1: iscsi_eh_session_reset wait for relogin
[ 398.843556] INFO: task systemd:1 blocked for more than 120 seconds.
...
[ 401.039006] INFO: task jbd2/sda1-8:2522 blocked for more than 123 seconds.
...
[ 402.483917] INFO: task iptables-restor:2648 blocked for more than 124 seconds.
...
[ 435.707549] session1: session recovery timed out after 120 secs
[ 435.780058] session1: iscsi_eh_session_reset failing session reset: Could not log back into <...> [age 0]
[ 435.920710] sd 12:0:0:1: Device offlined - not ready after error recovery
[ 436.003563] sd 12:0:0:1: [sda] tag#105 FAILED Result: hostbyte=DID_TRANSPORT_DISRUPTED driverbyte=DRIVER_OK cmd_age=169s
[ 436.015520] sd 12:0:0:1: rejecting I/O to offline device
[ 436.134354] sd 12:0:0:1: [sda] tag#105 CDB: Read(10) 28 00 00 05 8d d8 00 00 08 00
[ 436.198807] blk_update_request: I/O error, dev sda, sector 360816 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.198818] blk_update_request: I/O error, dev sda, sector 2324480 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
[ 436.198852] EXT4-fs warning (device sda1): htree_dirblock_to_tree:1004: inode #1398: lblock 0: comm systemd: error -5 reading directory block
[ 436.290259] blk_update_request: I/O error, dev sda, sector 363992 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.417093] Buffer I/O error on dev sda1, logical block 262144, lost sync page write
[ 436.417103] blk_update_request: I/O error, dev sda, sector 364040 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.417130] JBD2: Error -5 detected when updating journal superblock for sda1-8.
[ 436.417132] Aborting journal on device sda1-8. |
|
| 2021-10-27 18:43:01 |
Mauricio Faria de Oliveira |
description |
[Impact]
A system with rootfs on iSCSI stops booting when ufw.service starts.
The kernel logs iSCSI command/reset timeout until I/O fails and the
root filesystem/journal break.
The issue is that ufw_start() sets the default policy _first_, then
adds rules _later_.
So, a default INPUT policy of DROP (default setting in ufw) prevents
further access to the root filesystem (blocks incoming iSCSI traffic)
thus any rules that could help are not loaded (nor anything else.)
[Fix]
The fix is to set default policy after loading rules in ufw_start().
That seems to be OK as `ip[6]tables-restore -n/--noflush` is used,
and per iptables source, that only sets the chain policy.
This allows the system to boot due to the RELATED,ESTABLISHED rule,
that is introduced by before.rules in INPUT/ufw-before-input chain.
The comparison of `iptables -L` before/after shows no differences
(verified on a local rootfs); `run_tests.sh` has 0 skipped/errors.
[Test Steps]
* Install Ubuntu on an iSCSI (or other network-based) root filesystem.
(e.g., Oracle Cloud's bare-metal 'BM.Standard1.36' shape.)
* sudo ufw enable
* Observed: system may stall immediately if no prior iptables rules.
* Expected: system continues working.
* sudo reboot
* Observed: system boot stalls once ufw.service starts (see below.)
* Expected: system boot should move on.
[Regression Potential]
* Potential regressions would be observed on ufw start/reload,
when iptables rules are configured.
* The resulting iptables configuration has been compared
before/after the change, with identical rules on both.
[Other Info]
* Fixed in Debian and Jammy.
[ufw info]
# ufw --version
ufw 0.36
Copyright 2008-2015 Canonical Ltd.
# lsb_release -cs
focal
[Boot Log]
[ 232.168355] iBFT detected.
Begin: Running /scripts/init-premount ... done.
Begin: Mounting root file system ... Begin: Running /scripts/local-top ...
Setting up software interface enp45s0f0np0
...
[ 254.644505] Loading iSCSI transport class v2.0-870.
[ 254.714938] iscsi: registered transport (tcp)
[ 254.780129] scsi host12: iSCSI Initiator over TCP/IP
...
[ 255.433491] sd 12:0:0:1: [sda] 251658240 512-byte logical blocks: (129 GB/120 GiB)
...
[ 256.379550] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null)
...
[ 266.620860] systemd[1]: Starting Uncomplicated firewall...
Starting Uncomplicated firewall...
...
[ 298.491560] session1: iscsi_eh_cmd_timed_out scsi cmd 00000000310a6696 timedout
[ 298.580803] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 298.656262] session1: iscsi_eh_cmd_timed_out scsi cmd 0000000094ad9246 timedout
[ 298.745237] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 298.745270] session1: iscsi_eh_abort aborting sc 00000000310a6696
[ 298.899644] session1: iscsi_eh_abort aborting [sc 00000000310a6696 itt 0x13]
[ 298.985788] session1: iscsi_exec_task_mgmt_fn tmf set timeout
[ 302.075554] session1: iscsi_eh_cmd_timed_out scsi cmd 000000001a9458b5 timedout
[ 302.164786] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 314.107541] session1: iscsi_tmf_timedout tmf timedout
[ 314.169797] connection1:0: detected conn error (1021)
[ 314.232266] session1: iscsi_eh_abort abort failed [sc 00000000310a6696 itt 0x13]
[ 314.323531] session1: iscsi_eh_abort aborting sc 0000000094ad9246
[ 314.399640] session1: iscsi_eh_abort sc never reached iscsi layer or it completed.
[ 314.495578] session1: iscsi_eh_abort aborting sc 000000001a9458b5
[ 314.571554] session1: iscsi_eh_abort sc never reached iscsi layer or it completed.
[ 314.664050] session1: iscsi_eh_device_reset LU Reset [sc 00000000310a6696 lun 1]
[ 314.755773] session1: iscsi_eh_device_reset dev reset result = FAILED
[ 314.834736] session1: iscsi_eh_target_reset tgt Reset [sc 00000000310a6696 tgt <...>]
[ 314.954144] session1: iscsi_eh_target_reset tgt <...> reset result = FAILED
[ 315.063456] connection1:0: detected conn error (1021)
[ 315.125743] session1: iscsi_eh_session_reset wait for relogin
[ 398.843556] INFO: task systemd:1 blocked for more than 120 seconds.
...
[ 401.039006] INFO: task jbd2/sda1-8:2522 blocked for more than 123 seconds.
...
[ 402.483917] INFO: task iptables-restor:2648 blocked for more than 124 seconds.
...
[ 435.707549] session1: session recovery timed out after 120 secs
[ 435.780058] session1: iscsi_eh_session_reset failing session reset: Could not log back into <...> [age 0]
[ 435.920710] sd 12:0:0:1: Device offlined - not ready after error recovery
[ 436.003563] sd 12:0:0:1: [sda] tag#105 FAILED Result: hostbyte=DID_TRANSPORT_DISRUPTED driverbyte=DRIVER_OK cmd_age=169s
[ 436.015520] sd 12:0:0:1: rejecting I/O to offline device
[ 436.134354] sd 12:0:0:1: [sda] tag#105 CDB: Read(10) 28 00 00 05 8d d8 00 00 08 00
[ 436.198807] blk_update_request: I/O error, dev sda, sector 360816 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.198818] blk_update_request: I/O error, dev sda, sector 2324480 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
[ 436.198852] EXT4-fs warning (device sda1): htree_dirblock_to_tree:1004: inode #1398: lblock 0: comm systemd: error -5 reading directory block
[ 436.290259] blk_update_request: I/O error, dev sda, sector 363992 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.417093] Buffer I/O error on dev sda1, logical block 262144, lost sync page write
[ 436.417103] blk_update_request: I/O error, dev sda, sector 364040 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.417130] JBD2: Error -5 detected when updating journal superblock for sda1-8.
[ 436.417132] Aborting journal on device sda1-8. |
[Impact]
A system with rootfs on iSCSI stops booting when ufw.service starts.
The kernel logs iSCSI command/reset timeout until I/O fails and the
root filesystem/journal break.
The issue is that ufw_start() sets the default policy _first_, then
adds rules _later_.
So, a default INPUT policy of DROP (default setting in ufw) prevents
further access to the root filesystem (blocks incoming iSCSI traffic)
thus any rules that could help are not loaded (nor anything else.)
[Fix]
The fix is to set default policy after loading rules in ufw_start().
That seems to be OK as `ip[6]tables-restore -n/--noflush` is used,
and per iptables source, that only sets the chain policy.
This allows the system to boot due to the RELATED,ESTABLISHED rule,
that is introduced by before.rules in INPUT/ufw-before-input chain.
The comparison of `iptables -L` before/after shows no differences
(verified on a local rootfs); `run_tests.sh` has 0 skipped/errors.
[Test Steps]
* Install Ubuntu on an iSCSI (or other network-based) root filesystem.
(e.g., Oracle Cloud's bare-metal 'BM.Standard1.36' shape.)
* sudo ufw enable
* Observed: system may stall immediately if no prior iptables rules.
(eg, iptables -A INPUT -p tcp -s 169.254.0.2 --sport 3260 -j ACCEPT)
* Expected: system continues working.
* sudo reboot
* Observed: system boot stalls once ufw.service starts (see below.)
* Expected: system boot should move on.
[Regression Potential]
* Potential regressions would be observed on ufw start/reload,
when iptables rules are configured.
* The resulting iptables configuration has been compared
before/after the change, with identical rules on both.
[Other Info]
* Fixed in Debian and Jammy.
[ufw info]
# ufw --version
ufw 0.36
Copyright 2008-2015 Canonical Ltd.
# lsb_release -cs
focal
[Boot Log]
[ 232.168355] iBFT detected.
Begin: Running /scripts/init-premount ... done.
Begin: Mounting root file system ... Begin: Running /scripts/local-top ...
Setting up software interface enp45s0f0np0
...
[ 254.644505] Loading iSCSI transport class v2.0-870.
[ 254.714938] iscsi: registered transport (tcp)
[ 254.780129] scsi host12: iSCSI Initiator over TCP/IP
...
[ 255.433491] sd 12:0:0:1: [sda] 251658240 512-byte logical blocks: (129 GB/120 GiB)
...
[ 256.379550] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null)
...
[ 266.620860] systemd[1]: Starting Uncomplicated firewall...
Starting Uncomplicated firewall...
...
[ 298.491560] session1: iscsi_eh_cmd_timed_out scsi cmd 00000000310a6696 timedout
[ 298.580803] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 298.656262] session1: iscsi_eh_cmd_timed_out scsi cmd 0000000094ad9246 timedout
[ 298.745237] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 298.745270] session1: iscsi_eh_abort aborting sc 00000000310a6696
[ 298.899644] session1: iscsi_eh_abort aborting [sc 00000000310a6696 itt 0x13]
[ 298.985788] session1: iscsi_exec_task_mgmt_fn tmf set timeout
[ 302.075554] session1: iscsi_eh_cmd_timed_out scsi cmd 000000001a9458b5 timedout
[ 302.164786] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 314.107541] session1: iscsi_tmf_timedout tmf timedout
[ 314.169797] connection1:0: detected conn error (1021)
[ 314.232266] session1: iscsi_eh_abort abort failed [sc 00000000310a6696 itt 0x13]
[ 314.323531] session1: iscsi_eh_abort aborting sc 0000000094ad9246
[ 314.399640] session1: iscsi_eh_abort sc never reached iscsi layer or it completed.
[ 314.495578] session1: iscsi_eh_abort aborting sc 000000001a9458b5
[ 314.571554] session1: iscsi_eh_abort sc never reached iscsi layer or it completed.
[ 314.664050] session1: iscsi_eh_device_reset LU Reset [sc 00000000310a6696 lun 1]
[ 314.755773] session1: iscsi_eh_device_reset dev reset result = FAILED
[ 314.834736] session1: iscsi_eh_target_reset tgt Reset [sc 00000000310a6696 tgt <...>]
[ 314.954144] session1: iscsi_eh_target_reset tgt <...> reset result = FAILED
[ 315.063456] connection1:0: detected conn error (1021)
[ 315.125743] session1: iscsi_eh_session_reset wait for relogin
[ 398.843556] INFO: task systemd:1 blocked for more than 120 seconds.
...
[ 401.039006] INFO: task jbd2/sda1-8:2522 blocked for more than 123 seconds.
...
[ 402.483917] INFO: task iptables-restor:2648 blocked for more than 124 seconds.
...
[ 435.707549] session1: session recovery timed out after 120 secs
[ 435.780058] session1: iscsi_eh_session_reset failing session reset: Could not log back into <...> [age 0]
[ 435.920710] sd 12:0:0:1: Device offlined - not ready after error recovery
[ 436.003563] sd 12:0:0:1: [sda] tag#105 FAILED Result: hostbyte=DID_TRANSPORT_DISRUPTED driverbyte=DRIVER_OK cmd_age=169s
[ 436.015520] sd 12:0:0:1: rejecting I/O to offline device
[ 436.134354] sd 12:0:0:1: [sda] tag#105 CDB: Read(10) 28 00 00 05 8d d8 00 00 08 00
[ 436.198807] blk_update_request: I/O error, dev sda, sector 360816 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.198818] blk_update_request: I/O error, dev sda, sector 2324480 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
[ 436.198852] EXT4-fs warning (device sda1): htree_dirblock_to_tree:1004: inode #1398: lblock 0: comm systemd: error -5 reading directory block
[ 436.290259] blk_update_request: I/O error, dev sda, sector 363992 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.417093] Buffer I/O error on dev sda1, logical block 262144, lost sync page write
[ 436.417103] blk_update_request: I/O error, dev sda, sector 364040 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.417130] JBD2: Error -5 detected when updating journal superblock for sda1-8.
[ 436.417132] Aborting journal on device sda1-8. |
|
| 2021-10-27 18:43:15 |
Mauricio Faria de Oliveira |
description |
[Impact]
A system with rootfs on iSCSI stops booting when ufw.service starts.
The kernel logs iSCSI command/reset timeout until I/O fails and the
root filesystem/journal break.
The issue is that ufw_start() sets the default policy _first_, then
adds rules _later_.
So, a default INPUT policy of DROP (default setting in ufw) prevents
further access to the root filesystem (blocks incoming iSCSI traffic)
thus any rules that could help are not loaded (nor anything else.)
[Fix]
The fix is to set default policy after loading rules in ufw_start().
That seems to be OK as `ip[6]tables-restore -n/--noflush` is used,
and per iptables source, that only sets the chain policy.
This allows the system to boot due to the RELATED,ESTABLISHED rule,
that is introduced by before.rules in INPUT/ufw-before-input chain.
The comparison of `iptables -L` before/after shows no differences
(verified on a local rootfs); `run_tests.sh` has 0 skipped/errors.
[Test Steps]
* Install Ubuntu on an iSCSI (or other network-based) root filesystem.
(e.g., Oracle Cloud's bare-metal 'BM.Standard1.36' shape.)
* sudo ufw enable
* Observed: system may stall immediately if no prior iptables rules.
(eg, iptables -A INPUT -p tcp -s 169.254.0.2 --sport 3260 -j ACCEPT)
* Expected: system continues working.
* sudo reboot
* Observed: system boot stalls once ufw.service starts (see below.)
* Expected: system boot should move on.
[Regression Potential]
* Potential regressions would be observed on ufw start/reload,
when iptables rules are configured.
* The resulting iptables configuration has been compared
before/after the change, with identical rules on both.
[Other Info]
* Fixed in Debian and Jammy.
[ufw info]
# ufw --version
ufw 0.36
Copyright 2008-2015 Canonical Ltd.
# lsb_release -cs
focal
[Boot Log]
[ 232.168355] iBFT detected.
Begin: Running /scripts/init-premount ... done.
Begin: Mounting root file system ... Begin: Running /scripts/local-top ...
Setting up software interface enp45s0f0np0
...
[ 254.644505] Loading iSCSI transport class v2.0-870.
[ 254.714938] iscsi: registered transport (tcp)
[ 254.780129] scsi host12: iSCSI Initiator over TCP/IP
...
[ 255.433491] sd 12:0:0:1: [sda] 251658240 512-byte logical blocks: (129 GB/120 GiB)
...
[ 256.379550] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null)
...
[ 266.620860] systemd[1]: Starting Uncomplicated firewall...
Starting Uncomplicated firewall...
...
[ 298.491560] session1: iscsi_eh_cmd_timed_out scsi cmd 00000000310a6696 timedout
[ 298.580803] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 298.656262] session1: iscsi_eh_cmd_timed_out scsi cmd 0000000094ad9246 timedout
[ 298.745237] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 298.745270] session1: iscsi_eh_abort aborting sc 00000000310a6696
[ 298.899644] session1: iscsi_eh_abort aborting [sc 00000000310a6696 itt 0x13]
[ 298.985788] session1: iscsi_exec_task_mgmt_fn tmf set timeout
[ 302.075554] session1: iscsi_eh_cmd_timed_out scsi cmd 000000001a9458b5 timedout
[ 302.164786] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 314.107541] session1: iscsi_tmf_timedout tmf timedout
[ 314.169797] connection1:0: detected conn error (1021)
[ 314.232266] session1: iscsi_eh_abort abort failed [sc 00000000310a6696 itt 0x13]
[ 314.323531] session1: iscsi_eh_abort aborting sc 0000000094ad9246
[ 314.399640] session1: iscsi_eh_abort sc never reached iscsi layer or it completed.
[ 314.495578] session1: iscsi_eh_abort aborting sc 000000001a9458b5
[ 314.571554] session1: iscsi_eh_abort sc never reached iscsi layer or it completed.
[ 314.664050] session1: iscsi_eh_device_reset LU Reset [sc 00000000310a6696 lun 1]
[ 314.755773] session1: iscsi_eh_device_reset dev reset result = FAILED
[ 314.834736] session1: iscsi_eh_target_reset tgt Reset [sc 00000000310a6696 tgt <...>]
[ 314.954144] session1: iscsi_eh_target_reset tgt <...> reset result = FAILED
[ 315.063456] connection1:0: detected conn error (1021)
[ 315.125743] session1: iscsi_eh_session_reset wait for relogin
[ 398.843556] INFO: task systemd:1 blocked for more than 120 seconds.
...
[ 401.039006] INFO: task jbd2/sda1-8:2522 blocked for more than 123 seconds.
...
[ 402.483917] INFO: task iptables-restor:2648 blocked for more than 124 seconds.
...
[ 435.707549] session1: session recovery timed out after 120 secs
[ 435.780058] session1: iscsi_eh_session_reset failing session reset: Could not log back into <...> [age 0]
[ 435.920710] sd 12:0:0:1: Device offlined - not ready after error recovery
[ 436.003563] sd 12:0:0:1: [sda] tag#105 FAILED Result: hostbyte=DID_TRANSPORT_DISRUPTED driverbyte=DRIVER_OK cmd_age=169s
[ 436.015520] sd 12:0:0:1: rejecting I/O to offline device
[ 436.134354] sd 12:0:0:1: [sda] tag#105 CDB: Read(10) 28 00 00 05 8d d8 00 00 08 00
[ 436.198807] blk_update_request: I/O error, dev sda, sector 360816 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.198818] blk_update_request: I/O error, dev sda, sector 2324480 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
[ 436.198852] EXT4-fs warning (device sda1): htree_dirblock_to_tree:1004: inode #1398: lblock 0: comm systemd: error -5 reading directory block
[ 436.290259] blk_update_request: I/O error, dev sda, sector 363992 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.417093] Buffer I/O error on dev sda1, logical block 262144, lost sync page write
[ 436.417103] blk_update_request: I/O error, dev sda, sector 364040 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.417130] JBD2: Error -5 detected when updating journal superblock for sda1-8.
[ 436.417132] Aborting journal on device sda1-8. |
[Impact]
A system with rootfs on iSCSI stops booting when ufw.service starts.
The kernel logs iSCSI command/reset timeout until I/O fails and the
root filesystem/journal break.
The issue is that ufw_start() sets the default policy _first_, then
adds rules _later_.
So, a default INPUT policy of DROP (default setting in ufw) prevents
further access to the root filesystem (blocks incoming iSCSI traffic)
thus any rules that could help are not loaded (nor anything else.)
[Fix]
The fix is to set default policy after loading rules in ufw_start().
That seems to be OK as `ip[6]tables-restore -n/--noflush` is used,
and per iptables source, that only sets the chain policy.
This allows the system to boot due to the RELATED,ESTABLISHED rule,
that is introduced by before.rules in INPUT/ufw-before-input chain.
The comparison of `iptables -L` before/after shows no differences
(verified on a local rootfs); `run_tests.sh` has 0 skipped/errors.
[Test Steps]
* Install Ubuntu on an iSCSI (or other network-based) root filesystem.
(eg, Oracle Cloud's bare-metal 'BM.Standard1.36' shape.)
* sudo ufw enable
* Observed: system may stall immediately if no prior iptables rules.
(eg, iptables -A INPUT -p tcp -s 169.254.0.2 --sport 3260 -j ACCEPT)
* Expected: system continues working.
* sudo reboot
* Observed: system boot stalls once ufw.service starts (see below.)
* Expected: system boot should move on.
[Regression Potential]
* Potential regressions would be observed on ufw start/reload,
when iptables rules are configured.
* The resulting iptables configuration has been compared
before/after the change, with identical rules on both.
[Other Info]
* Fixed in Debian and Jammy.
[ufw info]
# ufw --version
ufw 0.36
Copyright 2008-2015 Canonical Ltd.
# lsb_release -cs
focal
[Boot Log]
[ 232.168355] iBFT detected.
Begin: Running /scripts/init-premount ... done.
Begin: Mounting root file system ... Begin: Running /scripts/local-top ...
Setting up software interface enp45s0f0np0
...
[ 254.644505] Loading iSCSI transport class v2.0-870.
[ 254.714938] iscsi: registered transport (tcp)
[ 254.780129] scsi host12: iSCSI Initiator over TCP/IP
...
[ 255.433491] sd 12:0:0:1: [sda] 251658240 512-byte logical blocks: (129 GB/120 GiB)
...
[ 256.379550] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null)
...
[ 266.620860] systemd[1]: Starting Uncomplicated firewall...
Starting Uncomplicated firewall...
...
[ 298.491560] session1: iscsi_eh_cmd_timed_out scsi cmd 00000000310a6696 timedout
[ 298.580803] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 298.656262] session1: iscsi_eh_cmd_timed_out scsi cmd 0000000094ad9246 timedout
[ 298.745237] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 298.745270] session1: iscsi_eh_abort aborting sc 00000000310a6696
[ 298.899644] session1: iscsi_eh_abort aborting [sc 00000000310a6696 itt 0x13]
[ 298.985788] session1: iscsi_exec_task_mgmt_fn tmf set timeout
[ 302.075554] session1: iscsi_eh_cmd_timed_out scsi cmd 000000001a9458b5 timedout
[ 302.164786] session1: iscsi_eh_cmd_timed_out return shutdown or nh
[ 314.107541] session1: iscsi_tmf_timedout tmf timedout
[ 314.169797] connection1:0: detected conn error (1021)
[ 314.232266] session1: iscsi_eh_abort abort failed [sc 00000000310a6696 itt 0x13]
[ 314.323531] session1: iscsi_eh_abort aborting sc 0000000094ad9246
[ 314.399640] session1: iscsi_eh_abort sc never reached iscsi layer or it completed.
[ 314.495578] session1: iscsi_eh_abort aborting sc 000000001a9458b5
[ 314.571554] session1: iscsi_eh_abort sc never reached iscsi layer or it completed.
[ 314.664050] session1: iscsi_eh_device_reset LU Reset [sc 00000000310a6696 lun 1]
[ 314.755773] session1: iscsi_eh_device_reset dev reset result = FAILED
[ 314.834736] session1: iscsi_eh_target_reset tgt Reset [sc 00000000310a6696 tgt <...>]
[ 314.954144] session1: iscsi_eh_target_reset tgt <...> reset result = FAILED
[ 315.063456] connection1:0: detected conn error (1021)
[ 315.125743] session1: iscsi_eh_session_reset wait for relogin
[ 398.843556] INFO: task systemd:1 blocked for more than 120 seconds.
...
[ 401.039006] INFO: task jbd2/sda1-8:2522 blocked for more than 123 seconds.
...
[ 402.483917] INFO: task iptables-restor:2648 blocked for more than 124 seconds.
...
[ 435.707549] session1: session recovery timed out after 120 secs
[ 435.780058] session1: iscsi_eh_session_reset failing session reset: Could not log back into <...> [age 0]
[ 435.920710] sd 12:0:0:1: Device offlined - not ready after error recovery
[ 436.003563] sd 12:0:0:1: [sda] tag#105 FAILED Result: hostbyte=DID_TRANSPORT_DISRUPTED driverbyte=DRIVER_OK cmd_age=169s
[ 436.015520] sd 12:0:0:1: rejecting I/O to offline device
[ 436.134354] sd 12:0:0:1: [sda] tag#105 CDB: Read(10) 28 00 00 05 8d d8 00 00 08 00
[ 436.198807] blk_update_request: I/O error, dev sda, sector 360816 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.198818] blk_update_request: I/O error, dev sda, sector 2324480 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
[ 436.198852] EXT4-fs warning (device sda1): htree_dirblock_to_tree:1004: inode #1398: lblock 0: comm systemd: error -5 reading directory block
[ 436.290259] blk_update_request: I/O error, dev sda, sector 363992 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.417093] Buffer I/O error on dev sda1, logical block 262144, lost sync page write
[ 436.417103] blk_update_request: I/O error, dev sda, sector 364040 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
[ 436.417130] JBD2: Error -5 detected when updating journal superblock for sda1-8.
[ 436.417132] Aborting journal on device sda1-8. |
|
| 2021-10-27 19:15:08 |
Mauricio Faria de Oliveira |
attachment added |
|
ufw-impish.debdiff https://bugs.launchpad.net/ufw/+bug/1946804/+attachment/5536527/+files/ufw-impish.debdiff |
|
| 2021-10-27 19:15:26 |
Mauricio Faria de Oliveira |
attachment added |
|
ufw-hirsute.debdiff https://bugs.launchpad.net/ufw/+bug/1946804/+attachment/5536528/+files/ufw-hirsute.debdiff |
|
| 2021-10-27 19:15:42 |
Mauricio Faria de Oliveira |
attachment added |
|
ufw-focal.debdiff https://bugs.launchpad.net/ufw/+bug/1946804/+attachment/5536529/+files/ufw-focal.debdiff |
|
| 2021-10-27 19:15:56 |
Mauricio Faria de Oliveira |
attachment added |
|
ufw-bionic.debdiff https://bugs.launchpad.net/ufw/+bug/1946804/+attachment/5536530/+files/ufw-bionic.debdiff |
|
| 2021-11-02 22:02:22 |
Brian Murray |
ufw (Ubuntu Impish): status |
In Progress |
Fix Committed |
|
| 2021-11-02 22:02:24 |
Brian Murray |
bug |
|
|
added subscriber Ubuntu Stable Release Updates Team |
| 2021-11-02 22:02:26 |
Brian Murray |
bug |
|
|
added subscriber SRU Verification |
| 2021-11-02 22:02:30 |
Brian Murray |
tags |
sts sts-sponsor-mfo |
sts sts-sponsor-mfo verification-needed verification-needed-impish |
|
| 2021-11-02 22:08:01 |
Brian Murray |
ufw (Ubuntu Hirsute): status |
In Progress |
Fix Committed |
|
| 2021-11-02 22:08:07 |
Brian Murray |
tags |
sts sts-sponsor-mfo verification-needed verification-needed-impish |
sts sts-sponsor-mfo verification-needed verification-needed-hirsute verification-needed-impish |
|
| 2021-11-02 22:09:27 |
Brian Murray |
ufw (Ubuntu Focal): status |
In Progress |
Fix Committed |
|
| 2021-11-02 22:09:33 |
Brian Murray |
tags |
sts sts-sponsor-mfo verification-needed verification-needed-hirsute verification-needed-impish |
sts sts-sponsor-mfo verification-needed verification-needed-focal verification-needed-hirsute verification-needed-impish |
|
| 2021-11-02 22:10:34 |
Brian Murray |
ufw (Ubuntu Bionic): status |
In Progress |
Fix Committed |
|
| 2021-11-02 22:10:41 |
Brian Murray |
tags |
sts sts-sponsor-mfo verification-needed verification-needed-focal verification-needed-hirsute verification-needed-impish |
sts sts-sponsor-mfo verification-needed verification-needed-bionic verification-needed-focal verification-needed-hirsute verification-needed-impish |
|
| 2021-11-03 18:43:38 |
Mauricio Faria de Oliveira |
tags |
sts sts-sponsor-mfo verification-needed verification-needed-bionic verification-needed-focal verification-needed-hirsute verification-needed-impish |
sts sts-sponsor-mfo verification-done verification-done-bionic verification-done-focal verification-done-hirsute verification-done-impish |
|
| 2021-11-10 18:31:41 |
Launchpad Janitor |
ufw (Ubuntu Impish): status |
Fix Committed |
Fix Released |
|
| 2021-11-10 18:31:45 |
Brian Murray |
removed subscriber Ubuntu Stable Release Updates Team |
|
|
|
| 2021-11-10 18:32:04 |
Launchpad Janitor |
ufw (Ubuntu Hirsute): status |
Fix Committed |
Fix Released |
|
| 2021-11-10 18:33:04 |
Launchpad Janitor |
ufw (Ubuntu Focal): status |
Fix Committed |
Fix Released |
|
| 2021-11-10 18:33:35 |
Launchpad Janitor |
ufw (Ubuntu Bionic): status |
Fix Committed |
Fix Released |
|
| 2022-04-25 14:53:53 |
Mauricio Faria de Oliveira |
tags |
sts sts-sponsor-mfo verification-done verification-done-bionic verification-done-focal verification-done-hirsute verification-done-impish |
sts verification-done verification-done-bionic verification-done-focal verification-done-hirsute verification-done-impish |
|
| 2023-05-18 14:07:11 |
Jamie Strandboge |
ufw: importance |
Undecided |
Medium |
|
| 2023-05-18 14:07:11 |
Jamie Strandboge |
ufw: assignee |
|
Jamie Strandboge (jdstrand) |
|
| 2023-05-18 14:08:02 |
Jamie Strandboge |
ufw: status |
Fix Committed |
Fix Released |
|
| 2023-05-18 14:08:08 |
Jamie Strandboge |
ufw (Ubuntu): importance |
Undecided |
Medium |
|
