Tricky redirection issue with bl-reload-gtk23 in BLOB

johnraff · 2021-01-26 06:25:24

@nobody this one's for you I guess.

Summary: when the output of bl-reload-gtk23 is stored in a variable, as in BLOB line 1376 then IF:
xsettingsd is already running: no problem.
xsettingsd is not yet running: the command does not return, and the calling script hangs.

EDIT: On reflection, maybe it's intrinsically hopeless to try to capture the output of a running daemon in a string? Perhaps best just to remove that bit of code from BLOB, and call bl-reload-gtk23 directly?

My guess is that when the caller uses stdout/stderr then python makes a pipe connection to xsettingsd, and waits for the latter to exit before considering that all the requested output has been captured.

The same behaviour can be elicited in a terminal, no need to run BLOB:

pgrep -x xsettingsd # check
pkill -x xsettingsd # make sure the daemon is not running
bl-reload-gtk23 2>&1 # no problem (now xsettingsd is running)

pkill -x xsettingsd 2>&1
(bl-reload-gtk23 2>&1) # run in subshell also OK

pkill -x xsettingsd
v=$(bl-reload-gtk23 2>&1)
# NOW IT HANGS
# Ctrl+C returns the prompt, and xsettingsd is RUNNING
# Alternatively, 'pkill -x xsettingsd' in another terminal also ends the process (xsettingsd not now running of course)

# In either case:
echo "$v"

(bl-reload-gtk23:13755): Gtk-WARNING **: 15:04:08.457: Theme parsing error: gtk.css:5:24: The style property GtkRange:stepper-size is deprecated and shouldn't be used anymore. It will be removed in a future version
xsettingsd: Loaded 13 settings from /home/john/.config/xsettingsd/xsettingsd.conf
xsettingsd: Created window 0x7400001 on screen 0 with timestamp 56407585
xsettingsd: Selection _XSETTINGS_S0 is owned by 0x0
xsettingsd: Took ownership of selection _XSETTINGS_S0

The daemon seems to be being correctly started (I think using setsuid) by the start_new_session=True parameter, and pstree confirms it as an independent process, not a child of BLOB or bl-reload-gtk23.

Is there maybe some tweak you can do in the way it's launched, eg to disconnect the pipe after a short timeout?

Otherwise, maybe something in the caller BLOB - eg run 'bl-reload-gtk23 2>/dev/null' when not in debug mode, or else just let it output whatever it wants: it's only a cosmetic issue really.

I have no problem building the isos again to include an upgraded bunsen-utilities if it looks as if there's an easy fix, but otherwise we could push it post-release.

I don't know if it's at all relevant, but 'python3 -m trace --trace /path/to/bl-reload-gtk23', in the case where xsettingsd needs to be restarted and the calling script hangs (just the last section of a 150MB file):

 --- modulename: shutil, funcname: _access_check
shutil.py(1129):         return (os.path.exists(fn) and os.access(fn, mode)
 --- modulename: genericpath, funcname: exists
genericpath.py(18):     try:
genericpath.py(19):         os.stat(path)
genericpath.py(22):     return True
shutil.py(1130):                 and not os.path.isdir(fn))
 --- modulename: genericpath, funcname: isdir
genericpath.py(41):     try:
genericpath.py(42):         st = os.stat(s)
genericpath.py(45):     return stat.S_ISDIR(st.st_mode)
shutil.py(1174):                     return name
bl-reload-gtk23(293):          if xsettingsd_binary is not None:
bl-reload-gtk23(294):             proc = subprocess.Popen([xsettingsd_binary], cwd="/", start_new_session=True)
 --- modulename: subprocess, funcname: __init__
subprocess.py(664):         _cleanup()
 --- modulename: subprocess, funcname: _cleanup
