Preview of rst files not working #790
Comments
|
Hmm, this maybe difficult for me to debug if this only occurs on an M1 Mac as it's not something I have access to. However, looking at the log messages this reads to me as the server hasn't crashed, but has instead printed something outside of the LSP spec. In fact, if I throw a random The preview mechanism is essentially a
|
alcarney
added
lsp
|
Hm that’s confusing because my temporary solution to this has just been to run |
Potentially? Though, I had a (very!) brief skim of the page and didn't notice anything obvious
Not easily I'm afraid... your best bet is probably to find your installation of |
|
Hi, I am trying to generate a reST preview from VSC. I will try the try/except proposal above. |
If you are able to share any debug logs/errors messages you encounter that really helps diagnose what might be happening.
Just checking that you are also using the stable version ( |
|
I am not very capable as a programmer (and also bound by confidentiality), so as far as I understand, this is the output in visual studio after I set the output level to debug. I will soon try to do something about the code and add some snippet that will redirect the built-in print function. I have read an earlier comment of yours about the print function and I will try do see if something prints something. However, I am not sure my skills and knowledge will suffice. We'll see... By the way, what is the meaning of this: |
|
alright, I think I have reached a conclusion and apparently both of you @alcarney and @WWGolay were correct. def preview(self, options: Dict[str, Any]) -> Dict[str, Any]:
if not self.app or not self.app.builder:
return {}
builder_name = self.app.builder.name
if builder_name not in {"html"}:
self.show_message(
f"Previews are not currently supported for the '{builder_name}' builder."
)
return {}
self.logger.debug('Making sure VSC is executing this file.')
import builtins
import inspect
global gl_logger
gl_logger = self.logger
original_print = print
def custom_print(*args, **kwargs):
stack = inspect.stack()
calling_frame_record = stack[1]
frame = calling_frame_record[0]
info = inspect.getframeinfo(frame)
logging.debug(f"Print called from {info.filename}:{info.lineno}")
gl_logger.debug(' '.join(str(arg) for arg in args))
builtins.print = custom_print
print('Making sure my print redirection works.')
import traceback
try:
if not self.preview_process and IS_LINUX:
self.logger.debug("Starting preview server.")
server = make_preview_server(self.app.outdir) # type: ignore[arg-type]
print('Checkpoint 1')
self.preview_port = server.server_port
print('Checkpoint 2')
self.preview_process = Process(target=server.serve_forever, daemon=True)
print('Checkpoint 3')
self.preview_process.start()
print('Checkpoint 4')
if not self.preview_process and not IS_LINUX:
self.logger.debug("Starting preview server")
q: Queue = Queue()
self.preview_process = Process(
target=start_preview_server, args=(q, self.app.outdir), daemon=True
)
self.preview_process.start()
self.preview_port = q.get()
if options.get("show", True):
print('Checkpoint 5')
self.show_document(
ShowDocumentParams(
uri=f"http://localhost:{self.preview_port}", external=True
)
)
print('Checkpoint 6')
except Exception:
exc_msg = traceback.format_exc()
self.logger.debug(exc_msg)
builtins.print = original_print
self.logger.debug('FINAL CHECKPOINT')
return {"port": self.preview_port}and now the output which means that a print-like operation (DeprecationWarning) is making everything go down, right? |
|
Apologies, I haven't been working on this myself! It looks like a deprecation warning is triggered by Python 3.12 multiprocessing library as I had suspected. |
|
I stand corrected, the above message of mine contains an error (logging.debug) which raises this DeprecationWarning (it still gives me a headache on how this triggered a warning, but I will not care any more). The corrected code is def preview(self, options: Dict[str, Any]) -> Dict[str, Any]:
if not self.app or not self.app.builder:
return {}
builder_name = self.app.builder.name
if builder_name not in {"html"}:
self.show_message(
f"Previews are not currently supported for the '{builder_name}' builder."
)
return {}
#self.logger.debug('Making sure VSC is executing this file.')
import builtins
import inspect
import warnings
warnings.filterwarnings('ignore')
global gl_logger
gl_logger = self.logger
original_print = print
def custom_print(*args, **kwargs):
stack = inspect.stack()
calling_frame_record = stack[1]
frame = calling_frame_record[0]
info = inspect.getframeinfo(frame)
log_entry = []
for frame_info in stack[1:]: # Skip the first element as it's this custom_print call
filename = frame_info.filename
lineno = frame_info.lineno
function = frame_info.function
code_context = frame_info.code_context[0].strip() if frame_info.code_context else "No context"
log_entry.append(f" File \"{filename}\", line {lineno}, in {function}\n {code_context}")
gl_logger.debug(f'Print called from {info.filename}:{info.lineno}')
gl_logger.debug('\n'.join(log_entry))
gl_logger.debug(' '.join(str(arg) for arg in args))
builtins.print = custom_print
#print('Making sure my print redirection works.')
import traceback
try:
if not self.preview_process and IS_LINUX:
self.logger.debug("Starting preview server.")
server = make_preview_server(self.app.outdir) # type: ignore[arg-type]
#print('Checkpoint 1')
self.preview_port = server.server_port
#print('Checkpoint 2')
self.preview_process = Process(target=server.serve_forever, daemon=True)
self.logger.debug('Checkpoint 3')
self.preview_process.start()
self.logger.debug('Checkpoint 4')
if not self.preview_process and not IS_LINUX:
self.logger.debug("Starting preview server")
q: Queue = Queue()
self.preview_process = Process(
target=start_preview_server, args=(q, self.app.outdir), daemon=True
)
self.preview_process.start()
self.preview_port = q.get()
if options.get("show", True):
#print('Checkpoint 5')
self.show_document(
ShowDocumentParams(
uri=f"http://localhost:{self.preview_port}", external=True
)
)
#print('Checkpoint 6')
except Exception:
exc_msg = traceback.format_exc()
self.logger.debug(exc_msg)
builtins.print = original_print
#self.logger.debug('FINAL CHECKPOINT')
return {"port": self.preview_port}and the output is which apparently is not really helpful, apart from indicating that a rogue print() call is not the issue here. |
|
Hm much more confusing then. |
|
Late last night I also took an effort to see if the fork() method of multiprocessing might be doing something, so I added an multiprocessing.set_start_method('spawn', force=True)after all multiprocessing imports (since I do not have the time to study the code in detail, entry points, etc). I did that because Windows uses spawn() by default. No luck here as well. I will now try to see if the OSes are blocking communication to the server. |
|
After doubtful code changes I was able to verify that the server actually starts. [Error - 11:21:11 AM] Client Esbonio Language Server: connection to server is erroring. Shutting down server. |
|
Thank you for digging into this! I wish I had a better idea on what might be going on... To answer some of the questions I see in the messages above.
It's a message coming from
Unfortunately not, I have never found the VSCode log messages to be that useful :/
Have you managed to get any logs from the server? (i.e. this file), you'd probably have to write them to a text file as I'm not sure if the language server is setup to forward them onto VSCode... Since you said you've also seen this issue on Linux I will see over the next few days if I can reproduce the issue myself. |
|
This is my first time working with VSC, I cannot say if this a regression or not. I do not think I was able to get what you want. I set the logging levels from VSC to debug and also added a line in python to set the logging module to debug, also enabled --log trace in VSC command line and I did not observe anything useful other than the JSONs passed to and fro. My educated guess is that it has to do with the multiprocessing module. Even when I had Esbonio operate in Linux as in Windows (by forcing spawn as the new process generation method and changing some of your code) it would not work. The fact that fork was/is used in Mac and fork is used in Linux makes me think that somewhere in the chain of Python modules this difference causes a problem. Unfortunately, I am nowhere near good enough to detect what is happening. If I had the time to spare, I would try it with Python 3.6. I think that differences in spawn and fork started from 3.7. Due to work and personal schedule, I cannot afford the time to check with such an old Python version this month. But I will do so when I find the time. P.S.: Python will switch to spawn as default from 3.14, even for Linux. |
|
Unfortunately I am unable to reproduce this issue using Python 3.12 on Fedora :/ I agree the issue is likely to do with the multiprocessing. Just to see what would happen I forced the multi-processing method to spawn and while it did fail.... it wasn't the manner you are describing. I had a nice error message about something like It's a long shot, but I don't suppose you have tried it with a blank
If that is the case... perhaps you want to consider trying the pre-release version of Esbonio? As much as I'd love to get to the bottom of this, my focus is on the upcoming major version. It's also worth mentioning that the preview implementation in the pre-release does not rely on multiprocessing so you may have more luck with it. - The trade-off of course, being a pre-release it's going to have it's own set of bugs to contend with 😅 That said, if we do eventually figure out what's going on I'm more than happy to push out a bugfix to resolve this :) |
|
Also if you think there's something I can try on my end to reproduce this please say :) |
alcarney
added
help wanted
|
I have the same issue on Ubuntu 24.04 with kernel 6.8.0-31 using Python 3.12.3 (LSP server is working fine but sort of crash/timeout when I try to preview the rst). I use the "break-system-packages = true" fyi I will try to do some tests to investigate. |
I took your modifications for testing. I changed: self.preview_process = Process(target=server.serve_forever, daemon=True)
print('Checkpoint 3')
self.preview_process.start()with: self.preview_process = threading.Thread(target=server.serve_forever, daemon = True)
print('Checkpoint 3')
self.preview_process.start()and it worked for me ! So @ArgyRad, can you try also and see if it works ? (to avoid the "works on my machine" effect) I haven't started any PR right now because I'm not really aware of the consequences for replacing Process with Thread (other than to be GIL locked which could be awful for preview efficiency). EDIT: I think this is a proof that the bug is related to multiprocessing and avoid it with a thread is not an ideal solution My complete preview function is : def preview(self, options: Dict[str, Any]) -> Dict[str, Any]:
if not self.app or not self.app.builder:
return {}
builder_name = self.app.builder.name
if builder_name not in {"html"}:
self.show_message(
f"Previews are not currently supported for the '{builder_name}' builder."
)
return {}
self.logger.debug('Making sure VSC is executing this file.')
import builtins
import inspect
global gl_logger
gl_logger = self.logger
original_print = print
def custom_print(*args, **kwargs):
stack = inspect.stack()
calling_frame_record = stack[1]
frame = calling_frame_record[0]
info = inspect.getframeinfo(frame)
logging.debug(f"Print called from {info.filename}:{info.lineno}")
gl_logger.debug(' '.join(str(arg) for arg in args))
builtins.print = custom_print
print('Making sure my print redirection works.')
import traceback
try:
if not self.preview_process and IS_LINUX:
self.logger.debug("Starting preview server.")
server = make_preview_server(self.app.outdir) # type: ignore[arg-type]
print('Checkpoint 1')
self.preview_port = server.server_port
print('Checkpoint 2')
self.preview_process = threading.Thread(target=server.serve_forever, daemon=True)
print('Checkpoint 3')
self.preview_process.start()
print('Checkpoint 4')
if not self.preview_process and not IS_LINUX:
self.logger.debug("Starting preview server")
q: Queue = Queue()
self.preview_process = threading.Thread(
target=start_preview_server, args=(q, self.app.outdir), daemon=True
)
self.preview_process.start()
self.preview_port = q.get()
if options.get("show", True):
print('Checkpoint 5')
self.show_document(
ShowDocumentParams(
uri=f"http://localhost:{self.preview_port}", external=True
)
)
print('Checkpoint 6')
except Exception:
exc_msg = traceback.format_exc()
self.logger.debug(exc_msg)
builtins.print = original_print
self.logger.debug('FINAL CHECKPOINT')
return {"port": self.preview_port} |
|
@Nitorac thanks for looking into this!
Using a thread might actually be ok. I don't remember exactly why I did it, but in the upcoming The preview server only needs to serve a handful of requests on each page load which happens relatively infrequently, so I'm assuming the performance requirements are fairly minimal. I'd certainly be happy accepting a PR switching from a Process to a Thread if it fixes the issue :) |
|
I have also run into this issue on Ubuntu 20.04 with Python 3.8. This was my first time installing esbonio. I have been using this machine for awhile, so it could be possible there is some package conflict going on. I didn't put any effort into trying to isolate the issue. |
|
@Nitorac Thanks for getting this figured out. Any update on that PR? |
|
Yep sorry, I was focused on other things ! The hard point for the PR is concerning the killing of the preview server. It's easy to kill a process, but I can't simply kill a thread without killing the entire app, so I have to spend time working around a wrapper to allow a simple "normal forced ending" of the thread, while maintaining the structure for the "Process" part working on any non-Linux workstations. I will try to push something acceptable soon. EDIT: My bad, I wasn't aware of the "shutdown" method for HTTPServer so it's easier than expected EDIT: The pull request is ready for review #837 |
|
Just tested 0.16.5 and it works for me. Thanks to all! |
|
Good to hear ! |
Expected behavior
When starting a preview window, I expect a new window to appear after Sphinx successfully builds the project.
Actual behavior
Sphinx completes the build, but when issuing
esbonio.preview, the server connection errors and times out. I am using the stable version of the esbonio VSCode extension 0.11.0 as the preview does not work, and I cannot cause it to log. I am on a MacBook Pro M1 (2021) with OSX Ventura 13.5.2. Note that I have no issues with the same stack when using my Windows 11 desktop.Log output
(Optional) Settings from conf.py
No response
The text was updated successfully, but these errors were encountered: