Skip to content

Commit

Permalink
WIP: define our logging principles and apply them
Browse files Browse the repository at this point in the history
  • Loading branch information
@ramnes
ramnes committed Aug 5, 2021
1 parent 34020c4 commit 7537ab7
Show file tree
Hide file tree
Showing 6 changed files with 50 additions and 36 deletions.
24 changes: 24 additions & 0 deletions docs/manual/hacking.rst
View file
Original file line number Diff line number Diff line change
Expand Up @@ -102,6 +102,30 @@ to ensure your patch complies with reasonable formatting constraints. We also
request that git commit messages follow the
`standard format <https://tbaggery.com/2008/04/19/a-note-about-git-commit-messages.html>`_.

Logging
=======

Logs are important to us because they are our best way to see what Qtile is
doing when something abnormal happens. However, our goal is not to have as many
logs as possible, as this hinders readability. What we want are relevant logs.

To decide which log level to use, refer to the following scenarios:

* ERROR: a problem affects the behavior of Qtile in a way that is noticeable to
the end user, and we can't work around it.
* WARNING: a problem causes Qtile to operate in a suboptimal manner.
* INFO: the state of Qtile has changed.
* DEBUG: information is worth giving to help the developer better understand
which branch the process is in.

Be careful not to overuse DEBUG and clutter the logs. No information should be
duplicated between two messages.

Also, keep in mind that any other level than DEBUG is aimed at users who don't
necessarily have advanced programming knowledge; adapt your message
accordingly. If it can't make sense to your grandma, it's probably meant to be
a DEBUG message.

Deprecation policy
==================

Expand Down
18 changes: 5 additions & 13 deletions libqtile/backend/x11/core.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -291,10 +291,9 @@ def _xpoll(self) -> None:
if event_type.endswith("Event"):
event_type = event_type[:-5]

logger.debug(event_type)

for target in self._get_target_chain(event_type, event):
logger.debug("Handling: {event_type}".format(event_type=event_type))
targets = self._get_target_chain(event_type, event)
logger.debug(f"X11 event: {event_type} (targets: {len(targets)})")
for target in targets:
ret = target(event)
if not ret:
break
Expand Down Expand Up @@ -368,9 +367,6 @@ def _get_target_chain(self, event_type: str, event) -> List[Callable]:

if hasattr(self, handler):
chain.append(getattr(self, handler))

if not chain:
logger.info("Unhandled event: {event_type}".format(event_type=event_type))
return chain

def get_valid_timestamp(self):
Expand Down Expand Up @@ -452,11 +448,7 @@ def grab_key(self, key: Union[config.Key, config.KeyChord]) -> Tuple[int, int]:

