Skip to content

Implement dynamic debug logging mask for Rust Binder #3

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
jahnavi-MN496 wants to merge 8 commits into
base: rust-binder-base
Choose a base branch
from
Open

Implement dynamic debug logging mask for Rust Binder #3

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
8 commits
Select commit Hold shift + click to select a range
c5b4867
rust_binder : Implement dynamic debug logging mask
jahnavi-MN496 Jul 2, 2026
a7e1f76
rust_binder: Add dynamic debug logging mask
jahnavi-MN496 Jun 22, 2026
63a61d3
rust_binder: Implement BINDER_DEBUG_USER_ERROR for
jahnavi-MN496 Jun 29, 2026
db6071e
rust_binder: Implement BINDER_DEBUG_USER_ERROR for refcounting
jahnavi-MN496 Jun 29, 2026
e2a8641
rust_binder: Implement BINDER_DEBUG_USER_ERROR for
jahnavi-MN496 Jun 29, 2026
4c049db
rust_binder: Implement BINDER_DEBUG_FAILED_TRANSACTION
jahnavi-MN496 Jun 24, 2026
83ca110
rust_binder: Implement BINDER_DEBUG_DEATH_NOTIFICATION
jahnavi-MN496 Jun 24, 2026
de7ee67
rust_binder: Implement BINDER_DEBUG_DEAD_TRANSACTION
jahnavi-MN496 Jun 26, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
74 changes: 74 additions & 0 deletions drivers/android/binder/debug.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,74 @@
// SPDX-License-Identifier: GPL-2.0
// Copyright (C) 2026 Google LLC.

//! Binder debugging helpers.

#![allow(dead_code)]

kernel::impl_flags!(
/// Represents multiple debug mask flags.
#[derive(Debug, Clone, Default, Copy, PartialEq, Eq)]
pub struct DebugMasks(u32);

/// Represents a single debug mask category.
#[derive(Debug, Clone, Copy, PartialEq, Eq)]
pub enum DebugMask {
UserError = kernel::bits::bit_u32(0),

@Darksonn Darksonn Jul 13, 2026

Copy link
Copy Markdown
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Let's import kernel::bits::bit_u32 and kernel::sync::atomic::Atomic instead of using the full path every time.

FailedTransaction = kernel::bits::bit_u32(1),
DeadTransaction = kernel::bits::bit_u32(2),
OpenClose = kernel::bits::bit_u32(3),
DeadBinder = kernel::bits::bit_u32(4),
DeathNotification = kernel::bits::bit_u32(5),
ReadWrite = kernel::bits::bit_u32(6),
UserRefs = kernel::bits::bit_u32(7),
Threads = kernel::bits::bit_u32(8),
Transaction = kernel::bits::bit_u32(9),
TransactionComplete = kernel::bits::bit_u32(10),
FreeBuffer = kernel::bits::bit_u32(11),
InternalRefs = kernel::bits::bit_u32(12),
PriorityCap = kernel::bits::bit_u32(13),
Spinlocks = kernel::bits::bit_u32(14),
}
);

#[no_mangle]
pub(crate) static rust_binder_debug_mask: kernel::sync::atomic::Atomic<u32> =
kernel::sync::atomic::Atomic::new(
(DebugMask::UserError as u32)
| (DebugMask::FailedTransaction as u32)
| (DebugMask::DeadTransaction as u32),
);

/// Checks if the given debug logging category is enabled in the mask.
pub(crate) fn debug_mask_enabled(mask: DebugMask) -> bool {
let current_mask = rust_binder_debug_mask.load(kernel::sync::atomic::Relaxed);
DebugMasks(current_mask).contains(mask)
}

/// Prints a debug log if the specified mask category is enabled.
#[macro_export]
macro_rules! binder_debug {
// Rule to explicitly specify a PID (used in kworkers).
(pid=$pid:expr, $mask:ident, $($arg:tt)*) => {
if $crate::debug::debug_mask_enabled($crate::debug::DebugMask::$mask) {
kernel::pr_info!(
"{}: {}\n",
$pid,
kernel::prelude::fmt!($($arg)*)
);
}
};

// Default rule (automatically prepends "PID:TID" of the current calling thread).
($mask:ident, $($arg:tt)*) => {
if $crate::debug::debug_mask_enabled($crate::debug::DebugMask::$mask) {
let thread = kernel::current!();
kernel::pr_info!(
"{}:{} {}\n",
thread.tgid(),
thread.pid(),
Comment thread
Darksonn marked this conversation as resolved.
kernel::prelude::fmt!($($arg)*)
);
}
};
}
64 changes: 46 additions & 18 deletions drivers/android/binder/freeze.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -60,6 +60,7 @@ type UninitFM = UniqueArc<core::mem::MaybeUninit<DTRWrap<FreezeMessage>>>;
/// Represents a notification that the freeze state has changed.
pub(crate) struct FreezeMessage {
cookie: FreezeCookie,
pid: i32,
}
Comment on lines 61 to 64