subprocess.py(227):     for inst in _active[:]:
subprocess.py(670):         self._waitpid_lock = threading.Lock()
subprocess.py(672):         self._input = None
subprocess.py(673):         self._communication_started = False
subprocess.py(674):         if bufsize is None:
subprocess.py(676):         if not isinstance(bufsize, int):
subprocess.py(679):         if _mswindows:
subprocess.py(685):             if pass_fds and not close_fds:
subprocess.py(688):             if startupinfo is not None:
subprocess.py(691):             if creationflags != 0:
subprocess.py(695):         self.args = args
subprocess.py(696):         self.stdin = None
subprocess.py(697):         self.stdout = None
subprocess.py(698):         self.stderr = None
subprocess.py(699):         self.pid = None
subprocess.py(700):         self.returncode = None
subprocess.py(701):         self.encoding = encoding
subprocess.py(702):         self.errors = errors
subprocess.py(705):         if (text is not None and universal_newlines is not None
subprocess.py(728):          errread, errwrite) = self._get_handles(stdin, stdout, stderr)
 --- modulename: subprocess, funcname: _get_handles
subprocess.py(1333):             p2cread, p2cwrite = -1, -1
subprocess.py(1334):             c2pread, c2pwrite = -1, -1
subprocess.py(1335):             errread, errwrite = -1, -1
subprocess.py(1337):             if stdin is None:
subprocess.py(1338):                 pass
subprocess.py(1349):             if stdout is None:
subprocess.py(1350):                 pass
subprocess.py(1361):             if stderr is None:
subprocess.py(1362):                 pass
subprocess.py(1378):             return (p2cread, p2cwrite,
subprocess.py(1379):                     c2pread, c2pwrite,
subprocess.py(1380):                     errread, errwrite)
subprocess.py(734):         if _mswindows:
subprocess.py(742):         self.text_mode = encoding or errors or text or universal_newlines
subprocess.py(747):         self._sigint_wait_secs = 0.25  # 1/xkcd221.getRandomNumber()
subprocess.py(749):         self._closed_child_pipe_fds = False
subprocess.py(751):         try:
subprocess.py(752):             if p2cwrite != -1:
subprocess.py(758):             if c2pread != -1:
subprocess.py(763):             if errread != -1:
subprocess.py(769):             self._execute_child(args, executable, preexec_fn, close_fds,
subprocess.py(770):                                 pass_fds, cwd, env,
subprocess.py(771):                                 startupinfo, creationflags, shell,
subprocess.py(772):                                 p2cread, p2cwrite,
subprocess.py(773):                                 c2pread, c2pwrite,
subprocess.py(774):                                 errread, errwrite,
subprocess.py(775):                                 restore_signals, start_new_session)
 --- modulename: subprocess, funcname: _execute_child
subprocess.py(1392):             if isinstance(args, (str, bytes)):
subprocess.py(1395):                 args = list(args)
subprocess.py(1397):             if shell:
subprocess.py(1405):             if executable is None:
subprocess.py(1406):                 executable = args[0]
subprocess.py(1407):             orig_executable = executable
subprocess.py(1412):             errpipe_read, errpipe_write = os.pipe()
subprocess.py(1414):             low_fds_to_close = []
subprocess.py(1415):             while errpipe_write < 3:
subprocess.py(1418):             for low_fd in low_fds_to_close:
subprocess.py(1420):             try:
subprocess.py(1421):                 try:
subprocess.py(1427):                     if env is not None:
subprocess.py(1435):                         env_list = None  # Use execv instead of execve.
subprocess.py(1436):                     executable = os.fsencode(executable)
 --- modulename: os, funcname: fsencode
os.py(809):         filename = fspath(filename)  # Does type-checking of `filename`.
os.py(810):         if isinstance(filename, str):
os.py(811):             return filename.encode(encoding, errors)
subprocess.py(1437):                     if os.path.dirname(executable):
 --- modulename: posixpath, funcname: dirname
posixpath.py(156):     p = os.fspath(p)
posixpath.py(157):     sep = _get_sep(p)
 --- modulename: posixpath, funcname: _get_sep