for code in codes:
if code == 0:
logger.warning(
"Keysym could not be mapped: {keysym}, mask: {modmask}".format(
keysym=hex(keysym), modmask=modmask
)
)
logger.warning(f"Can't grab {key} (unknown keysym: {hex(keysym)})")
continue
for amask in self._auto_modmasks():
self.conn.conn.core.GrabKey(
Expand Down Expand Up @@ -594,7 +586,7 @@ def handle_ClientMessage(self, event) -> None: # noqa: N802
try:
self.qtile.groups[index].cmd_toscreen()
except IndexError:
logger.info("Invalid Desktop Index: %s" % index)
logger.debug("Invalid desktop index: %s" % index)

def handle_KeyPress(self, event) -> None: # noqa: N802
assert self.qtile is not None
Expand Down
22 changes: 10 additions & 12 deletions libqtile/backend/x11/window.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -643,7 +643,6 @@ def update_state(self):

state = self.window.get_net_wm_state()

logger.debug('_NET_WM_STATE: %s', state)
for s in triggered:
setattr(self, s, (s in state))

Expand Down Expand Up @@ -1618,33 +1617,33 @@ def handle_ClientMessage(self, event): # noqa: N802
elif atoms["_NET_ACTIVE_WINDOW"] == opcode:
source = data.data32[0]
if source == 2: # XCB_EWMH_CLIENT_SOURCE_TYPE_NORMAL
logger.info("Focusing window by pager")
logger.debug("Focusing window by pager")
self.qtile.current_screen.set_group(self.group)
self.group.focus(self)
else: # XCB_EWMH_CLIENT_SOURCE_TYPE_OTHER
focus_behavior = self.qtile.config.focus_on_window_activation
if focus_behavior == "focus":
logger.info("Focusing window")
logger.debug("Focusing window")
self.qtile.current_screen.set_group(self.group)
self.group.focus(self)
elif focus_behavior == "smart":
if not self.group.screen:
logger.info("Ignoring focus request")
logger.debug("Ignoring focus request")
return
if self.group.screen == self.qtile.current_screen:
logger.info("Focusing window")
logger.debug("Focusing window")
self.qtile.current_screen.set_group(self.group)
self.group.focus(self)
else: # self.group.screen != self.qtile.current_screen:
logger.info("Setting urgent flag for window")
logger.debug("Setting urgent flag for window")
self.urgent = True
elif focus_behavior == "urgent":
logger.info("Setting urgent flag for window")
logger.debug("Setting urgent flag for window")
self.urgent = True
elif focus_behavior == "never":
logger.info("Ignoring focus request")
logger.debug("Ignoring focus request")
else:
logger.warning("Invalid value for focus_on_window_activation: {}".format(focus_behavior))
logger.debug("Invalid value for focus_on_window_activation: {}".format(focus_behavior))
elif atoms["_NET_CLOSE_WINDOW"] == opcode:
self.kill()
elif atoms["WM_CHANGE_STATE"] == opcode:
Expand All @@ -1654,11 +1653,10 @@ def handle_ClientMessage(self, event): # noqa: N802
elif state == IconicState and self.qtile.config.auto_minimize:
self.minimized = True
else:
logger.info("Unhandled client message: %s", atoms.get_name(opcode))
logger.debug("Unhandled client message: %s", atoms.get_name(opcode))

def handle_PropertyNotify(self, e): # noqa: N802
name = self.qtile.core.conn.atoms.get_name(e.atom)
logger.debug("PropertyNotifyEvent: %s", name)
if name == "WM_TRANSIENT_FOR":
pass
elif name == "WM_HINTS":
Expand Down Expand Up @@ -1694,7 +1692,7 @@ def handle_PropertyNotify(self, e): # noqa: N802
# self.update_state()
self.update_state()
else:
logger.info("Unknown window property: %s", name)
logger.debug("Unknown window property: %s", name)
return False

def _items(self, name: str) -> ItemT:
Expand Down
10 changes: 5 additions & 5 deletions libqtile/core/manager.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -344,7 +344,7 @@ def paint_screen(
def process_key_event(self, keysym: int, mask: int) -> None:
key = self.keys_map.get((keysym, mask), None)
if key is None:
logger.info("Ignoring unknown keysym: {keysym}, mask: {mask}".format(keysym=keysym, mask=mask))
logger.debug("Ignoring unknown keysym: {keysym}, mask: {mask}".format(keysym=keysym, mask=mask))
return

if isinstance(key, KeyChord):
Expand Down Expand Up @@ -1282,11 +1282,11 @@ def f(group):
try:
self.groups_map[group].cmd_toscreen()
except KeyError:
logger.info("No group named '{0:s}' present.".format(group))
logger.warning("No group named '{0:s}' present.".format(group))

mb = self.widgets_map.get(widget)
if not mb:
logger.warning("No widget named '{0:s}' present.".format(widget))
logger.error("No widget named '{0:s}' present.".format(widget))
return

mb.start_input(prompt, f, "group", strict_completer=True)
Expand Down Expand Up @@ -1371,7 +1371,7 @@ def f(cmd):
return
cmd_len = len(cmd_arg)
if cmd_len == 0:
logger.info('No command entered.')
logger.debug('No command entered.')
return
try:
result = eval(u'c.{0:s}'.format(cmd))
Expand Down Expand Up @@ -1466,7 +1466,7 @@ def cmd_hide_show_bar(
else:
logger.warning("Not found bar for hide/show.")
else:
logger.error("Invalid position value:{0:s}".format(position))
logger.warning("Invalid position value:{0:s}".format(position))

def cmd_get_state(self) -> str:
"""Get pickled state for restarting qtile"""
Expand Down
5 changes: 2 additions & 3 deletions libqtile/dgroups.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -150,7 +150,7 @@ def _addgroup(self, group_name):

def _add(self, client):
if client in self.timeout:
logger.info('Remove dgroup source')
logger.debug('Remove dgroup source')
self.timeout.pop(client).cancel()

# ignore static windows
Expand Down Expand Up @@ -249,8 +249,7 @@ def delete_client():
self.sort_groups()
del self.timeout[client]

# Wait the delay until really delete the group
logger.info('Add dgroup timer with delay {}s'.format(self.delay))
logger.debug(f'Deleting {group} in {self.delay}s')
self.timeout[client] = self.qtile.call_later(
self.delay, delete_client
)
7 changes: 4 additions & 3 deletions libqtile/widget/pulse_volume.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -84,21 +84,22 @@ def on_connection_change(self, context):
self.connected = True
# once onnection is established we need to get server information
self.timeout_add(0.1, self.get_server_info)
log.debug('Connection to pulseaudio ready')
elif state == lib.PA_CONTEXT_FAILED:
# failed to connect
self.connected = False
self._subscribed = False
log.error('Failed to connect to pulseaudio')
log.warning('Failed to connect to pulseaudio, retrying in 10s')
self.timeout_add(10, self.connect)
elif state == lib.PA_CONTEXT_TERMINATED:
# done
self.connected = False
self._subscribed = False
log.warning('Connection to pulseaudio has been terminated')
log.debug('Connection to pulseaudio terminated cleanly')
elif state == lib.PA_CONTEXT_UNCONNECTED:
self.connected = False
self._subscribed = False
log.error("Disconnected from pulsedio")
log.warning("Disconnected from pulseaudio")

def get_server_info(self):
lib.pa_context_get_server_info(
Expand Down

0 comments on commit 7537ab7

Please sign in to comment.