Received-SPF: pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) client-ip=209.132.180.67;
Subject: Re: [PATCH v4 1/2] timers: Don't wake ktimersoftd on every tick
To:     Mike Galbraith <efault@gmx.de>
Cc:     linux-rt-users@vger.kernel.org, linux-kernel@vger.kernel.org,
        daniel@bristot.me, hokanovi <haris.okanovic@ni.com>
References: <alpine.DEB.2.20.1707182206110.2425@nanos>
 <20180306233944.11271-1-haris.okanovic@ni.com>
 <1523332961.4827.1.camel@gmx.de>
 <c2664fbe-52e7-1044-e9f9-de4875047ee8@ni.com>
From:   Haris Okanovic <haris.okanovic@ni.com>
Message-ID: <7d21ff63-3dce-b8ea-a0f1-81d53617747d@ni.com>
Date:   Thu, 28 Jun 2018 11:36:54 -0500
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:52.0) Gecko/20100101
 Thunderbird/52.8.0
MIME-Version: 1.0
In-Reply-To: <c2664fbe-52e7-1044-e9f9-de4875047ee8@ni.com>
Content-Type: text/plain; charset=iso-8859-15; format=flowed
Content-Language: en-US
Content-Transfer-Encoding: 8bit
Received-SPF: None (protection.outlook.com: ni.com does not designate
 permitted sender hosts)
SpamDiagnosticOutput: 1:99
SpamDiagnosticMetadata: NSPM
X-MS-Exchange-CrossTenant-OriginalArrivalTime: 28 Jun 2018 16:36:56.3110 (UTC)
X-MS-Exchange-CrossTenant-Network-Message-Id: e56ac8f8-cf21-47bf-ccd1-08d5dd155cd7
X-MS-Exchange-CrossTenant-FromEntityHeader: Hosted
X-MS-Exchange-CrossTenant-Id: 87ba1f9a-44cd-43a6-b008-6fdb45a5204e
X-MS-Exchange-Transport-CrossTenantHeadersStamped: SN6PR04MB4637
X-Proofpoint-Virus-Version: vendor=fsecure engine=2.50.10434:,, definitions=2018-06-28_08:,,
 signatures=0
X-Proofpoint-Spam-Details: rule=inbound_policy_notspam policy=inbound_policy score=30
 priorityscore=1501 malwarescore=0 suspectscore=0 phishscore=0 bulkscore=0
 spamscore=0 clxscore=1015 lowpriorityscore=0 mlxscore=0 impostorscore=0
 mlxlogscore=999 adultscore=0 classifier=spam adjust=30 reason=mlx
 scancount=1 engine=8.0.1-1806210000 definitions=main-1806280188
Sender: linux-kernel-owner@vger.kernel.org
Precedence: bulk
List-ID: <linux-kernel.vger.kernel.org>
X-Mailing-List: linux-kernel@vger.kernel.org

I found the problem: Running `dumpcap -D` (E.g. by wireshark) creates a 
timer that's sometimes re-armed with 0 timeout in it's callback function 
prb_retire_rx_blk_timer_expired(). My change introduced a subtle change 
in __run_timers()'s stop condition, which causes ktimersoftd to spin 
when such a timer is present. This blocks all other timers including 
those from workqueues.

ktimersoftd stack:
  __run_timers()
  [...]
  call_timer_fn()
  prb_retire_rx_blk_timer_expired()
  _prb_refresh_rx_retire_blk_timer()
  mod_timer(..., jiffies + 0)

The current implementation deals with this corner case by deferring 
0-timeout timers to the next tick, where they expires late. I'll submit 
a v5 shortly to match this behavior.

Thanks again for reporting this issue, Mike. It's a good find! And my 
apologies for the late fix. I've been busy the last few months.

-- Haris


On 04/12/2018 10:00 AM, Haris Okanovic wrote:
> Hi Mike,
> 
> I haven't tested the patch with wireshark until now. My system also 
> hangs shortly after it starts. I'm pretty sure I hit workqueues in my 
> earlier tests via the block driver, but it's clearly not whatever 
> wireshark is using. I'll look at it and try to post a fix. CCing the 
> list to avoid this patch until then.
> 
> Thanks,
> Haris
> 
> 
> On 04/09/2018 11:02 PM, Mike Galbraith wrote:
>> Hi,
>>
>> Are these patches dead, or are you planning another submission?? I ask
>> because I discovered that with them applied, firing up wireshark hangs
>> the box 100% repeatably, with wireshark never fully initializing.
>>
>> Applying them to an otherwise virgin 4.14.20-rt17 to be sure...
>>
>> crash> bt 6016PID: 6016 ??TASK: ffff95dd68572180 ?CPU: 2 ??COMMAND:
>> "dumpcap"
>> ? #0 [ffffb490094f3bc0] __schedule at ffffffffa56d55b9
>> ? #1 [ffffb490094f3c40] schedule at ffffffffa56d5a03
>> ? #2 [ffffb490094f3c58] schedule_timeout at ffffffffa56d8467
>> ? #3 [ffffb490094f3cd8] wait_for_completion at ffffffffa56d6e34
>> ? #4 [ffffb490094f3d18] __wait_rcu_gp at ffffffffa50e59cd
>> ? #5 [ffffb490094f3d58] synchronize_rcu at ffffffffa50ec14e
>> ? #6 [ffffb490094f3d98] packet_set_ring at ffffffffc0c74da0 [af_packet]
>> ? #7 [ffffb490094f3e50] packet_setsockopt at ffffffffc0c75d23 [af_packet]
>> ? #8 [ffffb490094f3ef8] sys_setsockopt at ffffffffa558a5e2
>> ? #9 [ffffb490094f3f30] do_syscall_64 at ffffffffa5001b05
>> #10 [ffffb490094f3f50] entry_SYSCALL_64_after_hwframe at ffffffffa5800065
>> ? ???RIP: 00007f3107a1cfaa ?RSP: 00007ffc9745c2e8 ?RFLAGS: 00000246
>> ? ???RAX: ffffffffffffffda ?RBX: 0000000000000001 ?RCX: 00007f3107a1cfaa
>> ? ???RDX: 0000000000000005 ?RSI: 0000000000000107 ?RDI: 0000000000000003
>> ? ???RBP: 000055ae1d8eb470 ??R8: 000000000000001c ??R9: 0000000000000002
>> ? ???R10: 00007ffc9745c350 ?R11: 0000000000000246 ?R12: 00007ffc9745c350
>> ? ???R13: 0000000000000000 ?R14: 000055ae1d8eb200 ?R15: 000055ae1d8eb2d0
>> ? ???ORIG_RAX: 0000000000000036 ?CS: 0033 ?SS: 002b
>> crash> dmesg
>> ...
>> [ ?483.808197] BUG: workqueue lockup - pool cpus=2 node=0 flags=0x0 
>> nice=0 stuck for 52s!
>> [ ?483.808204] Showing busy workqueues and worker pools:
>> [ ?483.808206] workqueue events: flags=0x0
>> [ ?483.808208] ??pwq 4: cpus=2 node=0 flags=0x0 nice=0 active=1/256
>> [ ?483.808211] ????pending: check_corruption
>> [ ?492.695124] sysrq: SysRq : Trigger a crash
>>