posixpath.py(42):     if isinstance(path, bytes):
posixpath.py(43):         return b'/'
posixpath.py(158):     i = p.rfind(sep) + 1
posixpath.py(159):     head = p[:i]
posixpath.py(160):     if head and head != sep*len(head):
posixpath.py(161):         head = head.rstrip(sep)
posixpath.py(162):     return head
subprocess.py(1438):                         executable_list = (executable,)
subprocess.py(1444):                     fds_to_keep = set(pass_fds)
subprocess.py(1445):                     fds_to_keep.add(errpipe_write)
subprocess.py(1446):                     self.pid = _posixsubprocess.fork_exec(
subprocess.py(1447):                             args, executable_list,
subprocess.py(1448):                             close_fds, tuple(sorted(map(int, fds_to_keep))),
subprocess.py(1449):                             cwd, env_list,
subprocess.py(1450):                             p2cread, p2cwrite, c2pread, c2pwrite,
subprocess.py(1451):                             errread, errwrite,
subprocess.py(1452):                             errpipe_read, errpipe_write,
subprocess.py(1453):                             restore_signals, start_new_session, preexec_fn)
subprocess.py(1454):                     self._child_created = True
subprocess.py(1457):                     os.close(errpipe_write)
subprocess.py(1460):                 devnull_fd = getattr(self, '_devnull', None)
subprocess.py(1461):                 if p2cread != -1 and p2cwrite != -1 and p2cread != devnull_fd:
subprocess.py(1463):                 if c2pwrite != -1 and c2pread != -1 and c2pwrite != devnull_fd:
subprocess.py(1465):                 if errwrite != -1 and errread != -1 and errwrite != devnull_fd:
subprocess.py(1467):                 if devnull_fd is not None:
subprocess.py(1470):                 self._closed_child_pipe_fds = True
subprocess.py(1474):                 errpipe_data = bytearray()
subprocess.py(1475):                 while True:
subprocess.py(1476):                     part = os.read(errpipe_read, 50000)
subprocess.py(1477):                     errpipe_data += part
subprocess.py(1478):                     if not part or len(errpipe_data) > 50000:
subprocess.py(1479):                         break
subprocess.py(1482):                 os.close(errpipe_read)
subprocess.py(1484):             if errpipe_data:
bl-reload-gtk23(295):             logging.debug("xsettingsd is not running; started from %s; PID: %d", xsettingsd_binary, proc.pid)
 --- modulename: __init__, funcname: debug
__init__.py(2002):     if len(root.handlers) == 0:
__init__.py(2004):     root.debug(msg, *args, **kwargs)
 --- modulename: __init__, funcname: debug
__init__.py(1370):         if self.isEnabledFor(DEBUG):
 --- modulename: __init__, funcname: isEnabledFor
__init__.py(1623):         try:
__init__.py(1624):             return self._cache[level]
 --- modulename: subprocess, funcname: __del__
subprocess.py(851):         if not self._child_created:
subprocess.py(854):         if self.returncode is None:
subprocess.py(857):             _warn("subprocess %s is still running" % self.pid,
subprocess.py(858):                   ResourceWarning, source=self)
subprocess.py(860):         self._internal_poll(_deadstate=_maxsize)
 --- modulename: subprocess, funcname: _internal_poll
subprocess.py(1553):             if self.returncode is None:
subprocess.py(1554):                 if not self._waitpid_lock.acquire(False):
subprocess.py(1558):                 try:
subprocess.py(1559):                     if self.returncode is not None:
subprocess.py(1561):                     pid, sts = _waitpid(self.pid, _WNOHANG)
subprocess.py(1562):                     if pid == self.pid:
subprocess.py(1575):                     self._waitpid_lock.release()
subprocess.py(1576):             return self.returncode
subprocess.py(861):         if self.returncode is None and _active is not None:
subprocess.py(863):             _active.append(self)
bl-reload-gtk23(323):    return 0 if opts.force else ret

Last edited by johnraff (2024-04-21 05:12:40)

nobody · 2021-01-26 21:50:34

interesting, could you try https://github.com/BunsenLabs/bunsen-utilities/pull/73?

This discards all output from any spawned xsettingsd though. If we were interested in xsettingsd output, I imagine that the file descriptor of the subprocess needs to be changed differently.

Can we assume that all users have a systemd --user session running? If so, it would be much preferable to launch xsettingsd via systemd as a unit instead of doing it manually.

johnraff · 2021-01-27 05:57:13

Posted a response on GitHub: https://github.com/BunsenLabs/bunsen-ut … -767970587

CORRECTION: I was wrong here:

johnraff wrote:

v=$(bl-reload-gtk23 2>&1)
# NOW IT HANGS
# Ctrl+C returns the prompt, and xsettingsd is RUNNING
# Alternatively, 'pkill -x xsettingsd' in another terminal also ends the process (xsettingsd not now running of course)

# In either case:
echo "$v"

