Skip to content

Commit 330bdcf

Browse files
dhowellsdavem330
authored andcommitted
rxrpc: Fix the keepalive generator [ver #2]
AF_RXRPC has a keepalive message generator that generates a message for a peer ~20s after the last transmission to that peer to keep firewall ports open. The implementation is incorrect in the following ways: (1) It mixes up ktime_t and time64_t types. (2) It uses ktime_get_real(), the output of which may jump forward or backward due to adjustments to the time of day. (3) If the current time jumps forward too much or jumps backwards, the generator function will crank the base of the time ring round one slot at a time (ie. a 1s period) until it catches up, spewing out VERSION packets as it goes. Fix the problem by: (1) Only using time64_t. There's no need for sub-second resolution. (2) Use ktime_get_seconds() rather than ktime_get_real() so that time isn't perceived to go backwards. (3) Simplifying rxrpc_peer_keepalive_worker() by splitting it into two parts: (a) The "worker" function that manages the buckets and the timer. (b) The "dispatch" function that takes the pending peers and potentially transmits a keepalive packet before putting them back in the ring into the slot appropriate to the revised last-Tx time. (4) Taking everything that's pending out of the ring and splicing it into a temporary collector list for processing. In the case that there's been a significant jump forward, the ring gets entirely emptied and then the time base can be warped forward before the peers are processed. The warping can't happen if the ring isn't empty because the slot a peer is in is keepalive-time dependent, relative to the base time. (5) Limit the number of iterations of the bucket array when scanning it. (6) Set the timer to skip any empty slots as there's no point waking up if there's nothing to do yet. This can be triggered by an incoming call from a server after a reboot with AF_RXRPC and AFS built into the kernel causing a peer record to be set up before userspace is started. The system clock is then adjusted by userspace, thereby potentially causing the keepalive generator to have a meltdown - which leads to a message like: watchdog: BUG: soft lockup - CPU#0 stuck for 23s! [kworker/0:1:23] ... Workqueue: krxrpcd rxrpc_peer_keepalive_worker EIP: lock_acquire+0x69/0x80 ... Call Trace: ? rxrpc_peer_keepalive_worker+0x5e/0x350 ? _raw_spin_lock_bh+0x29/0x60 ? rxrpc_peer_keepalive_worker+0x5e/0x350 ? rxrpc_peer_keepalive_worker+0x5e/0x350 ? __lock_acquire+0x3d3/0x870 ? process_one_work+0x110/0x340 ? process_one_work+0x166/0x340 ? process_one_work+0x110/0x340 ? worker_thread+0x39/0x3c0 ? kthread+0xdb/0x110 ? cancel_delayed_work+0x90/0x90 ? kthread_stop+0x70/0x70 ? ret_from_fork+0x19/0x24 Fixes: ace45be ("rxrpc: Fix firewall route keepalive") Reported-by: kernel test robot <[email protected]> Signed-off-by: David Howells <[email protected]> Signed-off-by: David S. Miller <[email protected]>
1 parent f39cc1c commit 330bdcf

File tree

7 files changed

+109
-89
lines changed

7 files changed

+109
-89
lines changed

net/rxrpc/ar-internal.h

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -104,9 +104,9 @@ struct rxrpc_net {
104104

105105
#define RXRPC_KEEPALIVE_TIME 20 /* NAT keepalive time in seconds */
106106
u8 peer_keepalive_cursor;
107-
ktime_t peer_keepalive_base;
108-
struct hlist_head peer_keepalive[RXRPC_KEEPALIVE_TIME + 1];
109-
struct hlist_head peer_keepalive_new;
107+
time64_t peer_keepalive_base;
108+
struct list_head peer_keepalive[32];
109+
struct list_head peer_keepalive_new;
110110
struct timer_list peer_keepalive_timer;
111111
struct work_struct peer_keepalive_work;
112112
};
@@ -295,7 +295,7 @@ struct rxrpc_peer {
295295
struct hlist_head error_targets; /* targets for net error distribution */
296296
struct work_struct error_distributor;
297297
struct rb_root service_conns; /* Service connections */
298-
struct hlist_node keepalive_link; /* Link in net->peer_keepalive[] */
298+
struct list_head keepalive_link; /* Link in net->peer_keepalive[] */
299299
time64_t last_tx_at; /* Last time packet sent here */
300300
seqlock_t service_conn_lock;
301301
spinlock_t lock; /* access lock */

net/rxrpc/conn_event.c

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -136,7 +136,7 @@ static void rxrpc_conn_retransmit_call(struct rxrpc_connection *conn,
136136
}
137137

138138
ret = kernel_sendmsg(conn->params.local->socket, &msg, iov, ioc, len);
139-
conn->params.peer->last_tx_at = ktime_get_real();
139+
conn->params.peer->last_tx_at = ktime_get_seconds();
140140
if (ret < 0)
141141
trace_rxrpc_tx_fail(conn->debug_id, serial, ret,
142142
rxrpc_tx_fail_call_final_resend);
@@ -245,7 +245,7 @@ static int rxrpc_abort_connection(struct rxrpc_connection *conn,
245245
return -EAGAIN;
246246
}
247247

248-
conn->params.peer->last_tx_at = ktime_get_real();
248+
conn->params.peer->last_tx_at = ktime_get_seconds();
249249

250250
_leave(" = 0");
251251
return 0;

net/rxrpc/net_ns.c

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -85,12 +85,12 @@ static __net_init int rxrpc_init_net(struct net *net)
8585
hash_init(rxnet->peer_hash);
8686
spin_lock_init(&rxnet->peer_hash_lock);
8787
for (i = 0; i < ARRAY_SIZE(rxnet->peer_keepalive); i++)
88-
INIT_HLIST_HEAD(&rxnet->peer_keepalive[i]);
89-
INIT_HLIST_HEAD(&rxnet->peer_keepalive_new);
88+
INIT_LIST_HEAD(&rxnet->peer_keepalive[i]);
89+
INIT_LIST_HEAD(&rxnet->peer_keepalive_new);
9090
timer_setup(&rxnet->peer_keepalive_timer,
9191
rxrpc_peer_keepalive_timeout, 0);
9292
INIT_WORK(&rxnet->peer_keepalive_work, rxrpc_peer_keepalive_worker);
93-
rxnet->peer_keepalive_base = ktime_add(ktime_get_real(), NSEC_PER_SEC);
93+
rxnet->peer_keepalive_base = ktime_get_seconds();
9494

9595
ret = -ENOMEM;
9696
rxnet->proc_net = proc_net_mkdir(net, "rxrpc", net->proc_net);

net/rxrpc/output.c

Lines changed: 6 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -209,7 +209,7 @@ int rxrpc_send_ack_packet(struct rxrpc_call *call, bool ping,
209209
now = ktime_get_real();
210210
if (ping)
211211
call->ping_time = now;
212-
conn->params.peer->last_tx_at = ktime_get_real();
212+
conn->params.peer->last_tx_at = ktime_get_seconds();
213213
if (ret < 0)
214214
trace_rxrpc_tx_fail(call->debug_id, serial, ret,
215215
rxrpc_tx_fail_call_ack);
@@ -296,7 +296,7 @@ int rxrpc_send_abort_packet(struct rxrpc_call *call)
296296

297297
ret = kernel_sendmsg(conn->params.local->socket,
298298
&msg, iov, 1, sizeof(pkt));
299-
conn->params.peer->last_tx_at = ktime_get_real();
299+
conn->params.peer->last_tx_at = ktime_get_seconds();
300300
if (ret < 0)
301301
trace_rxrpc_tx_fail(call->debug_id, serial, ret,
302302
rxrpc_tx_fail_call_abort);
@@ -391,7 +391,7 @@ int rxrpc_send_data_packet(struct rxrpc_call *call, struct sk_buff *skb,
391391
* message and update the peer record
392392
*/
393393
ret = kernel_sendmsg(conn->params.local->socket, &msg, iov, 2, len);
394-
conn->params.peer->last_tx_at = ktime_get_real();
394+
conn->params.peer->last_tx_at = ktime_get_seconds();
395395

396396
up_read(&conn->params.local->defrag_sem);
397397
if (ret < 0)
@@ -457,7 +457,7 @@ int rxrpc_send_data_packet(struct rxrpc_call *call, struct sk_buff *skb,
457457
if (ret == 0) {
458458
ret = kernel_sendmsg(conn->params.local->socket, &msg,
459459
iov, 2, len);
460-
conn->params.peer->last_tx_at = ktime_get_real();
460+
conn->params.peer->last_tx_at = ktime_get_seconds();
461461

462462
opt = IP_PMTUDISC_DO;
463463
kernel_setsockopt(conn->params.local->socket, SOL_IP,
@@ -475,7 +475,7 @@ int rxrpc_send_data_packet(struct rxrpc_call *call, struct sk_buff *skb,
475475
if (ret == 0) {
476476
ret = kernel_sendmsg(conn->params.local->socket, &msg,
477477
iov, 2, len);
478-
conn->params.peer->last_tx_at = ktime_get_real();
478+
conn->params.peer->last_tx_at = ktime_get_seconds();
479479

480480
opt = IPV6_PMTUDISC_DO;
481481
kernel_setsockopt(conn->params.local->socket,
@@ -599,6 +599,6 @@ void rxrpc_send_keepalive(struct rxrpc_peer *peer)
599599
trace_rxrpc_tx_fail(peer->debug_id, 0, ret,
600600
rxrpc_tx_fail_version_keepalive);
601601

602-
peer->last_tx_at = ktime_get_real();
602+
peer->last_tx_at = ktime_get_seconds();
603603
_leave("");
604604
}

net/rxrpc/peer_event.c

Lines changed: 88 additions & 68 deletions
Original file line numberDiff line numberDiff line change
@@ -350,97 +350,117 @@ void rxrpc_peer_add_rtt(struct rxrpc_call *call, enum rxrpc_rtt_rx_trace why,
350350
}
351351

352352
/*
353-
* Perform keep-alive pings with VERSION packets to keep any NAT alive.
353+
* Perform keep-alive pings.
354354
*/
355-
void rxrpc_peer_keepalive_worker(struct work_struct *work)
355+
static void rxrpc_peer_keepalive_dispatch(struct rxrpc_net *rxnet,
356+
struct list_head *collector,
357+
time64_t base,
358+
u8 cursor)
356359
{
357-
struct rxrpc_net *rxnet =
358-
container_of(work, struct rxrpc_net, peer_keepalive_work);
359360
struct rxrpc_peer *peer;
360-
unsigned long delay;
361-
ktime_t base, now = ktime_get_real();
362-
s64 diff;
363-
u8 cursor, slot;
361+
const u8 mask = ARRAY_SIZE(rxnet->peer_keepalive) - 1;
362+
time64_t keepalive_at;
363+
int slot;
364364

365-
base = rxnet->peer_keepalive_base;
366-
cursor = rxnet->peer_keepalive_cursor;
365+
spin_lock_bh(&rxnet->peer_hash_lock);
367366

368-
_enter("%u,%lld", cursor, ktime_sub(now, base));
367+
while (!list_empty(collector)) {
368+
peer = list_entry(collector->next,
369+
struct rxrpc_peer, keepalive_link);
369370

370-
next_bucket:
371-
diff = ktime_to_ns(ktime_sub(now, base));
372-
if (diff < 0)
373-
goto resched;
371+
list_del_init(&peer->keepalive_link);
372+
if (!rxrpc_get_peer_maybe(peer))
373+
continue;
374374

375-
_debug("at %u", cursor);
376-
spin_lock_bh(&rxnet->peer_hash_lock);
377-
next_peer:
378-
if (!rxnet->live) {
379375
spin_unlock_bh(&rxnet->peer_hash_lock);
380-
goto out;
381-
}
382376

383-
/* Everything in the bucket at the cursor is processed this second; the
384-
* bucket at cursor + 1 goes now + 1s and so on...
385-
*/
386-
if (hlist_empty(&rxnet->peer_keepalive[cursor])) {
387-
if (hlist_empty(&rxnet->peer_keepalive_new)) {
388-
spin_unlock_bh(&rxnet->peer_hash_lock);
389-
goto emptied_bucket;
377+
keepalive_at = peer->last_tx_at + RXRPC_KEEPALIVE_TIME;
378+
slot = keepalive_at - base;
379+
_debug("%02x peer %u t=%d {%pISp}",
380+
cursor, peer->debug_id, slot, &peer->srx.transport);
381+
382+
if (keepalive_at <= base ||
383+
keepalive_at > base + RXRPC_KEEPALIVE_TIME) {
384+
rxrpc_send_keepalive(peer);
385+
slot = RXRPC_KEEPALIVE_TIME;
390386
}
391387

392-
hlist_move_list(&rxnet->peer_keepalive_new,
393-
&rxnet->peer_keepalive[cursor]);
388+
/* A transmission to this peer occurred since last we examined
389+
* it so put it into the appropriate future bucket.
390+
*/
391+
slot += cursor;
392+
slot &= mask;
393+
spin_lock_bh(&rxnet->peer_hash_lock);
394+
list_add_tail(&peer->keepalive_link,
395+
&rxnet->peer_keepalive[slot & mask]);
396+
rxrpc_put_peer(peer);
394397
}
395398

396-
peer = hlist_entry(rxnet->peer_keepalive[cursor].first,
397-
struct rxrpc_peer, keepalive_link);
398-
hlist_del_init(&peer->keepalive_link);
399-
if (!rxrpc_get_peer_maybe(peer))
400-
goto next_peer;
401-
402399
spin_unlock_bh(&rxnet->peer_hash_lock);
400+
}
403401

404-
_debug("peer %u {%pISp}", peer->debug_id, &peer->srx.transport);
402+
/*
403+
* Perform keep-alive pings with VERSION packets to keep any NAT alive.
404+
*/
405+
void rxrpc_peer_keepalive_worker(struct work_struct *work)
406+
{
407+
struct rxrpc_net *rxnet =
408+
container_of(work, struct rxrpc_net, peer_keepalive_work);
409+
const u8 mask = ARRAY_SIZE(rxnet->peer_keepalive) - 1;
410+
time64_t base, now, delay;
411+
u8 cursor, stop;
412+
LIST_HEAD(collector);
405413

406-
recalc:
407-
diff = ktime_divns(ktime_sub(peer->last_tx_at, base), NSEC_PER_SEC);
408-
if (diff < -30 || diff > 30)
409-
goto send; /* LSW of 64-bit time probably wrapped on 32-bit */
410-
diff += RXRPC_KEEPALIVE_TIME - 1;
411-
if (diff < 0)
412-
goto send;
414+
now = ktime_get_seconds();
415+
base = rxnet->peer_keepalive_base;
416+
cursor = rxnet->peer_keepalive_cursor;
417+
_enter("%lld,%u", base - now, cursor);
413418

414-
slot = (diff > RXRPC_KEEPALIVE_TIME - 1) ? RXRPC_KEEPALIVE_TIME - 1 : diff;
415-
if (slot == 0)
416-
goto send;
419+
if (!rxnet->live)
420+
return;
417421

418-
/* A transmission to this peer occurred since last we examined it so
419-
* put it into the appropriate future bucket.
422+
/* Remove to a temporary list all the peers that are currently lodged
423+
* in expired buckets plus all new peers.
424+
*
425+
* Everything in the bucket at the cursor is processed this
426+
* second; the bucket at cursor + 1 goes at now + 1s and so
427+
* on...
420428
*/
421-
slot = (slot + cursor) % ARRAY_SIZE(rxnet->peer_keepalive);
422429
spin_lock_bh(&rxnet->peer_hash_lock);
423-
hlist_add_head(&peer->keepalive_link, &rxnet->peer_keepalive[slot]);
424-
rxrpc_put_peer(peer);
425-
goto next_peer;
426-
427-
send:
428-
rxrpc_send_keepalive(peer);
429-
now = ktime_get_real();
430-
goto recalc;
430+
list_splice_init(&rxnet->peer_keepalive_new, &collector);
431+
432+
stop = cursor + ARRAY_SIZE(rxnet->peer_keepalive);
433+
while (base <= now && (s8)(cursor - stop) < 0) {
434+
list_splice_tail_init(&rxnet->peer_keepalive[cursor & mask],
435+
&collector);
436+
base++;
437+
cursor++;
438+
}
431439

432-
emptied_bucket:
433-
cursor++;
434-
if (cursor >= ARRAY_SIZE(rxnet->peer_keepalive))
435-
cursor = 0;
436-
base = ktime_add_ns(base, NSEC_PER_SEC);
437-
goto next_bucket;
440+
base = now;
441+
spin_unlock_bh(&rxnet->peer_hash_lock);
438442

439-
resched:
440443
rxnet->peer_keepalive_base = base;
441444
rxnet->peer_keepalive_cursor = cursor;
442-
delay = nsecs_to_jiffies(-diff) + 1;
443-
timer_reduce(&rxnet->peer_keepalive_timer, jiffies + delay);
444-
out:
445+
rxrpc_peer_keepalive_dispatch(rxnet, &collector, base, cursor);
446+
ASSERT(list_empty(&collector));
447+
448+
/* Schedule the timer for the next occupied timeslot. */
449+
cursor = rxnet->peer_keepalive_cursor;
450+
stop = cursor + RXRPC_KEEPALIVE_TIME - 1;
451+
for (; (s8)(cursor - stop) < 0; cursor++) {
452+
if (!list_empty(&rxnet->peer_keepalive[cursor & mask]))
453+
break;
454+
base++;
455+
}
456+
457+
now = ktime_get_seconds();
458+
delay = base - now;
459+
if (delay < 1)
460+
delay = 1;
461+
delay *= HZ;
462+
if (rxnet->live)
463+
timer_reduce(&rxnet->peer_keepalive_timer, jiffies + delay);
464+
445465
_leave("");
446466
}

net/rxrpc/peer_object.c

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -322,7 +322,7 @@ struct rxrpc_peer *rxrpc_lookup_incoming_peer(struct rxrpc_local *local,
322322
if (!peer) {
323323
peer = prealloc;
324324
hash_add_rcu(rxnet->peer_hash, &peer->hash_link, hash_key);
325-
hlist_add_head(&peer->keepalive_link, &rxnet->peer_keepalive_new);
325+
list_add_tail(&peer->keepalive_link, &rxnet->peer_keepalive_new);
326326
}
327327

328328
spin_unlock(&rxnet->peer_hash_lock);
@@ -367,8 +367,8 @@ struct rxrpc_peer *rxrpc_lookup_peer(struct rxrpc_local *local,
367367
if (!peer) {
368368
hash_add_rcu(rxnet->peer_hash,
369369
&candidate->hash_link, hash_key);
370-
hlist_add_head(&candidate->keepalive_link,
371-
&rxnet->peer_keepalive_new);
370+
list_add_tail(&candidate->keepalive_link,
371+
&rxnet->peer_keepalive_new);
372372
}
373373

374374
spin_unlock_bh(&rxnet->peer_hash_lock);
@@ -441,7 +441,7 @@ static void __rxrpc_put_peer(struct rxrpc_peer *peer)
441441

442442
spin_lock_bh(&rxnet->peer_hash_lock);
443443
hash_del_rcu(&peer->hash_link);
444-
hlist_del_init(&peer->keepalive_link);
444+
list_del_init(&peer->keepalive_link);
445445
spin_unlock_bh(&rxnet->peer_hash_lock);
446446

447447
kfree_rcu(peer, rcu);

net/rxrpc/rxkad.c

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -669,7 +669,7 @@ static int rxkad_issue_challenge(struct rxrpc_connection *conn)
669669
return -EAGAIN;
670670
}
671671

672-
conn->params.peer->last_tx_at = ktime_get_real();
672+
conn->params.peer->last_tx_at = ktime_get_seconds();
673673
_leave(" = 0");
674674
return 0;
675675
}
@@ -725,7 +725,7 @@ static int rxkad_send_response(struct rxrpc_connection *conn,
725725
return -EAGAIN;
726726
}
727727

728-
conn->params.peer->last_tx_at = ktime_get_real();
728+
conn->params.peer->last_tx_at = ktime_get_seconds();
729729
_leave(" = 0");
730730
return 0;
731731
}

0 commit comments

Comments
 (0)