diff mbox

sctp: fix a BUG_ON on triggered by setting max_autoclose to

Message ID 529DADE5.4040701@huawei.com
State Changes Requested, archived
Delegated to: David Miller
Headers show

Commit Message

wangweidong Dec. 3, 2013, 10:09 a.m. UTC 
since 2692ba61, add the max_autoclose to sysctl. when I setted the
max_autoclose to 0. Just do the test_autoclose, it will trigger that:

[  608.056238] ------------[ cut here ]------------
[  608.056244] kernel BUG at /home/wwd/work/linux/net/sctp/sm_sideeffect.c:1488!
[  608.056250] invalid opcode: 0000 [#1] SMP
[  608.056254] Modules linked in: md5 sctp(O) crc32c libcrc32c edd fuse loop dm_mod ipv6 8139too sg 8139cp mii i2c_piix4 i2c_core virtio_balloon intel_agp virtio_pci virtio_ring sr_mod cdrom rtc_cmos joydev hid_generic intel_gtt virtio floppy pcspkr button ext3 jbd mbcache usbhid hid uhci_hcd ehci_hcd usbcore sd_mod usb_common crc_t10dif crct10dif_common processor thermal_sys hwmon scsi_dh_emc scsi_dh_alua scsi_dh_hp_sw scsi_dh_rdac scsi_dh ata_generic ata_piix libata scsi_mod [last unloaded: sctp]
[  608.056310] CPU: 5 PID: 4517 Comm: test_autoclose Tainted: G  R        O 3.13.0-rc1-0.27-default+ #2
[  608.056315] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2007
[  608.056319] task: ffff8800372f5590 ti: ffff8800db882000 task.ti: ffff8800db882000
[  608.056323] RIP: 0010:[<ffffffffa033e350>]  [<ffffffffa033e350>] sctp_cmd_interpreter+0x1010/0x1070 [sctp]
[  608.056339] RSP: 0018:ffff880116f43928  EFLAGS: 00010246
[  608.056343] RAX: 0000000000000009 RBX: ffff880116f43ab8 RCX: 0000000000000009
[  608.056349] RDX: 0000000000000003 RSI: 0000000000000000 RDI: ffff880116f43a88
[  608.056353] RBP: ffff880116f439d8 R08: 0000000000002029 R09: 0000000000000001
[  608.056357] R10: 0000000000000000 R11: 0000000000000005 R12: ffff8800db7c9150
[  608.056361] R13: 0000000000000000 R14: ffff8800db7c9000 R15: 0000000000000001
[  608.056365] FS:  00007f942d71c700(0000) GS:ffff880116f40000(0000) knlGS:0000000000000000
[  608.056370] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[  608.056373] CR2: 00007f942d324d90 CR3: 00000000db094000 CR4: 00000000000006e0
[  608.056382] Stack:
[  608.056384]  0000000000000018 ffff880116f43988 ffff8800da569600 000000010000000a
[  608.056391]  ffff880037265e40 0000000016f43988 ffff880116f439e8 0000000000000000
[  608.056397]  ffffffffa0365101 0000000000000000 ffff880116f43a28 ffffffff812b7739
[  608.056403] Call Trace:
[  608.056406]  <IRQ>
[  608.056409]
[  608.056421]  [<ffffffff812b7739>] ? __dynamic_pr_debug+0x69/0x80
[  608.056432]  [<ffffffff81097c6d>] ? trace_hardirqs_off+0xd/0x10
[  608.056442]  [<ffffffff814e7258>] ? _raw_spin_unlock_irqrestore+0x58/0x60
[  608.056451]  [<ffffffffa033e3e6>] sctp_side_effects+0x36/0x130 [sctp]
[  608.056459]  [<ffffffffa033e5c7>] sctp_do_sm+0xe7/0x210 [sctp]
[  608.056470]  [<ffffffffa0359860>] ? sctp_rcv+0x780/0x780 [sctp]
[  608.056479]  [<ffffffffa0340a5f>] sctp_endpoint_bh_rcv+0x10f/0x220 [sctp]
[  608.056489]  [<ffffffffa0349991>] sctp_inq_push+0x41/0x60 [sctp]
[  608.056498]  [<ffffffffa03597b5>] sctp_rcv+0x6d5/0x780 [sctp]
[  608.056508]  [<ffffffffa0358e00>] ? sctp_csum_combine+0x10/0x10 [sctp]
[  608.056518]  [<ffffffffa0358df0>] ? sctp_v4_err+0x240/0x240 [sctp]
[  608.056528]  [<ffffffff8145b8a4>] ip_local_deliver_finish+0xf4/0x270
[  608.056533]  [<ffffffff8145b7f0>] ? ip_local_deliver_finish+0x40/0x270
[  608.056538]  [<ffffffff8145b690>] ip_local_deliver+0x80/0x90
[  608.056543]  [<ffffffff8145bbd3>] ip_rcv_finish+0x1b3/0x600
[  608.056547]  [<ffffffff8145ba20>] ? ip_local_deliver_finish+0x270/0x270
[  608.056552]  [<ffffffff8145b04f>] NF_HOOK+0x2f/0x70
[  608.056565]  [<ffffffff81425853>] ? __netif_receive_skb_core+0x113/0x7a0
[  608.056570]  [<ffffffff8145b365>] ip_rcv+0x2d5/0x3b0
[  608.056575]  [<ffffffff81425e3f>] __netif_receive_skb_core+0x6ff/0x7a0
[  608.056580]  [<ffffffff81425853>] ? __netif_receive_skb_core+0x113/0x7a0
[  608.056585]  [<ffffffff81426108>] ? process_backlog+0x1a8/0x1c0
[  608.056590]  [<ffffffff81425f0b>] __netif_receive_skb+0x2b/0x80
[  608.056595]  [<ffffffff81426018>] process_backlog+0xb8/0x1c0
[  608.056600]  [<ffffffff8142695c>] net_rx_action+0x11c/0x240
[  608.056607]  [<ffffffff81050e18>] __do_softirq+0x118/0x290
[  608.056615]  [<ffffffff814f0e0c>] do_softirq_own_stack+0x1c/0x30
[  608.056618]  <EOI>
[  608.056620]
[  608.056623]  [<ffffffff81050bd5>] do_softirq+0x65/0x70
[  608.056629]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
[  608.056635]  [<ffffffff810518c3>] local_bh_enable_ip+0xb3/0xc0
[  608.056640]  [<ffffffff814e71af>] _raw_spin_unlock_bh+0x2f/0x40
[  608.056645]  [<ffffffff8140fddc>] release_sock+0x8c/0xa0
[  608.056654]  [<ffffffffa0354c08>] sctp_sendmsg+0x3a8/0xcc0 [sctp]
[  608.056661]  [<ffffffff8129924a>] ? number+0x33a/0x360
[  608.056667]  [<ffffffff81497c3c>] inet_sendmsg+0x9c/0x100
[  608.056672]  [<ffffffff81497ba0>] ? inet_recvmsg+0x110/0x110
[  608.056679]  [<ffffffff8140a387>] sock_sendmsg+0x97/0xc0
[  608.056690]  [<ffffffff8114caae>] ? might_fault+0x3e/0x90
[  608.056695]  [<ffffffff8114caae>] ? might_fault+0x3e/0x90
[  608.056700]  [<ffffffff81417a73>] ? verify_iovec+0x53/0x100
[  608.056705]  [<ffffffff8140abb6>] ___sys_sendmsg+0x416/0x420
[  608.056710]  [<ffffffff81151af6>] ? __do_fault+0x216/0x510
[  608.056715]  [<ffffffff814eaf74>] ? __do_page_fault+0x2b4/0x4a0
[  608.056720]  [<ffffffff81095c9e>] ? up_read+0x1e/0x40
[  608.056724]  [<ffffffff814eaf74>] ? __do_page_fault+0x2b4/0x4a0
[  608.056729]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
[  608.056733]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
[  608.056741]  [<ffffffff8109bb5d>] ? trace_hardirqs_on+0xd/0x10
[  608.056746]  [<ffffffff81051875>] ? local_bh_enable_ip+0x65/0xc0
[  608.056751]  [<ffffffff8140ad94>] __sys_sendmsg+0x44/0x80
[  608.056756]  [<ffffffff8140ade4>] SyS_sendmsg+0x14/0x20
[  608.056761]  [<ffffffff814ef5a2>] system_call_fastpath+0x16/0x1b
-------------------------------------

The reason is: In test_autoclose set the autoclose to 5 not 0(default). So when
we init the association, the (sctp_sock) sp->autoclose is not 0 while asoc's 
timeouts[SCTP_EVENT_TIMEOUT_AUTOCLOSE] is 0. 
So when we process the COOKIE_ACK, the sctp_sf_do_5_1E_ca will be called, that
will do that:
	if (asoc->autoclose) //asoc->autoclose is equal sp->autoclose
		sctp_add_cmd_sf(commands, SCTP_CMD_TIMER_START,
				SCTP_TO(SCTP_EVENT_TIMEOUT_AUTOCLOSE));
then the sctp_do_sm will goto the SCTP_CMD_TIMER_START where place a BUG_ON.
So When we do test_autoclose will trigger the BUG_ON.
And when the sp->autoclose is 0, it will not happen.

the timeout is zero only when the sp->autoclose is 0. While the sp->autoclose should
consistent between setsockopt() and getsockopt() calls.
so I make the max_autoclose min value to 1.

Signed-off-by: Wang Weidong <wangweidong1@huawei.com>
---
 net/sctp/sysctl.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

Comments

Neil Horman Dec. 3, 2013, 3:43 p.m. UTC | #1 
On Tue, Dec 03, 2013 at 06:09:41PM +0800, Wang Weidong wrote:
> since 2692ba61, add the max_autoclose to sysctl. when I setted the
> max_autoclose to 0. Just do the test_autoclose, it will trigger that:
> 
> [  608.056238] ------------[ cut here ]------------
> [  608.056244] kernel BUG at /home/wwd/work/linux/net/sctp/sm_sideeffect.c:1488!
> [  608.056250] invalid opcode: 0000 [#1] SMP
> [  608.056254] Modules linked in: md5 sctp(O) crc32c libcrc32c edd fuse loop dm_mod ipv6 8139too sg 8139cp mii i2c_piix4 i2c_core virtio_balloon intel_agp virtio_pci virtio_ring sr_mod cdrom rtc_cmos joydev hid_generic intel_gtt virtio floppy pcspkr button ext3 jbd mbcache usbhid hid uhci_hcd ehci_hcd usbcore sd_mod usb_common crc_t10dif crct10dif_common processor thermal_sys hwmon scsi_dh_emc scsi_dh_alua scsi_dh_hp_sw scsi_dh_rdac scsi_dh ata_generic ata_piix libata scsi_mod [last unloaded: sctp]
> [  608.056310] CPU: 5 PID: 4517 Comm: test_autoclose Tainted: G  R        O 3.13.0-rc1-0.27-default+ #2
> [  608.056315] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2007
> [  608.056319] task: ffff8800372f5590 ti: ffff8800db882000 task.ti: ffff8800db882000
> [  608.056323] RIP: 0010:[<ffffffffa033e350>]  [<ffffffffa033e350>] sctp_cmd_interpreter+0x1010/0x1070 [sctp]
> [  608.056339] RSP: 0018:ffff880116f43928  EFLAGS: 00010246
> [  608.056343] RAX: 0000000000000009 RBX: ffff880116f43ab8 RCX: 0000000000000009
> [  608.056349] RDX: 0000000000000003 RSI: 0000000000000000 RDI: ffff880116f43a88
> [  608.056353] RBP: ffff880116f439d8 R08: 0000000000002029 R09: 0000000000000001
> [  608.056357] R10: 0000000000000000 R11: 0000000000000005 R12: ffff8800db7c9150
> [  608.056361] R13: 0000000000000000 R14: ffff8800db7c9000 R15: 0000000000000001
> [  608.056365] FS:  00007f942d71c700(0000) GS:ffff880116f40000(0000) knlGS:0000000000000000
> [  608.056370] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
> [  608.056373] CR2: 00007f942d324d90 CR3: 00000000db094000 CR4: 00000000000006e0
> [  608.056382] Stack:
> [  608.056384]  0000000000000018 ffff880116f43988 ffff8800da569600 000000010000000a
> [  608.056391]  ffff880037265e40 0000000016f43988 ffff880116f439e8 0000000000000000
> [  608.056397]  ffffffffa0365101 0000000000000000 ffff880116f43a28 ffffffff812b7739
> [  608.056403] Call Trace:
> [  608.056406]  <IRQ>
> [  608.056409]
> [  608.056421]  [<ffffffff812b7739>] ? __dynamic_pr_debug+0x69/0x80
> [  608.056432]  [<ffffffff81097c6d>] ? trace_hardirqs_off+0xd/0x10
> [  608.056442]  [<ffffffff814e7258>] ? _raw_spin_unlock_irqrestore+0x58/0x60
> [  608.056451]  [<ffffffffa033e3e6>] sctp_side_effects+0x36/0x130 [sctp]
> [  608.056459]  [<ffffffffa033e5c7>] sctp_do_sm+0xe7/0x210 [sctp]
> [  608.056470]  [<ffffffffa0359860>] ? sctp_rcv+0x780/0x780 [sctp]
> [  608.056479]  [<ffffffffa0340a5f>] sctp_endpoint_bh_rcv+0x10f/0x220 [sctp]
> [  608.056489]  [<ffffffffa0349991>] sctp_inq_push+0x41/0x60 [sctp]
> [  608.056498]  [<ffffffffa03597b5>] sctp_rcv+0x6d5/0x780 [sctp]
> [  608.056508]  [<ffffffffa0358e00>] ? sctp_csum_combine+0x10/0x10 [sctp]
> [  608.056518]  [<ffffffffa0358df0>] ? sctp_v4_err+0x240/0x240 [sctp]
> [  608.056528]  [<ffffffff8145b8a4>] ip_local_deliver_finish+0xf4/0x270
> [  608.056533]  [<ffffffff8145b7f0>] ? ip_local_deliver_finish+0x40/0x270
> [  608.056538]  [<ffffffff8145b690>] ip_local_deliver+0x80/0x90
> [  608.056543]  [<ffffffff8145bbd3>] ip_rcv_finish+0x1b3/0x600
> [  608.056547]  [<ffffffff8145ba20>] ? ip_local_deliver_finish+0x270/0x270
> [  608.056552]  [<ffffffff8145b04f>] NF_HOOK+0x2f/0x70
> [  608.056565]  [<ffffffff81425853>] ? __netif_receive_skb_core+0x113/0x7a0
> [  608.056570]  [<ffffffff8145b365>] ip_rcv+0x2d5/0x3b0
> [  608.056575]  [<ffffffff81425e3f>] __netif_receive_skb_core+0x6ff/0x7a0
> [  608.056580]  [<ffffffff81425853>] ? __netif_receive_skb_core+0x113/0x7a0
> [  608.056585]  [<ffffffff81426108>] ? process_backlog+0x1a8/0x1c0
> [  608.056590]  [<ffffffff81425f0b>] __netif_receive_skb+0x2b/0x80
> [  608.056595]  [<ffffffff81426018>] process_backlog+0xb8/0x1c0
> [  608.056600]  [<ffffffff8142695c>] net_rx_action+0x11c/0x240
> [  608.056607]  [<ffffffff81050e18>] __do_softirq+0x118/0x290
> [  608.056615]  [<ffffffff814f0e0c>] do_softirq_own_stack+0x1c/0x30
> [  608.056618]  <EOI>
> [  608.056620]
> [  608.056623]  [<ffffffff81050bd5>] do_softirq+0x65/0x70
> [  608.056629]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
> [  608.056635]  [<ffffffff810518c3>] local_bh_enable_ip+0xb3/0xc0
> [  608.056640]  [<ffffffff814e71af>] _raw_spin_unlock_bh+0x2f/0x40
> [  608.056645]  [<ffffffff8140fddc>] release_sock+0x8c/0xa0
> [  608.056654]  [<ffffffffa0354c08>] sctp_sendmsg+0x3a8/0xcc0 [sctp]
> [  608.056661]  [<ffffffff8129924a>] ? number+0x33a/0x360
> [  608.056667]  [<ffffffff81497c3c>] inet_sendmsg+0x9c/0x100
> [  608.056672]  [<ffffffff81497ba0>] ? inet_recvmsg+0x110/0x110
> [  608.056679]  [<ffffffff8140a387>] sock_sendmsg+0x97/0xc0
> [  608.056690]  [<ffffffff8114caae>] ? might_fault+0x3e/0x90
> [  608.056695]  [<ffffffff8114caae>] ? might_fault+0x3e/0x90
> [  608.056700]  [<ffffffff81417a73>] ? verify_iovec+0x53/0x100
> [  608.056705]  [<ffffffff8140abb6>] ___sys_sendmsg+0x416/0x420
> [  608.056710]  [<ffffffff81151af6>] ? __do_fault+0x216/0x510
> [  608.056715]  [<ffffffff814eaf74>] ? __do_page_fault+0x2b4/0x4a0
> [  608.056720]  [<ffffffff81095c9e>] ? up_read+0x1e/0x40
> [  608.056724]  [<ffffffff814eaf74>] ? __do_page_fault+0x2b4/0x4a0
> [  608.056729]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
> [  608.056733]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
> [  608.056741]  [<ffffffff8109bb5d>] ? trace_hardirqs_on+0xd/0x10
> [  608.056746]  [<ffffffff81051875>] ? local_bh_enable_ip+0x65/0xc0
> [  608.056751]  [<ffffffff8140ad94>] __sys_sendmsg+0x44/0x80
> [  608.056756]  [<ffffffff8140ade4>] SyS_sendmsg+0x14/0x20
> [  608.056761]  [<ffffffff814ef5a2>] system_call_fastpath+0x16/0x1b
> -------------------------------------
> 
> The reason is: In test_autoclose set the autoclose to 5 not 0(default). So when
> we init the association, the (sctp_sock) sp->autoclose is not 0 while asoc's 
> timeouts[SCTP_EVENT_TIMEOUT_AUTOCLOSE] is 0. 
> So when we process the COOKIE_ACK, the sctp_sf_do_5_1E_ca will be called, that
> will do that:
> 	if (asoc->autoclose) //asoc->autoclose is equal sp->autoclose
> 		sctp_add_cmd_sf(commands, SCTP_CMD_TIMER_START,
> 				SCTP_TO(SCTP_EVENT_TIMEOUT_AUTOCLOSE));
> then the sctp_do_sm will goto the SCTP_CMD_TIMER_START where place a BUG_ON.
> So When we do test_autoclose will trigger the BUG_ON.
> And when the sp->autoclose is 0, it will not happen.
> 
> the timeout is zero only when the sp->autoclose is 0. While the sp->autoclose should
> consistent between setsockopt() and getsockopt() calls.
> so I make the max_autoclose min value to 1.
> 
> Signed-off-by: Wang Weidong <wangweidong1@huawei.com>
Acked-by: Neil Horman <nhorman@tuxdriver.com>

--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Vladislav Yasevich Dec. 3, 2013, 4:09 p.m. UTC | #2 
On 12/03/2013 05:09 AM, Wang Weidong wrote:
> since 2692ba61, add the max_autoclose to sysctl. when I setted the
> max_autoclose to 0. Just do the test_autoclose, it will trigger that:
> 
> [  608.056238] ------------[ cut here ]------------
> [  608.056244] kernel BUG at /home/wwd/work/linux/net/sctp/sm_sideeffect.c:1488!
> [  608.056250] invalid opcode: 0000 [#1] SMP
> [  608.056254] Modules linked in: md5 sctp(O) crc32c libcrc32c edd fuse loop dm_mod ipv6 8139too sg 8139cp mii i2c_piix4 i2c_core virtio_balloon intel_agp virtio_pci virtio_ring sr_mod cdrom rtc_cmos joydev hid_generic intel_gtt virtio floppy pcspkr button ext3 jbd mbcache usbhid hid uhci_hcd ehci_hcd usbcore sd_mod usb_common crc_t10dif crct10dif_common processor thermal_sys hwmon scsi_dh_emc scsi_dh_alua scsi_dh_hp_sw scsi_dh_rdac scsi_dh ata_generic ata_piix libata scsi_mod [last unloaded: sctp]
> [  608.056310] CPU: 5 PID: 4517 Comm: test_autoclose Tainted: G  R        O 3.13.0-rc1-0.27-default+ #2
> [  608.056315] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2007
> [  608.056319] task: ffff8800372f5590 ti: ffff8800db882000 task.ti: ffff8800db882000
> [  608.056323] RIP: 0010:[<ffffffffa033e350>]  [<ffffffffa033e350>] sctp_cmd_interpreter+0x1010/0x1070 [sctp]
> [  608.056339] RSP: 0018:ffff880116f43928  EFLAGS: 00010246
> [  608.056343] RAX: 0000000000000009 RBX: ffff880116f43ab8 RCX: 0000000000000009
> [  608.056349] RDX: 0000000000000003 RSI: 0000000000000000 RDI: ffff880116f43a88
> [  608.056353] RBP: ffff880116f439d8 R08: 0000000000002029 R09: 0000000000000001
> [  608.056357] R10: 0000000000000000 R11: 0000000000000005 R12: ffff8800db7c9150
> [  608.056361] R13: 0000000000000000 R14: ffff8800db7c9000 R15: 0000000000000001
> [  608.056365] FS:  00007f942d71c700(0000) GS:ffff880116f40000(0000) knlGS:0000000000000000
> [  608.056370] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
> [  608.056373] CR2: 00007f942d324d90 CR3: 00000000db094000 CR4: 00000000000006e0
> [  608.056382] Stack:
> [  608.056384]  0000000000000018 ffff880116f43988 ffff8800da569600 000000010000000a
> [  608.056391]  ffff880037265e40 0000000016f43988 ffff880116f439e8 0000000000000000
> [  608.056397]  ffffffffa0365101 0000000000000000 ffff880116f43a28 ffffffff812b7739
> [  608.056403] Call Trace:
> [  608.056406]  <IRQ>
> [  608.056409]
> [  608.056421]  [<ffffffff812b7739>] ? __dynamic_pr_debug+0x69/0x80
> [  608.056432]  [<ffffffff81097c6d>] ? trace_hardirqs_off+0xd/0x10
> [  608.056442]  [<ffffffff814e7258>] ? _raw_spin_unlock_irqrestore+0x58/0x60
> [  608.056451]  [<ffffffffa033e3e6>] sctp_side_effects+0x36/0x130 [sctp]
> [  608.056459]  [<ffffffffa033e5c7>] sctp_do_sm+0xe7/0x210 [sctp]
> [  608.056470]  [<ffffffffa0359860>] ? sctp_rcv+0x780/0x780 [sctp]
> [  608.056479]  [<ffffffffa0340a5f>] sctp_endpoint_bh_rcv+0x10f/0x220 [sctp]
> [  608.056489]  [<ffffffffa0349991>] sctp_inq_push+0x41/0x60 [sctp]
> [  608.056498]  [<ffffffffa03597b5>] sctp_rcv+0x6d5/0x780 [sctp]
> [  608.056508]  [<ffffffffa0358e00>] ? sctp_csum_combine+0x10/0x10 [sctp]
> [  608.056518]  [<ffffffffa0358df0>] ? sctp_v4_err+0x240/0x240 [sctp]
> [  608.056528]  [<ffffffff8145b8a4>] ip_local_deliver_finish+0xf4/0x270
> [  608.056533]  [<ffffffff8145b7f0>] ? ip_local_deliver_finish+0x40/0x270
> [  608.056538]  [<ffffffff8145b690>] ip_local_deliver+0x80/0x90
> [  608.056543]  [<ffffffff8145bbd3>] ip_rcv_finish+0x1b3/0x600
> [  608.056547]  [<ffffffff8145ba20>] ? ip_local_deliver_finish+0x270/0x270
> [  608.056552]  [<ffffffff8145b04f>] NF_HOOK+0x2f/0x70
> [  608.056565]  [<ffffffff81425853>] ? __netif_receive_skb_core+0x113/0x7a0
> [  608.056570]  [<ffffffff8145b365>] ip_rcv+0x2d5/0x3b0
> [  608.056575]  [<ffffffff81425e3f>] __netif_receive_skb_core+0x6ff/0x7a0
> [  608.056580]  [<ffffffff81425853>] ? __netif_receive_skb_core+0x113/0x7a0
> [  608.056585]  [<ffffffff81426108>] ? process_backlog+0x1a8/0x1c0
> [  608.056590]  [<ffffffff81425f0b>] __netif_receive_skb+0x2b/0x80
> [  608.056595]  [<ffffffff81426018>] process_backlog+0xb8/0x1c0
> [  608.056600]  [<ffffffff8142695c>] net_rx_action+0x11c/0x240
> [  608.056607]  [<ffffffff81050e18>] __do_softirq+0x118/0x290
> [  608.056615]  [<ffffffff814f0e0c>] do_softirq_own_stack+0x1c/0x30
> [  608.056618]  <EOI>
> [  608.056620]
> [  608.056623]  [<ffffffff81050bd5>] do_softirq+0x65/0x70
> [  608.056629]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
> [  608.056635]  [<ffffffff810518c3>] local_bh_enable_ip+0xb3/0xc0
> [  608.056640]  [<ffffffff814e71af>] _raw_spin_unlock_bh+0x2f/0x40
> [  608.056645]  [<ffffffff8140fddc>] release_sock+0x8c/0xa0
> [  608.056654]  [<ffffffffa0354c08>] sctp_sendmsg+0x3a8/0xcc0 [sctp]
> [  608.056661]  [<ffffffff8129924a>] ? number+0x33a/0x360
> [  608.056667]  [<ffffffff81497c3c>] inet_sendmsg+0x9c/0x100
> [  608.056672]  [<ffffffff81497ba0>] ? inet_recvmsg+0x110/0x110
> [  608.056679]  [<ffffffff8140a387>] sock_sendmsg+0x97/0xc0
> [  608.056690]  [<ffffffff8114caae>] ? might_fault+0x3e/0x90
> [  608.056695]  [<ffffffff8114caae>] ? might_fault+0x3e/0x90
> [  608.056700]  [<ffffffff81417a73>] ? verify_iovec+0x53/0x100
> [  608.056705]  [<ffffffff8140abb6>] ___sys_sendmsg+0x416/0x420
> [  608.056710]  [<ffffffff81151af6>] ? __do_fault+0x216/0x510
> [  608.056715]  [<ffffffff814eaf74>] ? __do_page_fault+0x2b4/0x4a0
> [  608.056720]  [<ffffffff81095c9e>] ? up_read+0x1e/0x40
> [  608.056724]  [<ffffffff814eaf74>] ? __do_page_fault+0x2b4/0x4a0
> [  608.056729]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
> [  608.056733]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
> [  608.056741]  [<ffffffff8109bb5d>] ? trace_hardirqs_on+0xd/0x10
> [  608.056746]  [<ffffffff81051875>] ? local_bh_enable_ip+0x65/0xc0
> [  608.056751]  [<ffffffff8140ad94>] __sys_sendmsg+0x44/0x80
> [  608.056756]  [<ffffffff8140ade4>] SyS_sendmsg+0x14/0x20
> [  608.056761]  [<ffffffff814ef5a2>] system_call_fastpath+0x16/0x1b
> -------------------------------------
> 
> The reason is: In test_autoclose set the autoclose to 5 not 0(default). So when
> we init the association, the (sctp_sock) sp->autoclose is not 0 while asoc's 
> timeouts[SCTP_EVENT_TIMEOUT_AUTOCLOSE] is 0.
> So when we process the COOKIE_ACK, the sctp_sf_do_5_1E_ca will be called, that
> will do that:
> 	if (asoc->autoclose) //asoc->autoclose is equal sp->autoclose
> 		sctp_add_cmd_sf(commands, SCTP_CMD_TIMER_START,
> 				SCTP_TO(SCTP_EVENT_TIMEOUT_AUTOCLOSE));

this looks like a bug in how the timeout is being set.  The timeout
should be based on the association value, not some sysctl value.

The typical socket option values go like this:
   socket value = starts at sysctl, changed by user.
   assoc value = starts at socket value, may be changed by user.
     any timer = starts at assoc value.

this seems to be broken for autoclose.

> then the sctp_do_sm will goto the SCTP_CMD_TIMER_START where place a BUG_ON.
> So When we do test_autoclose will trigger the BUG_ON.
> And when the sp->autoclose is 0, it will not happen.
> 
> the timeout is zero only when the sp->autoclose is 0. While the sp->autoclose should
> consistent between setsockopt() and getsockopt() calls.
> so I make the max_autoclose min value to 1.
> 
> Signed-off-by: Wang Weidong <wangweidong1@huawei.com>
> ---
>  net/sctp/sysctl.c | 2 +-
>  1 file changed, 1 insertion(+), 1 deletion(-)
> 
> diff --git a/net/sctp/sysctl.c b/net/sctp/sysctl.c
> index 46832d3..8b619d6 100644
> --- a/net/sctp/sysctl.c
> +++ b/net/sctp/sysctl.c
> @@ -47,7 +47,7 @@ static int sack_timer_min = 1;
>  static int sack_timer_max = 500;
>  static int addr_scope_max = 3; /* check sctp_scope_policy_t in include/net/sctp/constants.h for max entries */
>  static int rwnd_scale_max = 16;
> -static unsigned long max_autoclose_min = 0;
> +static unsigned long max_autoclose_min = 1;
>  static unsigned long max_autoclose_max =
>  	(MAX_SCHEDULE_TIMEOUT / HZ > UINT_MAX)
>  	? UINT_MAX : MAX_SCHEDULE_TIMEOUT / HZ;
> 

allowing autoclose_min = 0 might be useful to disable
autoclose globally.  This is not a fix, but a bandaid.

-vlad
--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Neil Horman Dec. 3, 2013, 6:18 p.m. UTC | #3 
On Tue, Dec 03, 2013 at 11:09:38AM -0500, Vlad Yasevich wrote:
> On 12/03/2013 05:09 AM, Wang Weidong wrote:
> > since 2692ba61, add the max_autoclose to sysctl. when I setted the
> > max_autoclose to 0. Just do the test_autoclose, it will trigger that:
> > 
> > [  608.056238] ------------[ cut here ]------------
> > [  608.056244] kernel BUG at /home/wwd/work/linux/net/sctp/sm_sideeffect.c:1488!
> > [  608.056250] invalid opcode: 0000 [#1] SMP
> > [  608.056254] Modules linked in: md5 sctp(O) crc32c libcrc32c edd fuse loop dm_mod ipv6 8139too sg 8139cp mii i2c_piix4 i2c_core virtio_balloon intel_agp virtio_pci virtio_ring sr_mod cdrom rtc_cmos joydev hid_generic intel_gtt virtio floppy pcspkr button ext3 jbd mbcache usbhid hid uhci_hcd ehci_hcd usbcore sd_mod usb_common crc_t10dif crct10dif_common processor thermal_sys hwmon scsi_dh_emc scsi_dh_alua scsi_dh_hp_sw scsi_dh_rdac scsi_dh ata_generic ata_piix libata scsi_mod [last unloaded: sctp]
> > [  608.056310] CPU: 5 PID: 4517 Comm: test_autoclose Tainted: G  R        O 3.13.0-rc1-0.27-default+ #2
> > [  608.056315] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2007
> > [  608.056319] task: ffff8800372f5590 ti: ffff8800db882000 task.ti: ffff8800db882000
> > [  608.056323] RIP: 0010:[<ffffffffa033e350>]  [<ffffffffa033e350>] sctp_cmd_interpreter+0x1010/0x1070 [sctp]
> > [  608.056339] RSP: 0018:ffff880116f43928  EFLAGS: 00010246
> > [  608.056343] RAX: 0000000000000009 RBX: ffff880116f43ab8 RCX: 0000000000000009
> > [  608.056349] RDX: 0000000000000003 RSI: 0000000000000000 RDI: ffff880116f43a88
> > [  608.056353] RBP: ffff880116f439d8 R08: 0000000000002029 R09: 0000000000000001
> > [  608.056357] R10: 0000000000000000 R11: 0000000000000005 R12: ffff8800db7c9150
> > [  608.056361] R13: 0000000000000000 R14: ffff8800db7c9000 R15: 0000000000000001
> > [  608.056365] FS:  00007f942d71c700(0000) GS:ffff880116f40000(0000) knlGS:0000000000000000
> > [  608.056370] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
> > [  608.056373] CR2: 00007f942d324d90 CR3: 00000000db094000 CR4: 00000000000006e0
> > [  608.056382] Stack:
> > [  608.056384]  0000000000000018 ffff880116f43988 ffff8800da569600 000000010000000a
> > [  608.056391]  ffff880037265e40 0000000016f43988 ffff880116f439e8 0000000000000000
> > [  608.056397]  ffffffffa0365101 0000000000000000 ffff880116f43a28 ffffffff812b7739
> > [  608.056403] Call Trace:
> > [  608.056406]  <IRQ>
> > [  608.056409]
> > [  608.056421]  [<ffffffff812b7739>] ? __dynamic_pr_debug+0x69/0x80
> > [  608.056432]  [<ffffffff81097c6d>] ? trace_hardirqs_off+0xd/0x10
> > [  608.056442]  [<ffffffff814e7258>] ? _raw_spin_unlock_irqrestore+0x58/0x60
> > [  608.056451]  [<ffffffffa033e3e6>] sctp_side_effects+0x36/0x130 [sctp]
> > [  608.056459]  [<ffffffffa033e5c7>] sctp_do_sm+0xe7/0x210 [sctp]
> > [  608.056470]  [<ffffffffa0359860>] ? sctp_rcv+0x780/0x780 [sctp]
> > [  608.056479]  [<ffffffffa0340a5f>] sctp_endpoint_bh_rcv+0x10f/0x220 [sctp]
> > [  608.056489]  [<ffffffffa0349991>] sctp_inq_push+0x41/0x60 [sctp]
> > [  608.056498]  [<ffffffffa03597b5>] sctp_rcv+0x6d5/0x780 [sctp]
> > [  608.056508]  [<ffffffffa0358e00>] ? sctp_csum_combine+0x10/0x10 [sctp]
> > [  608.056518]  [<ffffffffa0358df0>] ? sctp_v4_err+0x240/0x240 [sctp]
> > [  608.056528]  [<ffffffff8145b8a4>] ip_local_deliver_finish+0xf4/0x270
> > [  608.056533]  [<ffffffff8145b7f0>] ? ip_local_deliver_finish+0x40/0x270
> > [  608.056538]  [<ffffffff8145b690>] ip_local_deliver+0x80/0x90
> > [  608.056543]  [<ffffffff8145bbd3>] ip_rcv_finish+0x1b3/0x600
> > [  608.056547]  [<ffffffff8145ba20>] ? ip_local_deliver_finish+0x270/0x270
> > [  608.056552]  [<ffffffff8145b04f>] NF_HOOK+0x2f/0x70
> > [  608.056565]  [<ffffffff81425853>] ? __netif_receive_skb_core+0x113/0x7a0
> > [  608.056570]  [<ffffffff8145b365>] ip_rcv+0x2d5/0x3b0
> > [  608.056575]  [<ffffffff81425e3f>] __netif_receive_skb_core+0x6ff/0x7a0
> > [  608.056580]  [<ffffffff81425853>] ? __netif_receive_skb_core+0x113/0x7a0
> > [  608.056585]  [<ffffffff81426108>] ? process_backlog+0x1a8/0x1c0
> > [  608.056590]  [<ffffffff81425f0b>] __netif_receive_skb+0x2b/0x80
> > [  608.056595]  [<ffffffff81426018>] process_backlog+0xb8/0x1c0
> > [  608.056600]  [<ffffffff8142695c>] net_rx_action+0x11c/0x240
> > [  608.056607]  [<ffffffff81050e18>] __do_softirq+0x118/0x290
> > [  608.056615]  [<ffffffff814f0e0c>] do_softirq_own_stack+0x1c/0x30
> > [  608.056618]  <EOI>
> > [  608.056620]
> > [  608.056623]  [<ffffffff81050bd5>] do_softirq+0x65/0x70
> > [  608.056629]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
> > [  608.056635]  [<ffffffff810518c3>] local_bh_enable_ip+0xb3/0xc0
> > [  608.056640]  [<ffffffff814e71af>] _raw_spin_unlock_bh+0x2f/0x40
> > [  608.056645]  [<ffffffff8140fddc>] release_sock+0x8c/0xa0
> > [  608.056654]  [<ffffffffa0354c08>] sctp_sendmsg+0x3a8/0xcc0 [sctp]
> > [  608.056661]  [<ffffffff8129924a>] ? number+0x33a/0x360
> > [  608.056667]  [<ffffffff81497c3c>] inet_sendmsg+0x9c/0x100
> > [  608.056672]  [<ffffffff81497ba0>] ? inet_recvmsg+0x110/0x110
> > [  608.056679]  [<ffffffff8140a387>] sock_sendmsg+0x97/0xc0
> > [  608.056690]  [<ffffffff8114caae>] ? might_fault+0x3e/0x90
> > [  608.056695]  [<ffffffff8114caae>] ? might_fault+0x3e/0x90
> > [  608.056700]  [<ffffffff81417a73>] ? verify_iovec+0x53/0x100
> > [  608.056705]  [<ffffffff8140abb6>] ___sys_sendmsg+0x416/0x420
> > [  608.056710]  [<ffffffff81151af6>] ? __do_fault+0x216/0x510
> > [  608.056715]  [<ffffffff814eaf74>] ? __do_page_fault+0x2b4/0x4a0
> > [  608.056720]  [<ffffffff81095c9e>] ? up_read+0x1e/0x40
> > [  608.056724]  [<ffffffff814eaf74>] ? __do_page_fault+0x2b4/0x4a0
> > [  608.056729]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
> > [  608.056733]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
> > [  608.056741]  [<ffffffff8109bb5d>] ? trace_hardirqs_on+0xd/0x10
> > [  608.056746]  [<ffffffff81051875>] ? local_bh_enable_ip+0x65/0xc0
> > [  608.056751]  [<ffffffff8140ad94>] __sys_sendmsg+0x44/0x80
> > [  608.056756]  [<ffffffff8140ade4>] SyS_sendmsg+0x14/0x20
> > [  608.056761]  [<ffffffff814ef5a2>] system_call_fastpath+0x16/0x1b
> > -------------------------------------
> > 
> > The reason is: In test_autoclose set the autoclose to 5 not 0(default). So when
> > we init the association, the (sctp_sock) sp->autoclose is not 0 while asoc's 
> > timeouts[SCTP_EVENT_TIMEOUT_AUTOCLOSE] is 0.
> > So when we process the COOKIE_ACK, the sctp_sf_do_5_1E_ca will be called, that
> > will do that:
> > 	if (asoc->autoclose) //asoc->autoclose is equal sp->autoclose
> > 		sctp_add_cmd_sf(commands, SCTP_CMD_TIMER_START,
> > 				SCTP_TO(SCTP_EVENT_TIMEOUT_AUTOCLOSE));
> 
> this looks like a bug in how the timeout is being set.  The timeout
> should be based on the association value, not some sysctl value.
> 
> The typical socket option values go like this:
>    socket value = starts at sysctl, changed by user.
>    assoc value = starts at socket value, may be changed by user.
>      any timer = starts at assoc value.
> 
> this seems to be broken for autoclose.
> 
Well, it is, but I think its a reasonable fix for the issue.  As I understand
the description, the problem is that if autoclose is non-zero, and the default
timeout is zero, then you'll get a BUG_ON halt because you need to set a timer
that will expire immediately.  It seems reasonable to me to make a minimal
default for the timeout to be non-zero, since it makes no sense to have a zero
auto-close timeout.

> 
> allowing autoclose_min = 0 might be useful to disable
> autoclose globally.  This is not a fix, but a bandaid.
> 
I'm not sure I agree here.  Doesn't a socket already default to autoclose being
zero?  That seems to obviate the need to have another global disable knob to me.
Neil

> -vlad
> --
> To unsubscribe from this list: send the line "unsubscribe linux-sctp" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> 
--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Vladislav Yasevich Dec. 3, 2013, 9:24 p.m. UTC | #4 
On 12/03/2013 01:18 PM, Neil Horman wrote:
> On Tue, Dec 03, 2013 at 11:09:38AM -0500, Vlad Yasevich wrote:
>> On 12/03/2013 05:09 AM, Wang Weidong wrote:
>>> since 2692ba61, add the max_autoclose to sysctl. when I setted the
>>> max_autoclose to 0. Just do the test_autoclose, it will trigger that:
>>>
>>> [  608.056238] ------------[ cut here ]------------
>>> [  608.056244] kernel BUG at /home/wwd/work/linux/net/sctp/sm_sideeffect.c:1488!
>>> [  608.056250] invalid opcode: 0000 [#1] SMP
>>> [  608.056254] Modules linked in: md5 sctp(O) crc32c libcrc32c edd fuse loop dm_mod ipv6 8139too sg 8139cp mii i2c_piix4 i2c_core virtio_balloon intel_agp virtio_pci virtio_ring sr_mod cdrom rtc_cmos joydev hid_generic intel_gtt virtio floppy pcspkr button ext3 jbd mbcache usbhid hid uhci_hcd ehci_hcd usbcore sd_mod usb_common crc_t10dif crct10dif_common processor thermal_sys hwmon scsi_dh_emc scsi_dh_alua scsi_dh_hp_sw scsi_dh_rdac scsi_dh ata_generic ata_piix libata scsi_mod [last unloaded: sctp]
>>> [  608.056310] CPU: 5 PID: 4517 Comm: test_autoclose Tainted: G  R        O 3.13.0-rc1-0.27-default+ #2
>>> [  608.056315] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2007
>>> [  608.056319] task: ffff8800372f5590 ti: ffff8800db882000 task.ti: ffff8800db882000
>>> [  608.056323] RIP: 0010:[<ffffffffa033e350>]  [<ffffffffa033e350>] sctp_cmd_interpreter+0x1010/0x1070 [sctp]
>>> [  608.056339] RSP: 0018:ffff880116f43928  EFLAGS: 00010246
>>> [  608.056343] RAX: 0000000000000009 RBX: ffff880116f43ab8 RCX: 0000000000000009
>>> [  608.056349] RDX: 0000000000000003 RSI: 0000000000000000 RDI: ffff880116f43a88
>>> [  608.056353] RBP: ffff880116f439d8 R08: 0000000000002029 R09: 0000000000000001
>>> [  608.056357] R10: 0000000000000000 R11: 0000000000000005 R12: ffff8800db7c9150
>>> [  608.056361] R13: 0000000000000000 R14: ffff8800db7c9000 R15: 0000000000000001
>>> [  608.056365] FS:  00007f942d71c700(0000) GS:ffff880116f40000(0000) knlGS:0000000000000000
>>> [  608.056370] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
>>> [  608.056373] CR2: 00007f942d324d90 CR3: 00000000db094000 CR4: 00000000000006e0
>>> [  608.056382] Stack:
>>> [  608.056384]  0000000000000018 ffff880116f43988 ffff8800da569600 000000010000000a
>>> [  608.056391]  ffff880037265e40 0000000016f43988 ffff880116f439e8 0000000000000000
>>> [  608.056397]  ffffffffa0365101 0000000000000000 ffff880116f43a28 ffffffff812b7739
>>> [  608.056403] Call Trace:
>>> [  608.056406]  <IRQ>
>>> [  608.056409]
>>> [  608.056421]  [<ffffffff812b7739>] ? __dynamic_pr_debug+0x69/0x80
>>> [  608.056432]  [<ffffffff81097c6d>] ? trace_hardirqs_off+0xd/0x10
>>> [  608.056442]  [<ffffffff814e7258>] ? _raw_spin_unlock_irqrestore+0x58/0x60
>>> [  608.056451]  [<ffffffffa033e3e6>] sctp_side_effects+0x36/0x130 [sctp]
>>> [  608.056459]  [<ffffffffa033e5c7>] sctp_do_sm+0xe7/0x210 [sctp]
>>> [  608.056470]  [<ffffffffa0359860>] ? sctp_rcv+0x780/0x780 [sctp]
>>> [  608.056479]  [<ffffffffa0340a5f>] sctp_endpoint_bh_rcv+0x10f/0x220 [sctp]
>>> [  608.056489]  [<ffffffffa0349991>] sctp_inq_push+0x41/0x60 [sctp]
>>> [  608.056498]  [<ffffffffa03597b5>] sctp_rcv+0x6d5/0x780 [sctp]
>>> [  608.056508]  [<ffffffffa0358e00>] ? sctp_csum_combine+0x10/0x10 [sctp]
>>> [  608.056518]  [<ffffffffa0358df0>] ? sctp_v4_err+0x240/0x240 [sctp]
>>> [  608.056528]  [<ffffffff8145b8a4>] ip_local_deliver_finish+0xf4/0x270
>>> [  608.056533]  [<ffffffff8145b7f0>] ? ip_local_deliver_finish+0x40/0x270
>>> [  608.056538]  [<ffffffff8145b690>] ip_local_deliver+0x80/0x90
>>> [  608.056543]  [<ffffffff8145bbd3>] ip_rcv_finish+0x1b3/0x600
>>> [  608.056547]  [<ffffffff8145ba20>] ? ip_local_deliver_finish+0x270/0x270
>>> [  608.056552]  [<ffffffff8145b04f>] NF_HOOK+0x2f/0x70
>>> [  608.056565]  [<ffffffff81425853>] ? __netif_receive_skb_core+0x113/0x7a0
>>> [  608.056570]  [<ffffffff8145b365>] ip_rcv+0x2d5/0x3b0
>>> [  608.056575]  [<ffffffff81425e3f>] __netif_receive_skb_core+0x6ff/0x7a0
>>> [  608.056580]  [<ffffffff81425853>] ? __netif_receive_skb_core+0x113/0x7a0
>>> [  608.056585]  [<ffffffff81426108>] ? process_backlog+0x1a8/0x1c0
>>> [  608.056590]  [<ffffffff81425f0b>] __netif_receive_skb+0x2b/0x80
>>> [  608.056595]  [<ffffffff81426018>] process_backlog+0xb8/0x1c0
>>> [  608.056600]  [<ffffffff8142695c>] net_rx_action+0x11c/0x240
>>> [  608.056607]  [<ffffffff81050e18>] __do_softirq+0x118/0x290
>>> [  608.056615]  [<ffffffff814f0e0c>] do_softirq_own_stack+0x1c/0x30
>>> [  608.056618]  <EOI>
>>> [  608.056620]
>>> [  608.056623]  [<ffffffff81050bd5>] do_softirq+0x65/0x70
>>> [  608.056629]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
>>> [  608.056635]  [<ffffffff810518c3>] local_bh_enable_ip+0xb3/0xc0
>>> [  608.056640]  [<ffffffff814e71af>] _raw_spin_unlock_bh+0x2f/0x40
>>> [  608.056645]  [<ffffffff8140fddc>] release_sock+0x8c/0xa0
>>> [  608.056654]  [<ffffffffa0354c08>] sctp_sendmsg+0x3a8/0xcc0 [sctp]
>>> [  608.056661]  [<ffffffff8129924a>] ? number+0x33a/0x360
>>> [  608.056667]  [<ffffffff81497c3c>] inet_sendmsg+0x9c/0x100
>>> [  608.056672]  [<ffffffff81497ba0>] ? inet_recvmsg+0x110/0x110
>>> [  608.056679]  [<ffffffff8140a387>] sock_sendmsg+0x97/0xc0
>>> [  608.056690]  [<ffffffff8114caae>] ? might_fault+0x3e/0x90
>>> [  608.056695]  [<ffffffff8114caae>] ? might_fault+0x3e/0x90
>>> [  608.056700]  [<ffffffff81417a73>] ? verify_iovec+0x53/0x100
>>> [  608.056705]  [<ffffffff8140abb6>] ___sys_sendmsg+0x416/0x420
>>> [  608.056710]  [<ffffffff81151af6>] ? __do_fault+0x216/0x510
>>> [  608.056715]  [<ffffffff814eaf74>] ? __do_page_fault+0x2b4/0x4a0
>>> [  608.056720]  [<ffffffff81095c9e>] ? up_read+0x1e/0x40
>>> [  608.056724]  [<ffffffff814eaf74>] ? __do_page_fault+0x2b4/0x4a0
>>> [  608.056729]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
>>> [  608.056733]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
>>> [  608.056741]  [<ffffffff8109bb5d>] ? trace_hardirqs_on+0xd/0x10
>>> [  608.056746]  [<ffffffff81051875>] ? local_bh_enable_ip+0x65/0xc0
>>> [  608.056751]  [<ffffffff8140ad94>] __sys_sendmsg+0x44/0x80
>>> [  608.056756]  [<ffffffff8140ade4>] SyS_sendmsg+0x14/0x20
>>> [  608.056761]  [<ffffffff814ef5a2>] system_call_fastpath+0x16/0x1b
>>> -------------------------------------
>>>
>>> The reason is: In test_autoclose set the autoclose to 5 not 0(default). So when
>>> we init the association, the (sctp_sock) sp->autoclose is not 0 while asoc's 
>>> timeouts[SCTP_EVENT_TIMEOUT_AUTOCLOSE] is 0.
>>> So when we process the COOKIE_ACK, the sctp_sf_do_5_1E_ca will be called, that
>>> will do that:
>>> 	if (asoc->autoclose) //asoc->autoclose is equal sp->autoclose
>>> 		sctp_add_cmd_sf(commands, SCTP_CMD_TIMER_START,
>>> 				SCTP_TO(SCTP_EVENT_TIMEOUT_AUTOCLOSE));
>>
>> this looks like a bug in how the timeout is being set.  The timeout
>> should be based on the association value, not some sysctl value.
>>
>> The typical socket option values go like this:
>>    socket value = starts at sysctl, changed by user.
>>    assoc value = starts at socket value, may be changed by user.
>>      any timer = starts at assoc value.
>>
>> this seems to be broken for autoclose.
>>
> Well, it is, but I think its a reasonable fix for the issue.  As I understand
> the description, the problem is that if autoclose is non-zero, and the default
> timeout is zero, then you'll get a BUG_ON halt because you need to set a timer
> that will expire immediately.  It seems reasonable to me to make a minimal
> default for the timeout to be non-zero, since it makes no sense to have a zero
> auto-close timeout.

Yes, the default timeout is zero because the timeout is latched by the
sysctl value while the association value is not.  So, the association
value is now out-of-sync with what the system does and we end up lying
to the user when they do a getsockopt().

If we simply latch the socket value properly, then we would have to
worry about this at all.  If the socket value is latched at 0, then
autoclose is disabled.

> 
>>
>> allowing autoclose_min = 0 might be useful to disable
>> autoclose globally.  This is not a fix, but a bandaid.
>>
> I'm not sure I agree here.  Doesn't a socket already default to autoclose being
> zero?  That seems to obviate the need to have another global disable knob to me.

This is another issue that we can discuss separately.  Simply changing
the min is only going to solve part of the problem.

-vlad

> Neil
> 
>> -vlad
>> --
>> To unsubscribe from this list: send the line "unsubscribe linux-sctp" in
>> the body of a message to majordomo@vger.kernel.org
>> More majordomo info at  http://vger.kernel.org/majordomo-info.html
>>

--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
wangweidong Dec. 4, 2013, 6:21 a.m. UTC | #5 
On 2013/12/4 5:24, Vlad Yasevich wrote:
> On 12/03/2013 01:18 PM, Neil Horman wrote:
>> On Tue, Dec 03, 2013 at 11:09:38AM -0500, Vlad Yasevich wrote:
>>> On 12/03/2013 05:09 AM, Wang Weidong wrote:
>>>> since 2692ba61, add the max_autoclose to sysctl. when I setted the
>>>> max_autoclose to 0. Just do the test_autoclose, it will trigger that:
>>>>
>>>> [  608.056238] ------------[ cut here ]------------
>>>> [  608.056244] kernel BUG at /home/wwd/work/linux/net/sctp/sm_sideeffect.c:1488!
>>>> [  608.056250] invalid opcode: 0000 [#1] SMP
>>>> [  608.056254] Modules linked in: md5 sctp(O) crc32c libcrc32c edd fuse loop dm_mod ipv6 8139too sg 8139cp mii i2c_piix4 i2c_core virtio_balloon intel_agp virtio_pci virtio_ring sr_mod cdrom rtc_cmos joydev hid_generic intel_gtt virtio floppy pcspkr button ext3 jbd mbcache usbhid hid uhci_hcd ehci_hcd usbcore sd_mod usb_common crc_t10dif crct10dif_common processor thermal_sys hwmon scsi_dh_emc scsi_dh_alua scsi_dh_hp_sw scsi_dh_rdac scsi_dh ata_generic ata_piix libata scsi_mod [last unloaded: sctp]
>>>> [  608.056310] CPU: 5 PID: 4517 Comm: test_autoclose Tainted: G  R        O 3.13.0-rc1-0.27-default+ #2
>>>> [  608.056315] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2007
>>>> [  608.056319] task: ffff8800372f5590 ti: ffff8800db882000 task.ti: ffff8800db882000
>>>> [  608.056323] RIP: 0010:[<ffffffffa033e350>]  [<ffffffffa033e350>] sctp_cmd_interpreter+0x1010/0x1070 [sctp]
>>>> [  608.056339] RSP: 0018:ffff880116f43928  EFLAGS: 00010246
>>>> [  608.056343] RAX: 0000000000000009 RBX: ffff880116f43ab8 RCX: 0000000000000009
>>>> [  608.056349] RDX: 0000000000000003 RSI: 0000000000000000 RDI: ffff880116f43a88
>>>> [  608.056353] RBP: ffff880116f439d8 R08: 0000000000002029 R09: 0000000000000001
>>>> [  608.056357] R10: 0000000000000000 R11: 0000000000000005 R12: ffff8800db7c9150
>>>> [  608.056361] R13: 0000000000000000 R14: ffff8800db7c9000 R15: 0000000000000001
>>>> [  608.056365] FS:  00007f942d71c700(0000) GS:ffff880116f40000(0000) knlGS:0000000000000000
>>>> [  608.056370] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
>>>> [  608.056373] CR2: 00007f942d324d90 CR3: 00000000db094000 CR4: 00000000000006e0
>>>> [  608.056382] Stack:
>>>> [  608.056384]  0000000000000018 ffff880116f43988 ffff8800da569600 000000010000000a
>>>> [  608.056391]  ffff880037265e40 0000000016f43988 ffff880116f439e8 0000000000000000
>>>> [  608.056397]  ffffffffa0365101 0000000000000000 ffff880116f43a28 ffffffff812b7739
>>>> [  608.056403] Call Trace:
>>>> [  608.056406]  <IRQ>
>>>> [  608.056409]
>>>> [  608.056421]  [<ffffffff812b7739>] ? __dynamic_pr_debug+0x69/0x80
>>>> [  608.056432]  [<ffffffff81097c6d>] ? trace_hardirqs_off+0xd/0x10
>>>> [  608.056442]  [<ffffffff814e7258>] ? _raw_spin_unlock_irqrestore+0x58/0x60
>>>> [  608.056451]  [<ffffffffa033e3e6>] sctp_side_effects+0x36/0x130 [sctp]
>>>> [  608.056459]  [<ffffffffa033e5c7>] sctp_do_sm+0xe7/0x210 [sctp]
>>>> [  608.056470]  [<ffffffffa0359860>] ? sctp_rcv+0x780/0x780 [sctp]
>>>> [  608.056479]  [<ffffffffa0340a5f>] sctp_endpoint_bh_rcv+0x10f/0x220 [sctp]
>>>> [  608.056489]  [<ffffffffa0349991>] sctp_inq_push+0x41/0x60 [sctp]
>>>> [  608.056498]  [<ffffffffa03597b5>] sctp_rcv+0x6d5/0x780 [sctp]
>>>> [  608.056508]  [<ffffffffa0358e00>] ? sctp_csum_combine+0x10/0x10 [sctp]
>>>> [  608.056518]  [<ffffffffa0358df0>] ? sctp_v4_err+0x240/0x240 [sctp]
>>>> [  608.056528]  [<ffffffff8145b8a4>] ip_local_deliver_finish+0xf4/0x270
>>>> [  608.056533]  [<ffffffff8145b7f0>] ? ip_local_deliver_finish+0x40/0x270
>>>> [  608.056538]  [<ffffffff8145b690>] ip_local_deliver+0x80/0x90
>>>> [  608.056543]  [<ffffffff8145bbd3>] ip_rcv_finish+0x1b3/0x600
>>>> [  608.056547]  [<ffffffff8145ba20>] ? ip_local_deliver_finish+0x270/0x270
>>>> [  608.056552]  [<ffffffff8145b04f>] NF_HOOK+0x2f/0x70
>>>> [  608.056565]  [<ffffffff81425853>] ? __netif_receive_skb_core+0x113/0x7a0
>>>> [  608.056570]  [<ffffffff8145b365>] ip_rcv+0x2d5/0x3b0
>>>> [  608.056575]  [<ffffffff81425e3f>] __netif_receive_skb_core+0x6ff/0x7a0
>>>> [  608.056580]  [<ffffffff81425853>] ? __netif_receive_skb_core+0x113/0x7a0
>>>> [  608.056585]  [<ffffffff81426108>] ? process_backlog+0x1a8/0x1c0
>>>> [  608.056590]  [<ffffffff81425f0b>] __netif_receive_skb+0x2b/0x80
>>>> [  608.056595]  [<ffffffff81426018>] process_backlog+0xb8/0x1c0
>>>> [  608.056600]  [<ffffffff8142695c>] net_rx_action+0x11c/0x240
>>>> [  608.056607]  [<ffffffff81050e18>] __do_softirq+0x118/0x290
>>>> [  608.056615]  [<ffffffff814f0e0c>] do_softirq_own_stack+0x1c/0x30
>>>> [  608.056618]  <EOI>
>>>> [  608.056620]
>>>> [  608.056623]  [<ffffffff81050bd5>] do_softirq+0x65/0x70
>>>> [  608.056629]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
>>>> [  608.056635]  [<ffffffff810518c3>] local_bh_enable_ip+0xb3/0xc0
>>>> [  608.056640]  [<ffffffff814e71af>] _raw_spin_unlock_bh+0x2f/0x40
>>>> [  608.056645]  [<ffffffff8140fddc>] release_sock+0x8c/0xa0
>>>> [  608.056654]  [<ffffffffa0354c08>] sctp_sendmsg+0x3a8/0xcc0 [sctp]
>>>> [  608.056661]  [<ffffffff8129924a>] ? number+0x33a/0x360
>>>> [  608.056667]  [<ffffffff81497c3c>] inet_sendmsg+0x9c/0x100
>>>> [  608.056672]  [<ffffffff81497ba0>] ? inet_recvmsg+0x110/0x110
>>>> [  608.056679]  [<ffffffff8140a387>] sock_sendmsg+0x97/0xc0
>>>> [  608.056690]  [<ffffffff8114caae>] ? might_fault+0x3e/0x90
>>>> [  608.056695]  [<ffffffff8114caae>] ? might_fault+0x3e/0x90
>>>> [  608.056700]  [<ffffffff81417a73>] ? verify_iovec+0x53/0x100
>>>> [  608.056705]  [<ffffffff8140abb6>] ___sys_sendmsg+0x416/0x420
>>>> [  608.056710]  [<ffffffff81151af6>] ? __do_fault+0x216/0x510
>>>> [  608.056715]  [<ffffffff814eaf74>] ? __do_page_fault+0x2b4/0x4a0
>>>> [  608.056720]  [<ffffffff81095c9e>] ? up_read+0x1e/0x40
>>>> [  608.056724]  [<ffffffff814eaf74>] ? __do_page_fault+0x2b4/0x4a0
>>>> [  608.056729]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
>>>> [  608.056733]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
>>>> [  608.056741]  [<ffffffff8109bb5d>] ? trace_hardirqs_on+0xd/0x10
>>>> [  608.056746]  [<ffffffff81051875>] ? local_bh_enable_ip+0x65/0xc0
>>>> [  608.056751]  [<ffffffff8140ad94>] __sys_sendmsg+0x44/0x80
>>>> [  608.056756]  [<ffffffff8140ade4>] SyS_sendmsg+0x14/0x20
>>>> [  608.056761]  [<ffffffff814ef5a2>] system_call_fastpath+0x16/0x1b
>>>> -------------------------------------
>>>>
>>>> The reason is: In test_autoclose set the autoclose to 5 not 0(default). So when
>>>> we init the association, the (sctp_sock) sp->autoclose is not 0 while asoc's 
>>>> timeouts[SCTP_EVENT_TIMEOUT_AUTOCLOSE] is 0.
>>>> So when we process the COOKIE_ACK, the sctp_sf_do_5_1E_ca will be called, that
>>>> will do that:
>>>> 	if (asoc->autoclose) //asoc->autoclose is equal sp->autoclose
>>>> 		sctp_add_cmd_sf(commands, SCTP_CMD_TIMER_START,
>>>> 				SCTP_TO(SCTP_EVENT_TIMEOUT_AUTOCLOSE));
>>>
>>> this looks like a bug in how the timeout is being set.  The timeout
>>> should be based on the association value, not some sysctl value.
>>>
>>> The typical socket option values go like this:
>>>    socket value = starts at sysctl, changed by user.
>>>    assoc value = starts at socket value, may be changed by user.
>>>      any timer = starts at assoc value.
>>>
>>> this seems to be broken for autoclose.
>>>
>> Well, it is, but I think its a reasonable fix for the issue.  As I understand
>> the description, the problem is that if autoclose is non-zero, and the default
>> timeout is zero, then you'll get a BUG_ON halt because you need to set a timer
>> that will expire immediately.  It seems reasonable to me to make a minimal
>> default for the timeout to be non-zero, since it makes no sense to have a zero
>> auto-close timeout.
> 
> Yes, the default timeout is zero because the timeout is latched by the
> sysctl value while the association value is not.  So, the association
> value is now out-of-sync with what the system does and we end up lying
> to the user when they do a getsockopt().
> 
> If we simply latch the socket value properly, then we would have to
> worry about this at all.  If the socket value is latched at 0, then
> autoclose is disabled.
> 
Yes, At first add the sysctl max_autoclose is to fix incorrect overflow check on
autoclose. why not we add the check in the setsockopt without the sysctl?

I am uncertain about how to fix the problem.
Do you or some other developers have stronger opinions on this?

Thanks.

>>
>>>
>>> allowing autoclose_min = 0 might be useful to disable
>>> autoclose globally.  This is not a fix, but a bandaid.
>>>
>> I'm not sure I agree here.  Doesn't a socket already default to autoclose being
>> zero?  That seems to obviate the need to have another global disable knob to me.
> 
> This is another issue that we can discuss separately.  Simply changing
> the min is only going to solve part of the problem.
> 
> -vlad
> 
>> Neil
>>
>>> -vlad
>>> --
>>> To unsubscribe from this list: send the line "unsubscribe linux-sctp" in
>>> the body of a message to majordomo@vger.kernel.org
>>> More majordomo info at  http://vger.kernel.org/majordomo-info.html
>>>
> 
> 
> .
> 


--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Neil Horman Dec. 4, 2013, 1:28 p.m. UTC | #6 
On Tue, Dec 03, 2013 at 04:24:10PM -0500, Vlad Yasevich wrote:
> On 12/03/2013 01:18 PM, Neil Horman wrote:
> > On Tue, Dec 03, 2013 at 11:09:38AM -0500, Vlad Yasevich wrote:
> >> On 12/03/2013 05:09 AM, Wang Weidong wrote:
> >>> since 2692ba61, add the max_autoclose to sysctl. when I setted the
> >>> max_autoclose to 0. Just do the test_autoclose, it will trigger that:
> >>>
> >>> [  608.056238] ------------[ cut here ]------------
> >>> [  608.056244] kernel BUG at /home/wwd/work/linux/net/sctp/sm_sideeffect.c:1488!
> >>> [  608.056250] invalid opcode: 0000 [#1] SMP
> >>> [  608.056254] Modules linked in: md5 sctp(O) crc32c libcrc32c edd fuse loop dm_mod ipv6 8139too sg 8139cp mii i2c_piix4 i2c_core virtio_balloon intel_agp virtio_pci virtio_ring sr_mod cdrom rtc_cmos joydev hid_generic intel_gtt virtio floppy pcspkr button ext3 jbd mbcache usbhid hid uhci_hcd ehci_hcd usbcore sd_mod usb_common crc_t10dif crct10dif_common processor thermal_sys hwmon scsi_dh_emc scsi_dh_alua scsi_dh_hp_sw scsi_dh_rdac scsi_dh ata_generic ata_piix libata scsi_mod [last unloaded: sctp]
> >>> [  608.056310] CPU: 5 PID: 4517 Comm: test_autoclose Tainted: G  R        O 3.13.0-rc1-0.27-default+ #2
> >>> [  608.056315] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2007
> >>> [  608.056319] task: ffff8800372f5590 ti: ffff8800db882000 task.ti: ffff8800db882000
> >>> [  608.056323] RIP: 0010:[<ffffffffa033e350>]  [<ffffffffa033e350>] sctp_cmd_interpreter+0x1010/0x1070 [sctp]
> >>> [  608.056339] RSP: 0018:ffff880116f43928  EFLAGS: 00010246
> >>> [  608.056343] RAX: 0000000000000009 RBX: ffff880116f43ab8 RCX: 0000000000000009
> >>> [  608.056349] RDX: 0000000000000003 RSI: 0000000000000000 RDI: ffff880116f43a88
> >>> [  608.056353] RBP: ffff880116f439d8 R08: 0000000000002029 R09: 0000000000000001
> >>> [  608.056357] R10: 0000000000000000 R11: 0000000000000005 R12: ffff8800db7c9150
> >>> [  608.056361] R13: 0000000000000000 R14: ffff8800db7c9000 R15: 0000000000000001
> >>> [  608.056365] FS:  00007f942d71c700(0000) GS:ffff880116f40000(0000) knlGS:0000000000000000
> >>> [  608.056370] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
> >>> [  608.056373] CR2: 00007f942d324d90 CR3: 00000000db094000 CR4: 00000000000006e0
> >>> [  608.056382] Stack:
> >>> [  608.056384]  0000000000000018 ffff880116f43988 ffff8800da569600 000000010000000a
> >>> [  608.056391]  ffff880037265e40 0000000016f43988 ffff880116f439e8 0000000000000000
> >>> [  608.056397]  ffffffffa0365101 0000000000000000 ffff880116f43a28 ffffffff812b7739
> >>> [  608.056403] Call Trace:
> >>> [  608.056406]  <IRQ>
> >>> [  608.056409]
> >>> [  608.056421]  [<ffffffff812b7739>] ? __dynamic_pr_debug+0x69/0x80
> >>> [  608.056432]  [<ffffffff81097c6d>] ? trace_hardirqs_off+0xd/0x10
> >>> [  608.056442]  [<ffffffff814e7258>] ? _raw_spin_unlock_irqrestore+0x58/0x60
> >>> [  608.056451]  [<ffffffffa033e3e6>] sctp_side_effects+0x36/0x130 [sctp]
> >>> [  608.056459]  [<ffffffffa033e5c7>] sctp_do_sm+0xe7/0x210 [sctp]
> >>> [  608.056470]  [<ffffffffa0359860>] ? sctp_rcv+0x780/0x780 [sctp]
> >>> [  608.056479]  [<ffffffffa0340a5f>] sctp_endpoint_bh_rcv+0x10f/0x220 [sctp]
> >>> [  608.056489]  [<ffffffffa0349991>] sctp_inq_push+0x41/0x60 [sctp]
> >>> [  608.056498]  [<ffffffffa03597b5>] sctp_rcv+0x6d5/0x780 [sctp]
> >>> [  608.056508]  [<ffffffffa0358e00>] ? sctp_csum_combine+0x10/0x10 [sctp]
> >>> [  608.056518]  [<ffffffffa0358df0>] ? sctp_v4_err+0x240/0x240 [sctp]
> >>> [  608.056528]  [<ffffffff8145b8a4>] ip_local_deliver_finish+0xf4/0x270
> >>> [  608.056533]  [<ffffffff8145b7f0>] ? ip_local_deliver_finish+0x40/0x270
> >>> [  608.056538]  [<ffffffff8145b690>] ip_local_deliver+0x80/0x90
> >>> [  608.056543]  [<ffffffff8145bbd3>] ip_rcv_finish+0x1b3/0x600
> >>> [  608.056547]  [<ffffffff8145ba20>] ? ip_local_deliver_finish+0x270/0x270
> >>> [  608.056552]  [<ffffffff8145b04f>] NF_HOOK+0x2f/0x70
> >>> [  608.056565]  [<ffffffff81425853>] ? __netif_receive_skb_core+0x113/0x7a0
> >>> [  608.056570]  [<ffffffff8145b365>] ip_rcv+0x2d5/0x3b0
> >>> [  608.056575]  [<ffffffff81425e3f>] __netif_receive_skb_core+0x6ff/0x7a0
> >>> [  608.056580]  [<ffffffff81425853>] ? __netif_receive_skb_core+0x113/0x7a0
> >>> [  608.056585]  [<ffffffff81426108>] ? process_backlog+0x1a8/0x1c0
> >>> [  608.056590]  [<ffffffff81425f0b>] __netif_receive_skb+0x2b/0x80
> >>> [  608.056595]  [<ffffffff81426018>] process_backlog+0xb8/0x1c0
> >>> [  608.056600]  [<ffffffff8142695c>] net_rx_action+0x11c/0x240
> >>> [  608.056607]  [<ffffffff81050e18>] __do_softirq+0x118/0x290
> >>> [  608.056615]  [<ffffffff814f0e0c>] do_softirq_own_stack+0x1c/0x30
> >>> [  608.056618]  <EOI>
> >>> [  608.056620]
> >>> [  608.056623]  [<ffffffff81050bd5>] do_softirq+0x65/0x70
> >>> [  608.056629]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
> >>> [  608.056635]  [<ffffffff810518c3>] local_bh_enable_ip+0xb3/0xc0
> >>> [  608.056640]  [<ffffffff814e71af>] _raw_spin_unlock_bh+0x2f/0x40
> >>> [  608.056645]  [<ffffffff8140fddc>] release_sock+0x8c/0xa0
> >>> [  608.056654]  [<ffffffffa0354c08>] sctp_sendmsg+0x3a8/0xcc0 [sctp]
> >>> [  608.056661]  [<ffffffff8129924a>] ? number+0x33a/0x360
> >>> [  608.056667]  [<ffffffff81497c3c>] inet_sendmsg+0x9c/0x100
> >>> [  608.056672]  [<ffffffff81497ba0>] ? inet_recvmsg+0x110/0x110
> >>> [  608.056679]  [<ffffffff8140a387>] sock_sendmsg+0x97/0xc0
> >>> [  608.056690]  [<ffffffff8114caae>] ? might_fault+0x3e/0x90
> >>> [  608.056695]  [<ffffffff8114caae>] ? might_fault+0x3e/0x90
> >>> [  608.056700]  [<ffffffff81417a73>] ? verify_iovec+0x53/0x100
> >>> [  608.056705]  [<ffffffff8140abb6>] ___sys_sendmsg+0x416/0x420
> >>> [  608.056710]  [<ffffffff81151af6>] ? __do_fault+0x216/0x510
> >>> [  608.056715]  [<ffffffff814eaf74>] ? __do_page_fault+0x2b4/0x4a0
> >>> [  608.056720]  [<ffffffff81095c9e>] ? up_read+0x1e/0x40
> >>> [  608.056724]  [<ffffffff814eaf74>] ? __do_page_fault+0x2b4/0x4a0
> >>> [  608.056729]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
> >>> [  608.056733]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
> >>> [  608.056741]  [<ffffffff8109bb5d>] ? trace_hardirqs_on+0xd/0x10
> >>> [  608.056746]  [<ffffffff81051875>] ? local_bh_enable_ip+0x65/0xc0
> >>> [  608.056751]  [<ffffffff8140ad94>] __sys_sendmsg+0x44/0x80
> >>> [  608.056756]  [<ffffffff8140ade4>] SyS_sendmsg+0x14/0x20
> >>> [  608.056761]  [<ffffffff814ef5a2>] system_call_fastpath+0x16/0x1b
> >>> -------------------------------------
> >>>
> >>> The reason is: In test_autoclose set the autoclose to 5 not 0(default). So when
> >>> we init the association, the (sctp_sock) sp->autoclose is not 0 while asoc's 
> >>> timeouts[SCTP_EVENT_TIMEOUT_AUTOCLOSE] is 0.
> >>> So when we process the COOKIE_ACK, the sctp_sf_do_5_1E_ca will be called, that
> >>> will do that:
> >>> 	if (asoc->autoclose) //asoc->autoclose is equal sp->autoclose
> >>> 		sctp_add_cmd_sf(commands, SCTP_CMD_TIMER_START,
> >>> 				SCTP_TO(SCTP_EVENT_TIMEOUT_AUTOCLOSE));
> >>
> >> this looks like a bug in how the timeout is being set.  The timeout
> >> should be based on the association value, not some sysctl value.
> >>
> >> The typical socket option values go like this:
> >>    socket value = starts at sysctl, changed by user.
> >>    assoc value = starts at socket value, may be changed by user.
> >>      any timer = starts at assoc value.
> >>
> >> this seems to be broken for autoclose.
> >>
> > Well, it is, but I think its a reasonable fix for the issue.  As I understand
> > the description, the problem is that if autoclose is non-zero, and the default
> > timeout is zero, then you'll get a BUG_ON halt because you need to set a timer
> > that will expire immediately.  It seems reasonable to me to make a minimal
> > default for the timeout to be non-zero, since it makes no sense to have a zero
> > auto-close timeout.
> 
> Yes, the default timeout is zero because the timeout is latched by the
> sysctl value while the association value is not.  So, the association
> value is now out-of-sync with what the system does and we end up lying
> to the user when they do a getsockopt().
> 
Thats not true, looking at the sctp_association_init code the timeout is
defaulted to the minimum of the socket value and the maxium timeout sysctl
value, the latter of which is defined as INT_MAX/HZ.  That seems reasonable to
me in that an association latches both the timeout value and the enabled value
from its parent socket at association init time (assoc->autoclose is assigned
from sp->autoclose farther down in sctp_association_init).

> If we simply latch the socket value properly, then we would have to
> worry about this at all.  If the socket value is latched at 0, then
> autoclose is disabled.
> 
We are latching the value properly from what I can see.  The problem is that the
upper bound on the value we latch can be zero.  The only way this bug can occur
is if net->sctp.max_autoclose is 0.  Note that I'm not talking about the timeout
value itself, but its upper bound.  We shouldn't be allowed to set the autoclose
timeout sysctl range to [0..0], it just doesn't make sense.  It should be at
least [0..1], and the socket autoclose value can range properly within that.
From what I see, thats what this patch does.

Neil
--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Vladislav Yasevich Dec. 4, 2013, 2:45 p.m. UTC | #7 
On 12/04/2013 08:28 AM, Neil Horman wrote:
> On Tue, Dec 03, 2013 at 04:24:10PM -0500, Vlad Yasevich wrote:
>> On 12/03/2013 01:18 PM, Neil Horman wrote:
>>> On Tue, Dec 03, 2013 at 11:09:38AM -0500, Vlad Yasevich wrote:
>>>> On 12/03/2013 05:09 AM, Wang Weidong wrote:
>>>>> since 2692ba61, add the max_autoclose to sysctl. when I setted the
>>>>> max_autoclose to 0. Just do the test_autoclose, it will trigger that:
>>>>>
>>>>> [  608.056238] ------------[ cut here ]------------
>>>>> [  608.056244] kernel BUG at /home/wwd/work/linux/net/sctp/sm_sideeffect.c:1488!
>>>>> [  608.056250] invalid opcode: 0000 [#1] SMP
>>>>> [  608.056254] Modules linked in: md5 sctp(O) crc32c libcrc32c edd fuse loop dm_mod ipv6 8139too sg 8139cp mii i2c_piix4 i2c_core virtio_balloon intel_agp virtio_pci virtio_ring sr_mod cdrom rtc_cmos joydev hid_generic intel_gtt virtio floppy pcspkr button ext3 jbd mbcache usbhid hid uhci_hcd ehci_hcd usbcore sd_mod usb_common crc_t10dif crct10dif_common processor thermal_sys hwmon scsi_dh_emc scsi_dh_alua scsi_dh_hp_sw scsi_dh_rdac scsi_dh ata_generic ata_piix libata scsi_mod [last unloaded: sctp]
>>>>> [  608.056310] CPU: 5 PID: 4517 Comm: test_autoclose Tainted: G  R        O 3.13.0-rc1-0.27-default+ #2
>>>>> [  608.056315] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2007
>>>>> [  608.056319] task: ffff8800372f5590 ti: ffff8800db882000 task.ti: ffff8800db882000
>>>>> [  608.056323] RIP: 0010:[<ffffffffa033e350>]  [<ffffffffa033e350>] sctp_cmd_interpreter+0x1010/0x1070 [sctp]
>>>>> [  608.056339] RSP: 0018:ffff880116f43928  EFLAGS: 00010246
>>>>> [  608.056343] RAX: 0000000000000009 RBX: ffff880116f43ab8 RCX: 0000000000000009
>>>>> [  608.056349] RDX: 0000000000000003 RSI: 0000000000000000 RDI: ffff880116f43a88
>>>>> [  608.056353] RBP: ffff880116f439d8 R08: 0000000000002029 R09: 0000000000000001
>>>>> [  608.056357] R10: 0000000000000000 R11: 0000000000000005 R12: ffff8800db7c9150
>>>>> [  608.056361] R13: 0000000000000000 R14: ffff8800db7c9000 R15: 0000000000000001
>>>>> [  608.056365] FS:  00007f942d71c700(0000) GS:ffff880116f40000(0000) knlGS:0000000000000000
>>>>> [  608.056370] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
>>>>> [  608.056373] CR2: 00007f942d324d90 CR3: 00000000db094000 CR4: 00000000000006e0
>>>>> [  608.056382] Stack:
>>>>> [  608.056384]  0000000000000018 ffff880116f43988 ffff8800da569600 000000010000000a
>>>>> [  608.056391]  ffff880037265e40 0000000016f43988 ffff880116f439e8 0000000000000000
>>>>> [  608.056397]  ffffffffa0365101 0000000000000000 ffff880116f43a28 ffffffff812b7739
>>>>> [  608.056403] Call Trace:
>>>>> [  608.056406]  <IRQ>
>>>>> [  608.056409]
>>>>> [  608.056421]  [<ffffffff812b7739>] ? __dynamic_pr_debug+0x69/0x80
>>>>> [  608.056432]  [<ffffffff81097c6d>] ? trace_hardirqs_off+0xd/0x10
>>>>> [  608.056442]  [<ffffffff814e7258>] ? _raw_spin_unlock_irqrestore+0x58/0x60
>>>>> [  608.056451]  [<ffffffffa033e3e6>] sctp_side_effects+0x36/0x130 [sctp]
>>>>> [  608.056459]  [<ffffffffa033e5c7>] sctp_do_sm+0xe7/0x210 [sctp]
>>>>> [  608.056470]  [<ffffffffa0359860>] ? sctp_rcv+0x780/0x780 [sctp]
>>>>> [  608.056479]  [<ffffffffa0340a5f>] sctp_endpoint_bh_rcv+0x10f/0x220 [sctp]
>>>>> [  608.056489]  [<ffffffffa0349991>] sctp_inq_push+0x41/0x60 [sctp]
>>>>> [  608.056498]  [<ffffffffa03597b5>] sctp_rcv+0x6d5/0x780 [sctp]
>>>>> [  608.056508]  [<ffffffffa0358e00>] ? sctp_csum_combine+0x10/0x10 [sctp]
>>>>> [  608.056518]  [<ffffffffa0358df0>] ? sctp_v4_err+0x240/0x240 [sctp]
>>>>> [  608.056528]  [<ffffffff8145b8a4>] ip_local_deliver_finish+0xf4/0x270
>>>>> [  608.056533]  [<ffffffff8145b7f0>] ? ip_local_deliver_finish+0x40/0x270
>>>>> [  608.056538]  [<ffffffff8145b690>] ip_local_deliver+0x80/0x90
>>>>> [  608.056543]  [<ffffffff8145bbd3>] ip_rcv_finish+0x1b3/0x600
>>>>> [  608.056547]  [<ffffffff8145ba20>] ? ip_local_deliver_finish+0x270/0x270
>>>>> [  608.056552]  [<ffffffff8145b04f>] NF_HOOK+0x2f/0x70
>>>>> [  608.056565]  [<ffffffff81425853>] ? __netif_receive_skb_core+0x113/0x7a0
>>>>> [  608.056570]  [<ffffffff8145b365>] ip_rcv+0x2d5/0x3b0
>>>>> [  608.056575]  [<ffffffff81425e3f>] __netif_receive_skb_core+0x6ff/0x7a0
>>>>> [  608.056580]  [<ffffffff81425853>] ? __netif_receive_skb_core+0x113/0x7a0
>>>>> [  608.056585]  [<ffffffff81426108>] ? process_backlog+0x1a8/0x1c0
>>>>> [  608.056590]  [<ffffffff81425f0b>] __netif_receive_skb+0x2b/0x80
>>>>> [  608.056595]  [<ffffffff81426018>] process_backlog+0xb8/0x1c0
>>>>> [  608.056600]  [<ffffffff8142695c>] net_rx_action+0x11c/0x240
>>>>> [  608.056607]  [<ffffffff81050e18>] __do_softirq+0x118/0x290
>>>>> [  608.056615]  [<ffffffff814f0e0c>] do_softirq_own_stack+0x1c/0x30
>>>>> [  608.056618]  <EOI>
>>>>> [  608.056620]
>>>>> [  608.056623]  [<ffffffff81050bd5>] do_softirq+0x65/0x70
>>>>> [  608.056629]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
>>>>> [  608.056635]  [<ffffffff810518c3>] local_bh_enable_ip+0xb3/0xc0
>>>>> [  608.056640]  [<ffffffff814e71af>] _raw_spin_unlock_bh+0x2f/0x40
>>>>> [  608.056645]  [<ffffffff8140fddc>] release_sock+0x8c/0xa0
>>>>> [  608.056654]  [<ffffffffa0354c08>] sctp_sendmsg+0x3a8/0xcc0 [sctp]
>>>>> [  608.056661]  [<ffffffff8129924a>] ? number+0x33a/0x360
>>>>> [  608.056667]  [<ffffffff81497c3c>] inet_sendmsg+0x9c/0x100
>>>>> [  608.056672]  [<ffffffff81497ba0>] ? inet_recvmsg+0x110/0x110
>>>>> [  608.056679]  [<ffffffff8140a387>] sock_sendmsg+0x97/0xc0
>>>>> [  608.056690]  [<ffffffff8114caae>] ? might_fault+0x3e/0x90
>>>>> [  608.056695]  [<ffffffff8114caae>] ? might_fault+0x3e/0x90
>>>>> [  608.056700]  [<ffffffff81417a73>] ? verify_iovec+0x53/0x100
>>>>> [  608.056705]  [<ffffffff8140abb6>] ___sys_sendmsg+0x416/0x420
>>>>> [  608.056710]  [<ffffffff81151af6>] ? __do_fault+0x216/0x510
>>>>> [  608.056715]  [<ffffffff814eaf74>] ? __do_page_fault+0x2b4/0x4a0
>>>>> [  608.056720]  [<ffffffff81095c9e>] ? up_read+0x1e/0x40
>>>>> [  608.056724]  [<ffffffff814eaf74>] ? __do_page_fault+0x2b4/0x4a0
>>>>> [  608.056729]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
>>>>> [  608.056733]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
>>>>> [  608.056741]  [<ffffffff8109bb5d>] ? trace_hardirqs_on+0xd/0x10
>>>>> [  608.056746]  [<ffffffff81051875>] ? local_bh_enable_ip+0x65/0xc0
>>>>> [  608.056751]  [<ffffffff8140ad94>] __sys_sendmsg+0x44/0x80
>>>>> [  608.056756]  [<ffffffff8140ade4>] SyS_sendmsg+0x14/0x20
>>>>> [  608.056761]  [<ffffffff814ef5a2>] system_call_fastpath+0x16/0x1b
>>>>> -------------------------------------
>>>>>
>>>>> The reason is: In test_autoclose set the autoclose to 5 not 0(default). So when
>>>>> we init the association, the (sctp_sock) sp->autoclose is not 0 while asoc's 
>>>>> timeouts[SCTP_EVENT_TIMEOUT_AUTOCLOSE] is 0.
>>>>> So when we process the COOKIE_ACK, the sctp_sf_do_5_1E_ca will be called, that
>>>>> will do that:
>>>>> 	if (asoc->autoclose) //asoc->autoclose is equal sp->autoclose
>>>>> 		sctp_add_cmd_sf(commands, SCTP_CMD_TIMER_START,
>>>>> 				SCTP_TO(SCTP_EVENT_TIMEOUT_AUTOCLOSE));
>>>>
>>>> this looks like a bug in how the timeout is being set.  The timeout
>>>> should be based on the association value, not some sysctl value.
>>>>
>>>> The typical socket option values go like this:
>>>>    socket value = starts at sysctl, changed by user.
>>>>    assoc value = starts at socket value, may be changed by user.
>>>>      any timer = starts at assoc value.
>>>>
>>>> this seems to be broken for autoclose.
>>>>
>>> Well, it is, but I think its a reasonable fix for the issue.  As I understand
>>> the description, the problem is that if autoclose is non-zero, and the default
>>> timeout is zero, then you'll get a BUG_ON halt because you need to set a timer
>>> that will expire immediately.  It seems reasonable to me to make a minimal
>>> default for the timeout to be non-zero, since it makes no sense to have a zero
>>> auto-close timeout.
>>
>> Yes, the default timeout is zero because the timeout is latched by the
>> sysctl value while the association value is not.  So, the association
>> value is now out-of-sync with what the system does and we end up lying
>> to the user when they do a getsockopt().
>>
> Thats not true, looking at the sctp_association_init code the timeout is
> defaulted to the minimum of the socket value and the maxium timeout sysctl
> value, the latter of which is defined as INT_MAX/HZ.  That seems reasonable to
> me in that an association latches both the timeout value and the enabled value
> from its parent socket at association init time (assoc->autoclose is assigned
> from sp->autoclose farther down in sctp_association_init).

Right, so let's see what happens.  Let the sysctl value be set to 1.
The the socket is created and the option is used to set the value to 10.
Now, association is created and the timeout is latched to 1.
However, the autoclose value of the association is set to 10.  So now
we are lying to the user about our autoclose value!

This is what's causing the problem.  The timeout value is out of sync
what what the requested timeout value is.

Now, if we latch the socket value correctly, then everything just starts
to work, even for sysctl value of 0, and we stop lying to the user on
getsockopt() calls.  This is the real bug that causing the BUG_ON.

> 
>> If we simply latch the socket value properly, then we would have to
>> worry about this at all.  If the socket value is latched at 0, then
>> autoclose is disabled.
>>
> We are latching the value properly from what I can see.  The problem is that the
> upper bound on the value we latch can be zero.  The only way this bug can occur
> is if net->sctp.max_autoclose is 0.  Note that I'm not talking about the timeout
> value itself, but its upper bound.  We shouldn't be allowed to set the autoclose
> timeout sysctl range to [0..0], it just doesn't make sense.  It should be at
> least [0..1], and the socket autoclose value can range properly within that.
> From what I see, thats what this patch does.

We don't allow the sysctl range of [0..0].  We allow the range of
[0..max_autoclose_max].  This patch tries to change the range to
[1..max_autoclose_max].  This may be a correct thing to do,
but it is another issue.  That fact this change fixes the BUG_ON is
a side-effect.  The real issue is in how we set set the timer value.

-vlad

> 
> Neil
> 

--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Neil Horman Dec. 4, 2013, 6:56 p.m. UTC | #8 
On Wed, Dec 04, 2013 at 09:45:59AM -0500, Vlad Yasevich wrote:
> On 12/04/2013 08:28 AM, Neil Horman wrote:
> > On Tue, Dec 03, 2013 at 04:24:10PM -0500, Vlad Yasevich wrote:
> >> On 12/03/2013 01:18 PM, Neil Horman wrote:
> >>> On Tue, Dec 03, 2013 at 11:09:38AM -0500, Vlad Yasevich wrote:
> >>>> On 12/03/2013 05:09 AM, Wang Weidong wrote:
> >>>>> since 2692ba61, add the max_autoclose to sysctl. when I setted the
> >>>>> max_autoclose to 0. Just do the test_autoclose, it will trigger that:
> >>>>>
> >>>>> [  608.056238] ------------[ cut here ]------------
> >>>>> [  608.056244] kernel BUG at /home/wwd/work/linux/net/sctp/sm_sideeffect.c:1488!
> >>>>> [  608.056250] invalid opcode: 0000 [#1] SMP
> >>>>> [  608.056254] Modules linked in: md5 sctp(O) crc32c libcrc32c edd fuse loop dm_mod ipv6 8139too sg 8139cp mii i2c_piix4 i2c_core virtio_balloon intel_agp virtio_pci virtio_ring sr_mod cdrom rtc_cmos joydev hid_generic intel_gtt virtio floppy pcspkr button ext3 jbd mbcache usbhid hid uhci_hcd ehci_hcd usbcore sd_mod usb_common crc_t10dif crct10dif_common processor thermal_sys hwmon scsi_dh_emc scsi_dh_alua scsi_dh_hp_sw scsi_dh_rdac scsi_dh ata_generic ata_piix libata scsi_mod [last unloaded: sctp]
> >>>>> [  608.056310] CPU: 5 PID: 4517 Comm: test_autoclose Tainted: G  R        O 3.13.0-rc1-0.27-default+ #2
> >>>>> [  608.056315] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2007
> >>>>> [  608.056319] task: ffff8800372f5590 ti: ffff8800db882000 task.ti: ffff8800db882000
> >>>>> [  608.056323] RIP: 0010:[<ffffffffa033e350>]  [<ffffffffa033e350>] sctp_cmd_interpreter+0x1010/0x1070 [sctp]
> >>>>> [  608.056339] RSP: 0018:ffff880116f43928  EFLAGS: 00010246
> >>>>> [  608.056343] RAX: 0000000000000009 RBX: ffff880116f43ab8 RCX: 0000000000000009
> >>>>> [  608.056349] RDX: 0000000000000003 RSI: 0000000000000000 RDI: ffff880116f43a88
> >>>>> [  608.056353] RBP: ffff880116f439d8 R08: 0000000000002029 R09: 0000000000000001
> >>>>> [  608.056357] R10: 0000000000000000 R11: 0000000000000005 R12: ffff8800db7c9150
> >>>>> [  608.056361] R13: 0000000000000000 R14: ffff8800db7c9000 R15: 0000000000000001
> >>>>> [  608.056365] FS:  00007f942d71c700(0000) GS:ffff880116f40000(0000) knlGS:0000000000000000
> >>>>> [  608.056370] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
> >>>>> [  608.056373] CR2: 00007f942d324d90 CR3: 00000000db094000 CR4: 00000000000006e0
> >>>>> [  608.056382] Stack:
> >>>>> [  608.056384]  0000000000000018 ffff880116f43988 ffff8800da569600 000000010000000a
> >>>>> [  608.056391]  ffff880037265e40 0000000016f43988 ffff880116f439e8 0000000000000000
> >>>>> [  608.056397]  ffffffffa0365101 0000000000000000 ffff880116f43a28 ffffffff812b7739
> >>>>> [  608.056403] Call Trace:
> >>>>> [  608.056406]  <IRQ>
> >>>>> [  608.056409]
> >>>>> [  608.056421]  [<ffffffff812b7739>] ? __dynamic_pr_debug+0x69/0x80
> >>>>> [  608.056432]  [<ffffffff81097c6d>] ? trace_hardirqs_off+0xd/0x10
> >>>>> [  608.056442]  [<ffffffff814e7258>] ? _raw_spin_unlock_irqrestore+0x58/0x60
> >>>>> [  608.056451]  [<ffffffffa033e3e6>] sctp_side_effects+0x36/0x130 [sctp]
> >>>>> [  608.056459]  [<ffffffffa033e5c7>] sctp_do_sm+0xe7/0x210 [sctp]
> >>>>> [  608.056470]  [<ffffffffa0359860>] ? sctp_rcv+0x780/0x780 [sctp]
> >>>>> [  608.056479]  [<ffffffffa0340a5f>] sctp_endpoint_bh_rcv+0x10f/0x220 [sctp]
> >>>>> [  608.056489]  [<ffffffffa0349991>] sctp_inq_push+0x41/0x60 [sctp]
> >>>>> [  608.056498]  [<ffffffffa03597b5>] sctp_rcv+0x6d5/0x780 [sctp]
> >>>>> [  608.056508]  [<ffffffffa0358e00>] ? sctp_csum_combine+0x10/0x10 [sctp]
> >>>>> [  608.056518]  [<ffffffffa0358df0>] ? sctp_v4_err+0x240/0x240 [sctp]
> >>>>> [  608.056528]  [<ffffffff8145b8a4>] ip_local_deliver_finish+0xf4/0x270
> >>>>> [  608.056533]  [<ffffffff8145b7f0>] ? ip_local_deliver_finish+0x40/0x270
> >>>>> [  608.056538]  [<ffffffff8145b690>] ip_local_deliver+0x80/0x90
> >>>>> [  608.056543]  [<ffffffff8145bbd3>] ip_rcv_finish+0x1b3/0x600
> >>>>> [  608.056547]  [<ffffffff8145ba20>] ? ip_local_deliver_finish+0x270/0x270
> >>>>> [  608.056552]  [<ffffffff8145b04f>] NF_HOOK+0x2f/0x70
> >>>>> [  608.056565]  [<ffffffff81425853>] ? __netif_receive_skb_core+0x113/0x7a0
> >>>>> [  608.056570]  [<ffffffff8145b365>] ip_rcv+0x2d5/0x3b0
> >>>>> [  608.056575]  [<ffffffff81425e3f>] __netif_receive_skb_core+0x6ff/0x7a0
> >>>>> [  608.056580]  [<ffffffff81425853>] ? __netif_receive_skb_core+0x113/0x7a0
> >>>>> [  608.056585]  [<ffffffff81426108>] ? process_backlog+0x1a8/0x1c0
> >>>>> [  608.056590]  [<ffffffff81425f0b>] __netif_receive_skb+0x2b/0x80
> >>>>> [  608.056595]  [<ffffffff81426018>] process_backlog+0xb8/0x1c0
> >>>>> [  608.056600]  [<ffffffff8142695c>] net_rx_action+0x11c/0x240
> >>>>> [  608.056607]  [<ffffffff81050e18>] __do_softirq+0x118/0x290
> >>>>> [  608.056615]  [<ffffffff814f0e0c>] do_softirq_own_stack+0x1c/0x30
> >>>>> [  608.056618]  <EOI>
> >>>>> [  608.056620]
> >>>>> [  608.056623]  [<ffffffff81050bd5>] do_softirq+0x65/0x70
> >>>>> [  608.056629]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
> >>>>> [  608.056635]  [<ffffffff810518c3>] local_bh_enable_ip+0xb3/0xc0
> >>>>> [  608.056640]  [<ffffffff814e71af>] _raw_spin_unlock_bh+0x2f/0x40
> >>>>> [  608.056645]  [<ffffffff8140fddc>] release_sock+0x8c/0xa0
> >>>>> [  608.056654]  [<ffffffffa0354c08>] sctp_sendmsg+0x3a8/0xcc0 [sctp]
> >>>>> [  608.056661]  [<ffffffff8129924a>] ? number+0x33a/0x360
> >>>>> [  608.056667]  [<ffffffff81497c3c>] inet_sendmsg+0x9c/0x100
> >>>>> [  608.056672]  [<ffffffff81497ba0>] ? inet_recvmsg+0x110/0x110
> >>>>> [  608.056679]  [<ffffffff8140a387>] sock_sendmsg+0x97/0xc0
> >>>>> [  608.056690]  [<ffffffff8114caae>] ? might_fault+0x3e/0x90
> >>>>> [  608.056695]  [<ffffffff8114caae>] ? might_fault+0x3e/0x90
> >>>>> [  608.056700]  [<ffffffff81417a73>] ? verify_iovec+0x53/0x100
> >>>>> [  608.056705]  [<ffffffff8140abb6>] ___sys_sendmsg+0x416/0x420
> >>>>> [  608.056710]  [<ffffffff81151af6>] ? __do_fault+0x216/0x510
> >>>>> [  608.056715]  [<ffffffff814eaf74>] ? __do_page_fault+0x2b4/0x4a0
> >>>>> [  608.056720]  [<ffffffff81095c9e>] ? up_read+0x1e/0x40
> >>>>> [  608.056724]  [<ffffffff814eaf74>] ? __do_page_fault+0x2b4/0x4a0
> >>>>> [  608.056729]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
> >>>>> [  608.056733]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
> >>>>> [  608.056741]  [<ffffffff8109bb5d>] ? trace_hardirqs_on+0xd/0x10
> >>>>> [  608.056746]  [<ffffffff81051875>] ? local_bh_enable_ip+0x65/0xc0
> >>>>> [  608.056751]  [<ffffffff8140ad94>] __sys_sendmsg+0x44/0x80
> >>>>> [  608.056756]  [<ffffffff8140ade4>] SyS_sendmsg+0x14/0x20
> >>>>> [  608.056761]  [<ffffffff814ef5a2>] system_call_fastpath+0x16/0x1b
> >>>>> -------------------------------------
> >>>>>
> >>>>> The reason is: In test_autoclose set the autoclose to 5 not 0(default). So when
> >>>>> we init the association, the (sctp_sock) sp->autoclose is not 0 while asoc's 
> >>>>> timeouts[SCTP_EVENT_TIMEOUT_AUTOCLOSE] is 0.
> >>>>> So when we process the COOKIE_ACK, the sctp_sf_do_5_1E_ca will be called, that
> >>>>> will do that:
> >>>>> 	if (asoc->autoclose) //asoc->autoclose is equal sp->autoclose
> >>>>> 		sctp_add_cmd_sf(commands, SCTP_CMD_TIMER_START,
> >>>>> 				SCTP_TO(SCTP_EVENT_TIMEOUT_AUTOCLOSE));
> >>>>
> >>>> this looks like a bug in how the timeout is being set.  The timeout
> >>>> should be based on the association value, not some sysctl value.
> >>>>
> >>>> The typical socket option values go like this:
> >>>>    socket value = starts at sysctl, changed by user.
> >>>>    assoc value = starts at socket value, may be changed by user.
> >>>>      any timer = starts at assoc value.
> >>>>
> >>>> this seems to be broken for autoclose.
> >>>>
> >>> Well, it is, but I think its a reasonable fix for the issue.  As I understand
> >>> the description, the problem is that if autoclose is non-zero, and the default
> >>> timeout is zero, then you'll get a BUG_ON halt because you need to set a timer
> >>> that will expire immediately.  It seems reasonable to me to make a minimal
> >>> default for the timeout to be non-zero, since it makes no sense to have a zero
> >>> auto-close timeout.
> >>
> >> Yes, the default timeout is zero because the timeout is latched by the
> >> sysctl value while the association value is not.  So, the association
> >> value is now out-of-sync with what the system does and we end up lying
> >> to the user when they do a getsockopt().
> >>
> > Thats not true, looking at the sctp_association_init code the timeout is
> > defaulted to the minimum of the socket value and the maxium timeout sysctl
> > value, the latter of which is defined as INT_MAX/HZ.  That seems reasonable to
> > me in that an association latches both the timeout value and the enabled value
> > from its parent socket at association init time (assoc->autoclose is assigned
> > from sp->autoclose farther down in sctp_association_init).
> 
> Right, so let's see what happens.  Let the sysctl value be set to 1.
> The the socket is created and the option is used to set the value to 10.
> Now, association is created and the timeout is latched to 1.
> However, the autoclose value of the association is set to 10.  So now
> we are lying to the user about our autoclose value!
> 
I think thats not really a problem here.  The sysctl in question is designed to
do exactly what you describe, and in your scenario above the user has change the
sysctl from the default setting of MAX_INT/HZ to 1, so they know that the
autocolse timeout is going to be limited.  I agree that the fact that getsockopt
is going to return the value 10 instead of 1 is an irritant, but its never
guaranteed to match what an associations actual timeout is, because, as you
note, its latched at the time the association is created. Its no different than
setting SOCK_AUTOCLOSE to 10, creating an association, then changing
SOCK_AUTOCLOSE to 20.  The getsockopt operation will return 20 even though the
existing association isn't using that as a timeout value.

> This is what's causing the problem.  The timeout value is out of sync
> what what the requested timeout value is.
> 
> Now, if we latch the socket value correctly, then everything just starts
> to work, even for sysctl value of 0, and we stop lying to the user on
> getsockopt() calls.  This is the real bug that causing the BUG_ON.
> 
> > 
> >> If we simply latch the socket value properly, then we would have to
> >> worry about this at all.  If the socket value is latched at 0, then
> >> autoclose is disabled.
> >>
Ok, so whats "correct" here?  Are you proposing that we remove the max_autoclose
sysctl entirely, or shall we check the value passed into the autoclose
setsockopt against the sysctl value, to ensure that users don't set a value
larger than what the max specifies, lest we continue to 'lie' to them by letting
them set a autoclose timeout larger than what we intend to set when we initalize
an association?  Regardless of what we do here, Theres still no guarantee that
the socket level value will match any given association, and thats just the way
it goes.

What we should do, regardless, is remove assoc->autoclose entirely, and replace
all references to it with references to
asoc->timeouts[SCTP_EVENT_TIMEOUT_AUTOCLOSE]
That way we use a single canonical place to test the autoclose value (since
assoc->autoclose is only used as a boolean test anyway).  Writing it down and
reading it back to myself, that may actually be congruent with what you mean
when you say that we should latch the socket value properly.

Neil

> > We are latching the value properly from what I can see.  The problem is that the
> > upper bound on the value we latch can be zero.  The only way this bug can occur
> > is if net->sctp.max_autoclose is 0.  Note that I'm not talking about the timeout
> > value itself, but its upper bound.  We shouldn't be allowed to set the autoclose
> > timeout sysctl range to [0..0], it just doesn't make sense.  It should be at
> > least [0..1], and the socket autoclose value can range properly within that.
> > From what I see, thats what this patch does.
> 
> We don't allow the sysctl range of [0..0].  We allow the range of
> [0..max_autoclose_max].  This patch tries to change the range to
> [1..max_autoclose_max].  This may be a correct thing to do,
> but it is another issue.  That fact this change fixes the BUG_ON is
> a side-effect.  The real issue is in how we set set the timer value.
> 
> -vlad
> 
> > 
> > Neil
> > 
> 
> --
> To unsubscribe from this list: send the line "unsubscribe linux-sctp" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> 
--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Vladislav Yasevich Dec. 5, 2013, 4 p.m. UTC | #9 
On 12/04/2013 01:56 PM, Neil Horman wrote:
> On Wed, Dec 04, 2013 at 09:45:59AM -0500, Vlad Yasevich wrote:
>> On 12/04/2013 08:28 AM, Neil Horman wrote:
>>> On Tue, Dec 03, 2013 at 04:24:10PM -0500, Vlad Yasevich wrote:
>>>> On 12/03/2013 01:18 PM, Neil Horman wrote:
>>>>> On Tue, Dec 03, 2013 at 11:09:38AM -0500, Vlad Yasevich wrote:
>>>>>> On 12/03/2013 05:09 AM, Wang Weidong wrote:
>>>>>>> since 2692ba61, add the max_autoclose to sysctl. when I setted the
>>>>>>> max_autoclose to 0. Just do the test_autoclose, it will trigger that:
>>>>>>>
>>>>>>> [  608.056238] ------------[ cut here ]------------
>>>>>>> [  608.056244] kernel BUG at /home/wwd/work/linux/net/sctp/sm_sideeffect.c:1488!
>>>>>>> [  608.056250] invalid opcode: 0000 [#1] SMP
>>>>>>> [  608.056254] Modules linked in: md5 sctp(O) crc32c libcrc32c edd fuse loop dm_mod ipv6 8139too sg 8139cp mii i2c_piix4 i2c_core virtio_balloon intel_agp virtio_pci virtio_ring sr_mod cdrom rtc_cmos joydev hid_generic intel_gtt virtio floppy pcspkr button ext3 jbd mbcache usbhid hid uhci_hcd ehci_hcd usbcore sd_mod usb_common crc_t10dif crct10dif_common processor thermal_sys hwmon scsi_dh_emc scsi_dh_alua scsi_dh_hp_sw scsi_dh_rdac scsi_dh ata_generic ata_piix libata scsi_mod [last unloaded: sctp]
>>>>>>> [  608.056310] CPU: 5 PID: 4517 Comm: test_autoclose Tainted: G  R        O 3.13.0-rc1-0.27-default+ #2
>>>>>>> [  608.056315] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2007
>>>>>>> [  608.056319] task: ffff8800372f5590 ti: ffff8800db882000 task.ti: ffff8800db882000
>>>>>>> [  608.056323] RIP: 0010:[<ffffffffa033e350>]  [<ffffffffa033e350>] sctp_cmd_interpreter+0x1010/0x1070 [sctp]
>>>>>>> [  608.056339] RSP: 0018:ffff880116f43928  EFLAGS: 00010246
>>>>>>> [  608.056343] RAX: 0000000000000009 RBX: ffff880116f43ab8 RCX: 0000000000000009
>>>>>>> [  608.056349] RDX: 0000000000000003 RSI: 0000000000000000 RDI: ffff880116f43a88
>>>>>>> [  608.056353] RBP: ffff880116f439d8 R08: 0000000000002029 R09: 0000000000000001
>>>>>>> [  608.056357] R10: 0000000000000000 R11: 0000000000000005 R12: ffff8800db7c9150
>>>>>>> [  608.056361] R13: 0000000000000000 R14: ffff8800db7c9000 R15: 0000000000000001
>>>>>>> [  608.056365] FS:  00007f942d71c700(0000) GS:ffff880116f40000(0000) knlGS:0000000000000000
>>>>>>> [  608.056370] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
>>>>>>> [  608.056373] CR2: 00007f942d324d90 CR3: 00000000db094000 CR4: 00000000000006e0
>>>>>>> [  608.056382] Stack:
>>>>>>> [  608.056384]  0000000000000018 ffff880116f43988 ffff8800da569600 000000010000000a
>>>>>>> [  608.056391]  ffff880037265e40 0000000016f43988 ffff880116f439e8 0000000000000000
>>>>>>> [  608.056397]  ffffffffa0365101 0000000000000000 ffff880116f43a28 ffffffff812b7739
>>>>>>> [  608.056403] Call Trace:
>>>>>>> [  608.056406]  <IRQ>
>>>>>>> [  608.056409]
>>>>>>> [  608.056421]  [<ffffffff812b7739>] ? __dynamic_pr_debug+0x69/0x80
>>>>>>> [  608.056432]  [<ffffffff81097c6d>] ? trace_hardirqs_off+0xd/0x10
>>>>>>> [  608.056442]  [<ffffffff814e7258>] ? _raw_spin_unlock_irqrestore+0x58/0x60
>>>>>>> [  608.056451]  [<ffffffffa033e3e6>] sctp_side_effects+0x36/0x130 [sctp]
>>>>>>> [  608.056459]  [<ffffffffa033e5c7>] sctp_do_sm+0xe7/0x210 [sctp]
>>>>>>> [  608.056470]  [<ffffffffa0359860>] ? sctp_rcv+0x780/0x780 [sctp]
>>>>>>> [  608.056479]  [<ffffffffa0340a5f>] sctp_endpoint_bh_rcv+0x10f/0x220 [sctp]
>>>>>>> [  608.056489]  [<ffffffffa0349991>] sctp_inq_push+0x41/0x60 [sctp]
>>>>>>> [  608.056498]  [<ffffffffa03597b5>] sctp_rcv+0x6d5/0x780 [sctp]
>>>>>>> [  608.056508]  [<ffffffffa0358e00>] ? sctp_csum_combine+0x10/0x10 [sctp]
>>>>>>> [  608.056518]  [<ffffffffa0358df0>] ? sctp_v4_err+0x240/0x240 [sctp]
>>>>>>> [  608.056528]  [<ffffffff8145b8a4>] ip_local_deliver_finish+0xf4/0x270
>>>>>>> [  608.056533]  [<ffffffff8145b7f0>] ? ip_local_deliver_finish+0x40/0x270
>>>>>>> [  608.056538]  [<ffffffff8145b690>] ip_local_deliver+0x80/0x90
>>>>>>> [  608.056543]  [<ffffffff8145bbd3>] ip_rcv_finish+0x1b3/0x600
>>>>>>> [  608.056547]  [<ffffffff8145ba20>] ? ip_local_deliver_finish+0x270/0x270
>>>>>>> [  608.056552]  [<ffffffff8145b04f>] NF_HOOK+0x2f/0x70
>>>>>>> [  608.056565]  [<ffffffff81425853>] ? __netif_receive_skb_core+0x113/0x7a0
>>>>>>> [  608.056570]  [<ffffffff8145b365>] ip_rcv+0x2d5/0x3b0
>>>>>>> [  608.056575]  [<ffffffff81425e3f>] __netif_receive_skb_core+0x6ff/0x7a0
>>>>>>> [  608.056580]  [<ffffffff81425853>] ? __netif_receive_skb_core+0x113/0x7a0
>>>>>>> [  608.056585]  [<ffffffff81426108>] ? process_backlog+0x1a8/0x1c0
>>>>>>> [  608.056590]  [<ffffffff81425f0b>] __netif_receive_skb+0x2b/0x80
>>>>>>> [  608.056595]  [<ffffffff81426018>] process_backlog+0xb8/0x1c0
>>>>>>> [  608.056600]  [<ffffffff8142695c>] net_rx_action+0x11c/0x240
>>>>>>> [  608.056607]  [<ffffffff81050e18>] __do_softirq+0x118/0x290
>>>>>>> [  608.056615]  [<ffffffff814f0e0c>] do_softirq_own_stack+0x1c/0x30
>>>>>>> [  608.056618]  <EOI>
>>>>>>> [  608.056620]
>>>>>>> [  608.056623]  [<ffffffff81050bd5>] do_softirq+0x65/0x70
>>>>>>> [  608.056629]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
>>>>>>> [  608.056635]  [<ffffffff810518c3>] local_bh_enable_ip+0xb3/0xc0
>>>>>>> [  608.056640]  [<ffffffff814e71af>] _raw_spin_unlock_bh+0x2f/0x40
>>>>>>> [  608.056645]  [<ffffffff8140fddc>] release_sock+0x8c/0xa0
>>>>>>> [  608.056654]  [<ffffffffa0354c08>] sctp_sendmsg+0x3a8/0xcc0 [sctp]
>>>>>>> [  608.056661]  [<ffffffff8129924a>] ? number+0x33a/0x360
>>>>>>> [  608.056667]  [<ffffffff81497c3c>] inet_sendmsg+0x9c/0x100
>>>>>>> [  608.056672]  [<ffffffff81497ba0>] ? inet_recvmsg+0x110/0x110
>>>>>>> [  608.056679]  [<ffffffff8140a387>] sock_sendmsg+0x97/0xc0
>>>>>>> [  608.056690]  [<ffffffff8114caae>] ? might_fault+0x3e/0x90
>>>>>>> [  608.056695]  [<ffffffff8114caae>] ? might_fault+0x3e/0x90
>>>>>>> [  608.056700]  [<ffffffff81417a73>] ? verify_iovec+0x53/0x100
>>>>>>> [  608.056705]  [<ffffffff8140abb6>] ___sys_sendmsg+0x416/0x420
>>>>>>> [  608.056710]  [<ffffffff81151af6>] ? __do_fault+0x216/0x510
>>>>>>> [  608.056715]  [<ffffffff814eaf74>] ? __do_page_fault+0x2b4/0x4a0
>>>>>>> [  608.056720]  [<ffffffff81095c9e>] ? up_read+0x1e/0x40
>>>>>>> [  608.056724]  [<ffffffff814eaf74>] ? __do_page_fault+0x2b4/0x4a0
>>>>>>> [  608.056729]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
>>>>>>> [  608.056733]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
>>>>>>> [  608.056741]  [<ffffffff8109bb5d>] ? trace_hardirqs_on+0xd/0x10
>>>>>>> [  608.056746]  [<ffffffff81051875>] ? local_bh_enable_ip+0x65/0xc0
>>>>>>> [  608.056751]  [<ffffffff8140ad94>] __sys_sendmsg+0x44/0x80
>>>>>>> [  608.056756]  [<ffffffff8140ade4>] SyS_sendmsg+0x14/0x20
>>>>>>> [  608.056761]  [<ffffffff814ef5a2>] system_call_fastpath+0x16/0x1b
>>>>>>> -------------------------------------
>>>>>>>
>>>>>>> The reason is: In test_autoclose set the autoclose to 5 not 0(default). So when
>>>>>>> we init the association, the (sctp_sock) sp->autoclose is not 0 while asoc's 
>>>>>>> timeouts[SCTP_EVENT_TIMEOUT_AUTOCLOSE] is 0.
>>>>>>> So when we process the COOKIE_ACK, the sctp_sf_do_5_1E_ca will be called, that
>>>>>>> will do that:
>>>>>>> 	if (asoc->autoclose) //asoc->autoclose is equal sp->autoclose
>>>>>>> 		sctp_add_cmd_sf(commands, SCTP_CMD_TIMER_START,
>>>>>>> 				SCTP_TO(SCTP_EVENT_TIMEOUT_AUTOCLOSE));
>>>>>>
>>>>>> this looks like a bug in how the timeout is being set.  The timeout
>>>>>> should be based on the association value, not some sysctl value.
>>>>>>
>>>>>> The typical socket option values go like this:
>>>>>>    socket value = starts at sysctl, changed by user.
>>>>>>    assoc value = starts at socket value, may be changed by user.
>>>>>>      any timer = starts at assoc value.
>>>>>>
>>>>>> this seems to be broken for autoclose.
>>>>>>
>>>>> Well, it is, but I think its a reasonable fix for the issue.  As I understand
>>>>> the description, the problem is that if autoclose is non-zero, and the default
>>>>> timeout is zero, then you'll get a BUG_ON halt because you need to set a timer
>>>>> that will expire immediately.  It seems reasonable to me to make a minimal
>>>>> default for the timeout to be non-zero, since it makes no sense to have a zero
>>>>> auto-close timeout.
>>>>
>>>> Yes, the default timeout is zero because the timeout is latched by the
>>>> sysctl value while the association value is not.  So, the association
>>>> value is now out-of-sync with what the system does and we end up lying
>>>> to the user when they do a getsockopt().
>>>>
>>> Thats not true, looking at the sctp_association_init code the timeout is
>>> defaulted to the minimum of the socket value and the maxium timeout sysctl
>>> value, the latter of which is defined as INT_MAX/HZ.  That seems reasonable to
>>> me in that an association latches both the timeout value and the enabled value
>>> from its parent socket at association init time (assoc->autoclose is assigned
>>> from sp->autoclose farther down in sctp_association_init).
>>
>> Right, so let's see what happens.  Let the sysctl value be set to 1.
>> The the socket is created and the option is used to set the value to 10.
>> Now, association is created and the timeout is latched to 1.
>> However, the autoclose value of the association is set to 10.  So now
>> we are lying to the user about our autoclose value!
>>
> I think thats not really a problem here.  The sysctl in question is designed to
> do exactly what you describe, and in your scenario above the user has change the
> sysctl from the default setting of MAX_INT/HZ to 1, so they know that the
> autocolse timeout is going to be limited.  I agree that the fact that getsockopt
> is going to return the value 10 instead of 1 is an irritant, but its never
> guaranteed to match what an associations actual timeout is, because, as you
> note, its latched at the time the association is created. Its no different than
> setting SOCK_AUTOCLOSE to 10, creating an association, then changing
> SOCK_AUTOCLOSE to 20.  The getsockopt operation will return 20 even though the
> existing association isn't using that as a timeout value.

Yes, the above is absolutely true for multiple calls to set autoclose.
However, for a single call to autoclose, we should return the value
currently in use, not the value that use the set and we may be ignoring
completely.

> 
>> This is what's causing the problem.  The timeout value is out of sync
>> what what the requested timeout value is.
>>
>> Now, if we latch the socket value correctly, then everything just starts
>> to work, even for sysctl value of 0, and we stop lying to the user on
>> getsockopt() calls.  This is the real bug that causing the BUG_ON.
>>
>>>
>>>> If we simply latch the socket value properly, then we would have to
>>>> worry about this at all.  If the socket value is latched at 0, then
>>>> autoclose is disabled.
>>>>
> Ok, so whats "correct" here?  Are you proposing that we remove the max_autoclose
> sysctl entirely, or shall we check the value passed into the autoclose
> setsockopt against the sysctl value, to ensure that users don't set a value
> larger than what the max specifies, lest we continue to 'lie' to them by letting
> them set a autoclose timeout larger than what we intend to set when we initalize
> an association? 

Yes, that's what we should do.  Essentially treat this similar to how
the stack SO_{SND|RCV}BUF.  Might even log a warning to say autoclose is
limited by sysctl.

> Regardless of what we do here, Theres still no guarantee that
> the socket level value will match any given association, and thats just the way
> it goes.
> 

That's ok, as long as it uses a valid value and the association timer is
set based on the value in the socket.

> What we should do, regardless, is remove assoc->autoclose entirely, and replace
> all references to it with references to
> asoc->timeouts[SCTP_EVENT_TIMEOUT_AUTOCLOSE]
> That way we use a single canonical place to test the autoclose value (since
> assoc->autoclose is only used as a boolean test anyway).  Writing it down and
> reading it back to myself, that may actually be congruent with what you mean
> when you say that we should latch the socket value properly.
>

That's fine to.  So we would have a socket value that is properly
limited by sysctl and returns to the user the value new association will
use.  We would also have the timer value in the association that is
initialized with the socket value.  The timer value of 0 means autoclose
is disabled.  Does that make sense to you?

-vlad

> Neil
> 
>>> We are latching the value properly from what I can see.  The problem is that the
>>> upper bound on the value we latch can be zero.  The only way this bug can occur
>>> is if net->sctp.max_autoclose is 0.  Note that I'm not talking about the timeout
>>> value itself, but its upper bound.  We shouldn't be allowed to set the autoclose
>>> timeout sysctl range to [0..0], it just doesn't make sense.  It should be at
>>> least [0..1], and the socket autoclose value can range properly within that.
>>> From what I see, thats what this patch does.
>>
>> We don't allow the sysctl range of [0..0].  We allow the range of
>> [0..max_autoclose_max].  This patch tries to change the range to
>> [1..max_autoclose_max].  This may be a correct thing to do,
>> but it is another issue.  That fact this change fixes the BUG_ON is
>> a side-effect.  The real issue is in how we set set the timer value.
>>
>> -vlad
>>
>>>
>>> Neil
>>>
>>
>> --
>> To unsubscribe from this list: send the line "unsubscribe linux-sctp" in
>> the body of a message to majordomo@vger.kernel.org
>> More majordomo info at  http://vger.kernel.org/majordomo-info.html
>>

--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Neil Horman Dec. 5, 2013, 8:43 p.m. UTC | #10 
On Thu, Dec 05, 2013 at 11:00:00AM -0500, Vlad Yasevich wrote:
> On 12/04/2013 01:56 PM, Neil Horman wrote:
> > On Wed, Dec 04, 2013 at 09:45:59AM -0500, Vlad Yasevich wrote:
> >> On 12/04/2013 08:28 AM, Neil Horman wrote:
> >>> On Tue, Dec 03, 2013 at 04:24:10PM -0500, Vlad Yasevich wrote:
> >>>> On 12/03/2013 01:18 PM, Neil Horman wrote:
> >>>>> On Tue, Dec 03, 2013 at 11:09:38AM -0500, Vlad Yasevich wrote:
> >>>>>> On 12/03/2013 05:09 AM, Wang Weidong wrote:
> >>>>>>> since 2692ba61, add the max_autoclose to sysctl. when I setted the
> >>>>>>> max_autoclose to 0. Just do the test_autoclose, it will trigger that:
> >>>>>>>
> >>>>>>> [  608.056238] ------------[ cut here ]------------
> >>>>>>> [  608.056244] kernel BUG at /home/wwd/work/linux/net/sctp/sm_sideeffect.c:1488!
> >>>>>>> [  608.056250] invalid opcode: 0000 [#1] SMP
> >>>>>>> [  608.056254] Modules linked in: md5 sctp(O) crc32c libcrc32c edd fuse loop dm_mod ipv6 8139too sg 8139cp mii i2c_piix4 i2c_core virtio_balloon intel_agp virtio_pci virtio_ring sr_mod cdrom rtc_cmos joydev hid_generic intel_gtt virtio floppy pcspkr button ext3 jbd mbcache usbhid hid uhci_hcd ehci_hcd usbcore sd_mod usb_common crc_t10dif crct10dif_common processor thermal_sys hwmon scsi_dh_emc scsi_dh_alua scsi_dh_hp_sw scsi_dh_rdac scsi_dh ata_generic ata_piix libata scsi_mod [last unloaded: sctp]
> >>>>>>> [  608.056310] CPU: 5 PID: 4517 Comm: test_autoclose Tainted: G  R        O 3.13.0-rc1-0.27-default+ #2
> >>>>>>> [  608.056315] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2007
> >>>>>>> [  608.056319] task: ffff8800372f5590 ti: ffff8800db882000 task.ti: ffff8800db882000
> >>>>>>> [  608.056323] RIP: 0010:[<ffffffffa033e350>]  [<ffffffffa033e350>] sctp_cmd_interpreter+0x1010/0x1070 [sctp]
> >>>>>>> [  608.056339] RSP: 0018:ffff880116f43928  EFLAGS: 00010246
> >>>>>>> [  608.056343] RAX: 0000000000000009 RBX: ffff880116f43ab8 RCX: 0000000000000009
> >>>>>>> [  608.056349] RDX: 0000000000000003 RSI: 0000000000000000 RDI: ffff880116f43a88
> >>>>>>> [  608.056353] RBP: ffff880116f439d8 R08: 0000000000002029 R09: 0000000000000001
> >>>>>>> [  608.056357] R10: 0000000000000000 R11: 0000000000000005 R12: ffff8800db7c9150
> >>>>>>> [  608.056361] R13: 0000000000000000 R14: ffff8800db7c9000 R15: 0000000000000001
> >>>>>>> [  608.056365] FS:  00007f942d71c700(0000) GS:ffff880116f40000(0000) knlGS:0000000000000000
> >>>>>>> [  608.056370] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
> >>>>>>> [  608.056373] CR2: 00007f942d324d90 CR3: 00000000db094000 CR4: 00000000000006e0
> >>>>>>> [  608.056382] Stack:
> >>>>>>> [  608.056384]  0000000000000018 ffff880116f43988 ffff8800da569600 000000010000000a
> >>>>>>> [  608.056391]  ffff880037265e40 0000000016f43988 ffff880116f439e8 0000000000000000
> >>>>>>> [  608.056397]  ffffffffa0365101 0000000000000000 ffff880116f43a28 ffffffff812b7739
> >>>>>>> [  608.056403] Call Trace:
> >>>>>>> [  608.056406]  <IRQ>
> >>>>>>> [  608.056409]
> >>>>>>> [  608.056421]  [<ffffffff812b7739>] ? __dynamic_pr_debug+0x69/0x80
> >>>>>>> [  608.056432]  [<ffffffff81097c6d>] ? trace_hardirqs_off+0xd/0x10
> >>>>>>> [  608.056442]  [<ffffffff814e7258>] ? _raw_spin_unlock_irqrestore+0x58/0x60
> >>>>>>> [  608.056451]  [<ffffffffa033e3e6>] sctp_side_effects+0x36/0x130 [sctp]
> >>>>>>> [  608.056459]  [<ffffffffa033e5c7>] sctp_do_sm+0xe7/0x210 [sctp]
> >>>>>>> [  608.056470]  [<ffffffffa0359860>] ? sctp_rcv+0x780/0x780 [sctp]
> >>>>>>> [  608.056479]  [<ffffffffa0340a5f>] sctp_endpoint_bh_rcv+0x10f/0x220 [sctp]
> >>>>>>> [  608.056489]  [<ffffffffa0349991>] sctp_inq_push+0x41/0x60 [sctp]
> >>>>>>> [  608.056498]  [<ffffffffa03597b5>] sctp_rcv+0x6d5/0x780 [sctp]
> >>>>>>> [  608.056508]  [<ffffffffa0358e00>] ? sctp_csum_combine+0x10/0x10 [sctp]
> >>>>>>> [  608.056518]  [<ffffffffa0358df0>] ? sctp_v4_err+0x240/0x240 [sctp]
> >>>>>>> [  608.056528]  [<ffffffff8145b8a4>] ip_local_deliver_finish+0xf4/0x270
> >>>>>>> [  608.056533]  [<ffffffff8145b7f0>] ? ip_local_deliver_finish+0x40/0x270
> >>>>>>> [  608.056538]  [<ffffffff8145b690>] ip_local_deliver+0x80/0x90
> >>>>>>> [  608.056543]  [<ffffffff8145bbd3>] ip_rcv_finish+0x1b3/0x600
> >>>>>>> [  608.056547]  [<ffffffff8145ba20>] ? ip_local_deliver_finish+0x270/0x270
> >>>>>>> [  608.056552]  [<ffffffff8145b04f>] NF_HOOK+0x2f/0x70
> >>>>>>> [  608.056565]  [<ffffffff81425853>] ? __netif_receive_skb_core+0x113/0x7a0
> >>>>>>> [  608.056570]  [<ffffffff8145b365>] ip_rcv+0x2d5/0x3b0
> >>>>>>> [  608.056575]  [<ffffffff81425e3f>] __netif_receive_skb_core+0x6ff/0x7a0
> >>>>>>> [  608.056580]  [<ffffffff81425853>] ? __netif_receive_skb_core+0x113/0x7a0
> >>>>>>> [  608.056585]  [<ffffffff81426108>] ? process_backlog+0x1a8/0x1c0
> >>>>>>> [  608.056590]  [<ffffffff81425f0b>] __netif_receive_skb+0x2b/0x80
> >>>>>>> [  608.056595]  [<ffffffff81426018>] process_backlog+0xb8/0x1c0
> >>>>>>> [  608.056600]  [<ffffffff8142695c>] net_rx_action+0x11c/0x240
> >>>>>>> [  608.056607]  [<ffffffff81050e18>] __do_softirq+0x118/0x290
> >>>>>>> [  608.056615]  [<ffffffff814f0e0c>] do_softirq_own_stack+0x1c/0x30
> >>>>>>> [  608.056618]  <EOI>
> >>>>>>> [  608.056620]
> >>>>>>> [  608.056623]  [<ffffffff81050bd5>] do_softirq+0x65/0x70
> >>>>>>> [  608.056629]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
> >>>>>>> [  608.056635]  [<ffffffff810518c3>] local_bh_enable_ip+0xb3/0xc0
> >>>>>>> [  608.056640]  [<ffffffff814e71af>] _raw_spin_unlock_bh+0x2f/0x40
> >>>>>>> [  608.056645]  [<ffffffff8140fddc>] release_sock+0x8c/0xa0
> >>>>>>> [  608.056654]  [<ffffffffa0354c08>] sctp_sendmsg+0x3a8/0xcc0 [sctp]
> >>>>>>> [  608.056661]  [<ffffffff8129924a>] ? number+0x33a/0x360
> >>>>>>> [  608.056667]  [<ffffffff81497c3c>] inet_sendmsg+0x9c/0x100
> >>>>>>> [  608.056672]  [<ffffffff81497ba0>] ? inet_recvmsg+0x110/0x110
> >>>>>>> [  608.056679]  [<ffffffff8140a387>] sock_sendmsg+0x97/0xc0
> >>>>>>> [  608.056690]  [<ffffffff8114caae>] ? might_fault+0x3e/0x90
> >>>>>>> [  608.056695]  [<ffffffff8114caae>] ? might_fault+0x3e/0x90
> >>>>>>> [  608.056700]  [<ffffffff81417a73>] ? verify_iovec+0x53/0x100
> >>>>>>> [  608.056705]  [<ffffffff8140abb6>] ___sys_sendmsg+0x416/0x420
> >>>>>>> [  608.056710]  [<ffffffff81151af6>] ? __do_fault+0x216/0x510
> >>>>>>> [  608.056715]  [<ffffffff814eaf74>] ? __do_page_fault+0x2b4/0x4a0
> >>>>>>> [  608.056720]  [<ffffffff81095c9e>] ? up_read+0x1e/0x40
> >>>>>>> [  608.056724]  [<ffffffff814eaf74>] ? __do_page_fault+0x2b4/0x4a0
> >>>>>>> [  608.056729]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
> >>>>>>> [  608.056733]  [<ffffffff8140fddc>] ? release_sock+0x8c/0xa0
> >>>>>>> [  608.056741]  [<ffffffff8109bb5d>] ? trace_hardirqs_on+0xd/0x10
> >>>>>>> [  608.056746]  [<ffffffff81051875>] ? local_bh_enable_ip+0x65/0xc0
> >>>>>>> [  608.056751]  [<ffffffff8140ad94>] __sys_sendmsg+0x44/0x80
> >>>>>>> [  608.056756]  [<ffffffff8140ade4>] SyS_sendmsg+0x14/0x20
> >>>>>>> [  608.056761]  [<ffffffff814ef5a2>] system_call_fastpath+0x16/0x1b
> >>>>>>> -------------------------------------
> >>>>>>>
> >>>>>>> The reason is: In test_autoclose set the autoclose to 5 not 0(default). So when
> >>>>>>> we init the association, the (sctp_sock) sp->autoclose is not 0 while asoc's 
> >>>>>>> timeouts[SCTP_EVENT_TIMEOUT_AUTOCLOSE] is 0.
> >>>>>>> So when we process the COOKIE_ACK, the sctp_sf_do_5_1E_ca will be called, that
> >>>>>>> will do that:
> >>>>>>> 	if (asoc->autoclose) //asoc->autoclose is equal sp->autoclose
> >>>>>>> 		sctp_add_cmd_sf(commands, SCTP_CMD_TIMER_START,
> >>>>>>> 				SCTP_TO(SCTP_EVENT_TIMEOUT_AUTOCLOSE));
> >>>>>>
> >>>>>> this looks like a bug in how the timeout is being set.  The timeout
> >>>>>> should be based on the association value, not some sysctl value.
> >>>>>>
> >>>>>> The typical socket option values go like this:
> >>>>>>    socket value = starts at sysctl, changed by user.
> >>>>>>    assoc value = starts at socket value, may be changed by user.
> >>>>>>      any timer = starts at assoc value.
> >>>>>>
> >>>>>> this seems to be broken for autoclose.
> >>>>>>
> >>>>> Well, it is, but I think its a reasonable fix for the issue.  As I understand
> >>>>> the description, the problem is that if autoclose is non-zero, and the default
> >>>>> timeout is zero, then you'll get a BUG_ON halt because you need to set a timer
> >>>>> that will expire immediately.  It seems reasonable to me to make a minimal
> >>>>> default for the timeout to be non-zero, since it makes no sense to have a zero
> >>>>> auto-close timeout.
> >>>>
> >>>> Yes, the default timeout is zero because the timeout is latched by the
> >>>> sysctl value while the association value is not.  So, the association
> >>>> value is now out-of-sync with what the system does and we end up lying
> >>>> to the user when they do a getsockopt().
> >>>>
> >>> Thats not true, looking at the sctp_association_init code the timeout is
> >>> defaulted to the minimum of the socket value and the maxium timeout sysctl
> >>> value, the latter of which is defined as INT_MAX/HZ.  That seems reasonable to
> >>> me in that an association latches both the timeout value and the enabled value
> >>> from its parent socket at association init time (assoc->autoclose is assigned
> >>> from sp->autoclose farther down in sctp_association_init).
> >>
> >> Right, so let's see what happens.  Let the sysctl value be set to 1.
> >> The the socket is created and the option is used to set the value to 10.
> >> Now, association is created and the timeout is latched to 1.
> >> However, the autoclose value of the association is set to 10.  So now
> >> we are lying to the user about our autoclose value!
> >>
> > I think thats not really a problem here.  The sysctl in question is designed to
> > do exactly what you describe, and in your scenario above the user has change the
> > sysctl from the default setting of MAX_INT/HZ to 1, so they know that the
> > autocolse timeout is going to be limited.  I agree that the fact that getsockopt
> > is going to return the value 10 instead of 1 is an irritant, but its never
> > guaranteed to match what an associations actual timeout is, because, as you
> > note, its latched at the time the association is created. Its no different than
> > setting SOCK_AUTOCLOSE to 10, creating an association, then changing
> > SOCK_AUTOCLOSE to 20.  The getsockopt operation will return 20 even though the
> > existing association isn't using that as a timeout value.
> 
> Yes, the above is absolutely true for multiple calls to set autoclose.
> However, for a single call to autoclose, we should return the value
> currently in use, not the value that use the set and we may be ignoring
> completely.
> 
> > 
> >> This is what's causing the problem.  The timeout value is out of sync
> >> what what the requested timeout value is.
> >>
> >> Now, if we latch the socket value correctly, then everything just starts
> >> to work, even for sysctl value of 0, and we stop lying to the user on
> >> getsockopt() calls.  This is the real bug that causing the BUG_ON.
> >>
> >>>
> >>>> If we simply latch the socket value properly, then we would have to
> >>>> worry about this at all.  If the socket value is latched at 0, then
> >>>> autoclose is disabled.
> >>>>
> > Ok, so whats "correct" here?  Are you proposing that we remove the max_autoclose
> > sysctl entirely, or shall we check the value passed into the autoclose
> > setsockopt against the sysctl value, to ensure that users don't set a value
> > larger than what the max specifies, lest we continue to 'lie' to them by letting
> > them set a autoclose timeout larger than what we intend to set when we initalize
> > an association? 
> 
> Yes, that's what we should do.  Essentially treat this similar to how
> the stack SO_{SND|RCV}BUF.  Might even log a warning to say autoclose is
> limited by sysctl.
> 
> > Regardless of what we do here, Theres still no guarantee that
> > the socket level value will match any given association, and thats just the way
> > it goes.
> > 
> 
> That's ok, as long as it uses a valid value and the association timer is
> set based on the value in the socket.
> 
> > What we should do, regardless, is remove assoc->autoclose entirely, and replace
> > all references to it with references to
> > asoc->timeouts[SCTP_EVENT_TIMEOUT_AUTOCLOSE]
> > That way we use a single canonical place to test the autoclose value (since
> > assoc->autoclose is only used as a boolean test anyway).  Writing it down and
> > reading it back to myself, that may actually be congruent with what you mean
> > when you say that we should latch the socket value properly.
> >
> 
> That's fine to.  So we would have a socket value that is properly
> limited by sysctl and returns to the user the value new association will
> use.  We would also have the timer value in the association that is
> initialized with the socket value.  The timer value of 0 means autoclose
> is disabled.  Does that make sense to you?
> 
Yeah, that makes sense, I'll write it in the AM.
Neil

> -vlad
> 
> > Neil
> > 
> >>> We are latching the value properly from what I can see.  The problem is that the
> >>> upper bound on the value we latch can be zero.  The only way this bug can occur
> >>> is if net->sctp.max_autoclose is 0.  Note that I'm not talking about the timeout
> >>> value itself, but its upper bound.  We shouldn't be allowed to set the autoclose
> >>> timeout sysctl range to [0..0], it just doesn't make sense.  It should be at
> >>> least [0..1], and the socket autoclose value can range properly within that.
> >>> From what I see, thats what this patch does.
> >>
> >> We don't allow the sysctl range of [0..0].  We allow the range of
> >> [0..max_autoclose_max].  This patch tries to change the range to
> >> [1..max_autoclose_max].  This may be a correct thing to do,
> >> but it is another issue.  That fact this change fixes the BUG_ON is
> >> a side-effect.  The real issue is in how we set set the timer value.
> >>
> >> -vlad
> >>
> >>>
> >>> Neil
> >>>
> >>
> >> --
> >> To unsubscribe from this list: send the line "unsubscribe linux-sctp" in
> >> the body of a message to majordomo@vger.kernel.org
> >> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> >>
> 
> 
--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
diff mbox

Patch

diff --git a/net/sctp/sysctl.c b/net/sctp/sysctl.c
index 46832d3..8b619d6 100644
--- a/net/sctp/sysctl.c
+++ b/net/sctp/sysctl.c
@@ -47,7 +47,7 @@  static int sack_timer_min = 1;
 static int sack_timer_max = 500;
 static int addr_scope_max = 3; /* check sctp_scope_policy_t in include/net/sctp/constants.h for max entries */
 static int rwnd_scale_max = 16;
-static unsigned long max_autoclose_min = 0;
+static unsigned long max_autoclose_min = 1;
 static unsigned long max_autoclose_max =
 	(MAX_SCHEDULE_TIMEOUT / HZ > UINT_MAX)
 	? UINT_MAX : MAX_SCHEDULE_TIMEOUT / HZ;