(bl-reload-gtk23:13755): Gtk-WARNING **: 15:04:08.457: Theme parsing error: gtk.css:5:24: The style property GtkRange:stepper-size is deprecated and shouldn't be used anymore. It will be removed in a future version
xsettingsd: Loaded 13 settings from /home/john/.config/xsettingsd/xsettingsd.conf

Variable v is only set when xsettingsd is killed from a second terminal. Killing the script with Ctrl+C does not set the variable - I was seeing the result of the previous command, forgetting to 'unset v'.

---
Anyway, let's not get too bogged down in the depths of Python process control and file descriptors. Just not trying to capture stderr is enough to fix the hang, and switching the >/dev/null might be enough for our purposes?

---
Running xsettingsd by default? That's another option too. I was thinking, at this point it's only started when needed, ie when running BLOB, and only continues to run in that particular session. It's a very small daemon consuming minuscule system resources, but I thought maybe we could wait to see if there was any user feedback on its introduction with the new bunsen-utilities.

If no-one notices or complains, let's start launching it by default in Beryllium - either via systemd or just an entry in the bunsen/autostart file?

nobody · 2021-01-27 09:29:46

^ No, I did not necessarily mean to run xsettingsd by default (although it sounds more correct) but just use systemd for process management in any case, to discard the burden of doing process management.

I think that the case of "fixing" the redirect just for stderr is enough is purely accidental, caused by the fact that in its code, xsettingsd is only ever writing debug messages to stderr, on the code path we're taking.

johnraff · 2021-01-28 03:12:07

^Sorry, I didn't mean it that way - just saying that stderr was the feed we were interested in in this case. Of course attempting to capture stdout also causes the hang.

johnraff wrote:

Just not trying to capture stderr is enough to fix the hang

The "just" was aimed at "not trying to capture" not at "stderr".

Yes, xsettingsd is sending everything on stderr anyway - to whichever terminal it was started from. Three cases:

1) If, with xsettingsd not running we run 'bl-reload-gtk23 >/dev/null 2>&1' then the terminal messages are all suppressed. Interesting to see that after that, even 'bl-reload-gtk23' shows no messages from xsettingsd. Its stderr and stdout have already been attached to /dev/null.

2) Again with xsettingsd killed, run 'bl-reload-gtk23' and see the xsettingsd messages (of course). But now, even running 'bl-reload-gtk23 >/dev/null 2>&1' the xsettingsd messages still get through. Presumably now xsettingsd's stderr and stdout are attached to the terminal, regardless of indirections applied to bl-reload-gtk23.

3) Kill xsettingsd, and launch it without a controlling terminal (eg in gmrun). Now no messages from xsettingsd are displayed when running bl-reload-gtk23, with or without the redirection to /dev/null.

That all makes sense if you think about it, and means there's no point in trying to control what happens to xsettingsd's messages, I guess. And indeed it might be better to launch it as a systemd service, if bl-reload-gtk23 is going to have to start it, instead of relying on Python mechanisms. But that is a refinement which could wait till Beryllium perhaps? (Although that's not so far away.)

Meanwhile, OK with you if I just drop the variable capture and apply the /dev/null redirection when calling bl-reload-gtk23 from BLOB (except when debugging) for now, and we leave bl-reload-gtk23 as it is?

johnraff · 2021-01-30 05:35:57

Bunsen-utilities workaround pushed https://forums.bunsenlabs.org/viewtopic … 17#p110717

Meanwhile, let's indeed consider whether we want to launch xsettingsd (or possibly lxde-settings-daemon?) by default in Beryllium...

#1 2021-01-26 06:25:24

Tricky redirection issue with bl-reload-gtk23 in BLOB

#2 2021-01-26 21:50:34

Re: Tricky redirection issue with bl-reload-gtk23 in BLOB

#3 2021-01-27 05:57:13

Re: Tricky redirection issue with bl-reload-gtk23 in BLOB

#4 2021-01-27 09:29:46

Re: Tricky redirection issue with bl-reload-gtk23 in BLOB

#5 2021-01-28 03:12:07

Re: Tricky redirection issue with bl-reload-gtk23 in BLOB

#6 2021-01-30 05:35:57

Re: Tricky redirection issue with bl-reload-gtk23 in BLOB

Board footer