@Darksonn Darksonn Jul 10, 2026

Copy link
Copy Markdown
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

For commit rust_binder: Implement BINDER_DEBUG_DEAD_TRANSACTION, I would add an explanation to the commit message saying that you are adding the pid to some structs so that they can be used when printing in cancel() because the cancel() method is often called from a workqueue (typically from deferred_release).


kernel::list::impl_list_arc_safe! {
Expand All @@ -73,8 +74,8 @@ impl FreezeMessage {
UniqueArc::new_uninit(flags)
}

fn init(ua: UninitFM, cookie: FreezeCookie) -> DLArc<FreezeMessage> {
match ua.pin_init_with(DTRWrap::new(FreezeMessage { cookie })) {
fn init(ua: UninitFM, cookie: FreezeCookie, pid: i32) -> DLArc<FreezeMessage> {
match ua.pin_init_with(DTRWrap::new(FreezeMessage { cookie, pid })) {
Ok(msg) => ListArc::from(msg),
Err(err) => match err {},
}
Expand Down Expand Up @@ -140,7 +141,14 @@ impl DeliverToRead for FreezeMessage {
}
}

fn cancel(self: DArc<Self>) {}
fn cancel(self: DArc<Self>) {
binder_debug!(
pid = self.pid,
DeadTransaction,
"undelivered freeze notification, {:016x}",
self.cookie.0
);
}

fn should_sync_wakeup(&self) -> bool {
false
Expand Down Expand Up @@ -182,20 +190,23 @@ impl Process {
info = match node_refs.by_handle.get_mut(&handle) {
Some(info) => info,
None => {
pr_warn!("BC_REQUEST_FREEZE_NOTIFICATION invalid ref {}\n", handle);
binder_debug!(
UserError,
"BC_REQUEST_FREEZE_NOTIFICATION invalid ref {handle}"
);
return Err(EINVAL);
}
};
if info.freeze().is_some() {
pr_warn!("BC_REQUEST_FREEZE_NOTIFICATION already set\n");
binder_debug!(UserError, "BC_REQUEST_FREEZE_NOTIFICATION already set");
return Err(EINVAL);
}
let node_ref = info.node_ref();
freeze_entry = node_refs.freeze_listeners.entry(cookie);

if let rbtree::Entry::Occupied(ref dupe) = freeze_entry {
if !dupe.get().allow_duplicate(&node_ref.node) {
pr_warn!("BC_REQUEST_FREEZE_NOTIFICATION duplicate cookie\n");
binder_debug!(UserError, "BC_REQUEST_FREEZE_NOTIFICATION duplicate cookie");
return Err(EINVAL);
}
}
Expand Down Expand Up @@ -248,7 +259,7 @@ impl Process {
}

*info.freeze() = Some(cookie);
let msg = FreezeMessage::init(msg, cookie);
let msg = FreezeMessage::init(msg, cookie, self.task.pid());
drop(node_refs_guard);
let _ = self.push_work(msg);
Ok(())
Expand All @@ -260,26 +271,31 @@ impl Process {
let mut node_refs_guard = self.node_refs.lock();
let node_refs = &mut *node_refs_guard;
let Some(freeze) = node_refs.freeze_listeners.get_mut(&cookie) else {
pr_warn!("BC_FREEZE_NOTIFICATION_DONE {:016x} not found\n", cookie.0);
binder_debug!(
UserError,
"BC_FREEZE_NOTIFICATION_DONE {:016x} not found",
cookie.0
);
return Err(EINVAL);
};
let mut clear_msg = None;
if freeze.num_pending_duplicates > 0 {
clear_msg = Some(FreezeMessage::init(alloc, cookie));
clear_msg = Some(FreezeMessage::init(alloc, cookie, self.task.pid()));
freeze.num_pending_duplicates -= 1;
freeze.num_cleared_duplicates += 1;
} else {
if !freeze.is_pending {
pr_warn!(
"BC_FREEZE_NOTIFICATION_DONE {:016x} not pending\n",
binder_debug!(
UserError,
"BC_FREEZE_NOTIFICATION_DONE {:016x} not pending",
cookie.0
);
return Err(EINVAL);
}
let is_frozen = freeze.node.owner.inner.lock().is_frozen.is_fully_frozen();
if freeze.is_clearing || freeze.last_is_frozen != Some(is_frozen) {
// Immediately send another FreezeMessage.
clear_msg = Some(FreezeMessage::init(alloc, cookie));
clear_msg = Some(FreezeMessage::init(alloc, cookie, self.task.pid()));
}
freeze.is_pending = false;
}
Expand All @@ -300,27 +316,39 @@ impl Process {
let mut node_refs_guard = self.node_refs.lock();
let node_refs = &mut *node_refs_guard;
let Some(info) = node_refs.by_handle.get_mut(&handle) else {
pr_warn!("BC_CLEAR_FREEZE_NOTIFICATION invalid ref {}\n", handle);
binder_debug!(
UserError,
"BC_CLEAR_FREEZE_NOTIFICATION invalid ref {handle}"
);
return Err(EINVAL);
};
let Some(info_cookie) = info.freeze() else {
pr_warn!("BC_CLEAR_FREEZE_NOTIFICATION freeze notification not active\n");
binder_debug!(
UserError,
"BC_CLEAR_FREEZE_NOTIFICATION freeze notification not active"
);
return Err(EINVAL);
};
if *info_cookie != cookie {
pr_warn!("BC_CLEAR_FREEZE_NOTIFICATION freeze notification cookie mismatch\n");
binder_debug!(
UserError,
"BC_CLEAR_FREEZE_NOTIFICATION freeze notification cookie mismatch"
);
return Err(EINVAL);
}
let Some(listener) = node_refs.freeze_listeners.get_mut(&cookie) else {
pr_warn!("BC_CLEAR_FREEZE_NOTIFICATION invalid cookie {}\n", handle);
binder_debug!(
UserError,
"BC_CLEAR_FREEZE_NOTIFICATION invalid cookie {handle}"
);
return Err(EINVAL);
};
listener.is_clearing = true;
_to_free_fl = listener.node.remove_freeze_listener(self);
*info.freeze() = None;
let mut msg = None;
if !listener.is_pending {
msg = Some(FreezeMessage::init(alloc, cookie));
msg = Some(FreezeMessage::init(alloc, cookie, self.task.pid()));
}
drop(node_refs_guard);

Expand Down Expand Up @@ -400,7 +428,7 @@ impl Process {
continue;
};
let msg_alloc = FreezeMessage::new(GFP_KERNEL)?;
let msg = FreezeMessage::init(msg_alloc, cookie);
let msg = FreezeMessage::init(msg_alloc, cookie, proc.task.pid());
batch.push((proc, msg), GFP_KERNEL)?;
}

Expand Down
24 changes: 19 additions & 5 deletions drivers/android/binder/node.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -345,7 +345,7 @@ impl Node {
) -> Option<DLArc<Node>> {
let inner = self.inner.access_mut(owner_inner);
if inner.active_inc_refs == 0 {
pr_err!("inc_ref_done called when no active inc_refs");
binder_debug!(UserError, "inc_ref_done called when no active inc_refs");
return None;
}

Expand Down Expand Up @@ -819,6 +819,7 @@ impl NodeRef {

pub(crate) fn clone(&self, strong: bool) -> Result<NodeRef> {
if strong && self.strong_count == 0 {
binder_debug!(UserError, "tried to use weak ref as strong ref");
return Err(EINVAL);
}
Ok(self
Expand Down Expand Up @@ -859,9 +860,10 @@ impl NodeRef {
*count += 1;
} else {
if *count == 0 {
pr_warn!(
"pid {} performed invalid decrement on ref\n",
kernel::current!().pid()
binder_debug!(
UserError,
"performed invalid {} decrement on ref",
if strong { "strong" } else { "weak" }
);
return false;
}
Expand Down Expand Up @@ -1103,6 +1105,11 @@ impl DeliverToRead for NodeDeath {
// We're still holding the inner lock, so it cannot be aborted while we insert it into
// the delivered list.
process_inner.death_delivered(self.clone());
binder_debug!(
DeathNotification,
"sending death notification, cookie {:016x}",
cookie
);
BR_DEAD_BINDER
};

Expand All @@ -1113,7 +1120,14 @@ impl DeliverToRead for NodeDeath {
Ok(cmd != BR_DEAD_BINDER)
}

fn cancel(self: DArc<Self>) {}
fn cancel(self: DArc<Self>) {
binder_debug!(
pid = self.process.task.pid(),
DeadTransaction,
"undelivered death notification, {:016x}",
self.cookie
);
}

fn should_sync_wakeup(&self) -> bool {
false
Expand Down
Loading