Infinite wait when using Chromium installed via Snap

[kristianLundkvist]

Current behavior: Ubuntu have decided to install Chromium using Snap and this causes the PDF generation to quietly fail. Unless you pass arguments to get a more detailed log it will simply display Generating PDF, please be patient... until the process is manually killed. Using debian packages resolves the issue, this method to be precise.

Expected behavior: Since the issue isn't really caused by mdbook-pdf, a note in the README about it and how to manually resolve it would suffice. A bonus would be some way of detecting that chrome failed to start properly, displaying this to the user with a link to the issue and the solution but this might not be feasible.

Logs:

Generated using RUST_BACKTRACE=full RUST_LOG=trace mdbook build, shortened to the relevant part.

Generating PDF, please be patient...
[2023-02-15T10:24:20Z TRACE headless_chrome::browser::process] Chrome will have profile: --user-data-dir=/tmp/rust-headless-chrome-profilexjCsX9
[2023-02-15T10:24:20Z INFO  headless_chrome::browser::process] Launching Chrome binary at "/snap/bin/chromium"
[2023-02-15T10:24:20Z INFO  headless_chrome::browser::process] Started Chrome. PID: 40118
[2023-02-15T10:24:20Z TRACE headless_chrome::browser::process] Chrome output: ERROR: ld.so: object '/usr/local/lib/AppProtection/libAppProtection.so' from /etc/ld.so.preload cannot be preloaded (failed to map segment from shared object): ignored.
[2023-02-15T10:24:20Z TRACE headless_chrome::browser::process] Chrome output: ERROR: ld.so: object '/usr/local/lib/AppProtection/libAppProtection.so' from /etc/ld.so.preload cannot be preloaded (cannot open shared object file): ignored.

[HollowMan6]

Hi! Thanks for reporting this. Unfortunately this looks like an issue with mdbook-pdf's dependency rust-headless-chrome, as I can't see any issue related to snap at their side and actually chromium has already been released as a snap package for a long time, I would assume that this is related to this issue as well: https://github.com/atroche/rust-headless-chrome/issues/367 I'll try to bump the version of our rust-headless-chrome to see if it can get fixed.

By the way, I would like to mention that infinite wait won't happen, as I just extend the wait time to 10 min, so that it would also work in the CI for generating some very large PDF books. It would eventually fail in 10 min.

[HollowMan6]

I can reproduce your issue with current version of mdbook-pdf under chrome 110, even it's not installed by snap. Will work on this now.

[HollowMan6]

Hi! I think this should have already been resolved, you can build mdbook-pdf again to use new version of rust-headless-chrome by cargo install -f mdbook-pdf

[kristianLundkvist]

Thanks for the quick response. I still have the same issue, even with the latest version of rust-headless-chrome (v0.1.4 according to cargo). The log created when running with the snap version (110):

[2023-02-15T13:46:52Z TRACE headless_chrome::browser::process] Chrome will have profile: --user-data-dir=/tmp/rust-headless-chrome-profilemWmmKy
[2023-02-15T13:46:52Z INFO  headless_chrome::browser::process] Launching Chrome binary at "/snap/bin/chromium"
[2023-02-15T13:46:52Z INFO  headless_chrome::browser::process] Started Chrome. PID: 84072
[2023-02-15T13:46:52Z TRACE headless_chrome::browser::process] Chrome output: ERROR: ld.so: object '/usr/local/lib/AppProtection/libAppProtection.so' from /etc/ld.so.preload cannot be preloaded (failed to map segment from shared object): ignored.
[2023-02-15T13:46:52Z TRACE headless_chrome::browser::process] Chrome output: ERROR: ld.so: object '/usr/local/lib/AppProtection/libAppProtection.so' from /etc/ld.so.preload cannot be preloaded (cannot open shared object file): ignored.
[2023-02-15T13:46:52Z TRACE headless_chrome::browser::process] Chrome output: ERROR: ld.so: object '/usr/local/lib/AppProtection/libAppProtection.so' from /etc/ld.so.preload cannot be preloaded (cannot open shared object file): ignored.
[2023-02-15T13:46:52Z TRACE headless_chrome::browser::process] Chrome output: ERROR: ld.so: object '/usr/local/lib/AppProtection/libAppProtection.so' from /etc/ld.so.preload cannot be preloaded (cannot open shared object file): ignored.
[2023-02-15T13:46:52Z TRACE headless_chrome::browser::process] Chrome output: ERROR: ld.so: object '/usr/local/lib/AppProtection/libAppProtection.so' from /etc/ld.so.preload cannot be preloaded (cannot open shared object file): ignored.
[2023-02-15T13:46:52Z TRACE headless_chrome::browser::process] Chrome output: ERROR: ld.so: object '/usr/local/lib/AppProtection/libAppProtection.so' from /etc/ld.so.preload cannot be preloaded (cannot open shared object file): ignored.
[2023-02-15T13:46:52Z TRACE headless_chrome::browser::process] Chrome output: ERROR: ld.so: object '/usr/local/lib/AppProtection/libAppProtection.so' from /etc/ld.so.preload cannot be preloaded (cannot open shared object file): ignored.
[2023-02-15T13:46:52Z TRACE headless_chrome::browser::process] Chrome output: ERROR: ld.so: object '/usr/local/lib/AppProtection/libAppProtection.so' from /etc/ld.so.preload cannot be preloaded (cannot open shared object file): ignored.
[2023-02-15T13:46:52Z TRACE headless_chrome::browser::process] Chrome output: ERROR: ld.so: object '/usr/local/lib/AppProtection/libAppProtection.so' from /etc/ld.so.preload cannot be preloaded (cannot open shared object file): ignored.
[2023-02-15T13:46:52Z TRACE headless_chrome::browser::process] Chrome output: ERROR: ld.so: object '/usr/local/lib/AppProtection/libAppProtection.so' from /etc/ld.so.preload cannot be preloaded (cannot open shared object file): ignored.
[2023-02-15T13:46:52Z TRACE headless_chrome::browser::process] Chrome output: ERROR: ld.so: object '/usr/local/lib/AppProtection/libAppProtection.so' from /etc/ld.so.preload cannot be preloaded (cannot open shared object file): ignored.
[2023-02-15T13:46:52Z TRACE headless_chrome::browser::process] Chrome output: ERROR: ld.so: object '/usr/local/lib/AppProtection/libAppProtection.so' from /etc/ld.so.preload cannot be preloaded (cannot open shared object file): ignored.
[2023-02-15T13:46:52Z TRACE headless_chrome::browser::process] Chrome output: ERROR: ld.so: object '/usr/local/lib/AppProtection/libAppProtection.so' from /etc/ld.so.preload cannot be preloaded (cannot open shared object file): ignored.
[2023-02-15T13:46:52Z TRACE headless_chrome::browser::process] Chrome output: ERROR: ld.so: object '/usr/local/lib/AppProtection/libAppProtection.so' from /etc/ld.so.preload cannot be preloaded (cannot open shared object file): ignored.
[2023-02-15T13:46:52Z TRACE headless_chrome::browser::process] Chrome output: ERROR: ld.so: object '/usr/local/lib/AppProtection/libAppProtection.so' from /etc/ld.so.preload cannot be preloaded (cannot open shared object file): ignored.
[2023-02-15T13:46:52Z TRACE headless_chrome::browser::process] Chrome output: ERROR: ld.so: object '/usr/local/lib/AppProtection/libAppProtection.so' from /etc/ld.so.preload cannot be preloaded (cannot open shared object file): ignored.
[2023-02-15T13:46:52Z TRACE headless_chrome::browser::process] Chrome output: ERROR: ld.so: object '/usr/local/lib/AppProtection/libAppProtection.so' from /etc/ld.so.preload cannot be preloaded (cannot open shared object file): ignored.
[2023-02-15T13:46:52Z TRACE headless_chrome::browser::process] Chrome output: ERROR: ld.so: object '/usr/local/lib/AppProtection/libAppProtection.so' from /etc/ld.so.preload cannot be preloaded (cannot open shared object file): ignored.
[2023-02-15T13:46:52Z TRACE headless_chrome::browser::process] Chrome output: ERROR: ld.so: object '/usr/local/lib/AppProtection/libAppProtection.so' from /etc/ld.so.preload cannot be preloaded (cannot open shared object file): ignored.
[2023-02-15T13:46:52Z TRACE headless_chrome::browser::process] Chrome output: ERROR: ld.so: object '/usr/local/lib/AppProtection/libAppProtection.so' from /etc/ld.so.preload cannot be preloaded (cannot open shared object file): ignored.
[2023-02-15T13:46:52Z TRACE headless_chrome::browser::process] Chrome output: 
[2023-02-15T13:46:52Z TRACE headless_chrome::browser::process] Chrome output: DevTools listening on ws://127.0.0.1:8912/devtools/browser/8d3623f0-2802-4add-86cc-87a91ff5c170
[2023-02-15T13:46:52Z DEBUG headless_chrome::browser::process] Found debugging WS URL: Url { scheme: "ws", cannot_be_a_base: false, username: "", password: None, host: Some(Ipv4(127.0.0.1)), port: Some(8912), path: "/devtools/browser/8d3623f0-2802-4add-86cc-87a91ff5c170", query: None, fragment: None }
[2023-02-15T13:46:52Z DEBUG tungstenite::client] Trying to contact ws://127.0.0.1:8912/devtools/browser/8d3623f0-2802-4add-86cc-87a91ff5c170 at 127.0.0.1:8912...
[2023-02-15T13:46:52Z TRACE tungstenite::handshake::client] Request: "GET /devtools/browser/8d3623f0-2802-4add-86cc-87a91ff5c170 HTTP/1.1\r\nHost: 127.0.0.1:8912\r\nConnection: Upgrade\r\nUpgrade: websocket\r\nSec-WebSocket-Version: 13\r\nSec-WebSocket-Key: nMYb8rK3isVPyUMSyI5TqQ==\r\n\r\n"
[2023-02-15T13:46:52Z TRACE tungstenite::handshake::client] Client handshake initiated.
[2023-02-15T13:46:52Z TRACE tungstenite::handshake::machine] Doing handshake round.
[2023-02-15T13:46:52Z TRACE tungstenite::handshake::machine] Doing handshake round.
[2023-02-15T13:46:52Z DEBUG tungstenite::handshake::client] Client handshake done.
[2023-02-15T13:46:52Z DEBUG headless_chrome::browser::transport::web_socket_connection] Successfully connected to WebSocket: ws://127.0.0.1:8912/devtools/browser/8d3623f0-2802-4add-86cc-87a91ff5c170
[2023-02-15T13:46:52Z TRACE headless_chrome::browser::transport] Starting handle_incoming_messages
[2023-02-15T13:46:52Z TRACE headless_chrome::browser::transport::web_socket_connection] Starting msg dispatching loop
[2023-02-15T13:46:52Z TRACE tungstenite::protocol] Frames still in queue: 0
[2023-02-15T13:46:52Z TRACE headless_chrome::browser] created browser event listener
[2023-02-15T13:46:52Z TRACE headless_chrome::browser] Calling set discover
[2023-02-15T13:46:52Z TRACE headless_chrome::browser::transport] Inside handle_incoming_messages thread
[2023-02-15T13:46:52Z TRACE headless_chrome::browser::transport::waiting_call_registry] registered 0
[2023-02-15T13:46:52Z TRACE headless_chrome::browser] Starting browser's event handling loop
[2023-02-15T13:46:53Z TRACE tungstenite::protocol] Frames still in queue: 1
[2023-02-15T13:46:53Z TRACE tungstenite::protocol] Sending frame: Frame { header: FrameHeader { is_final: true, rsv1: false, rsv2: false, rsv3: false, opcode: Data(Text), mask: Some([180, 254, 121, 105]) }, payload: [123, 34, 109, 101, 116, 104, 111, 100, 34, 58, 34, 84, 97, 114, 103, 101, 116, 46, 115, 101, 116, 68, 105, 115, 99, 111, 118, 101, 114, 84, 97, 114, 103, 101, 116, 115, 34, 44, 34, 105, 100, 34, 58, 48, 44, 34, 112, 97, 114, 97, 109, 115, 34, 58, 123, 34, 100, 105, 115, 99, 111, 118, 101, 114, 34, 58, 116, 114, 117, 101, 125, 125] }
[2023-02-15T13:46:53Z TRACE tungstenite::protocol::frame] writing frame 
    <FRAME>
    final: true
    reserved: false false false
    opcode: TEXT
    length: 78
    payload length: 72
    payload: 0x7b226d6574686f64223a225461726765742e736574446973636f76657254617267657473222c226964223a302c22706172616d73223a7b22646973636f766572223a747275657d7d

[2023-02-15T13:46:53Z TRACE headless_chrome::browser::transport] sent method call to browser via websocket
[2023-02-15T13:46:53Z TRACE tungstenite::protocol] Frames still in queue: 0
[2023-02-15T13:46:53Z TRACE headless_chrome::browser::transport] waiting for response from call registry: 0 "SetDiscoverTargets { discover: true }"
[2023-02-15T13:46:53Z TRACE tungstenite::protocol::frame::frame] Parsed headers [129, 20]
[2023-02-15T13:46:53Z TRACE tungstenite::protocol::frame::frame] First: 10000001
[2023-02-15T13:46:53Z TRACE tungstenite::protocol::frame::frame] Second: 10100
[2023-02-15T13:46:53Z TRACE tungstenite::protocol::frame::frame] Opcode: Data(Text)
[2023-02-15T13:46:53Z TRACE tungstenite::protocol::frame::frame] Masked: false
[2023-02-15T13:46:53Z TRACE tungstenite::protocol::frame] received frame 
    <FRAME>
    final: true
    reserved: false false false
    opcode: TEXT
    length: 22
    payload length: 20
    payload: 0x7b226964223a302c22726573756c74223a7b7d7d

[2023-02-15T13:46:53Z TRACE tungstenite::protocol] Received message {"id":0,"result":{}}
[2023-02-15T13:46:53Z TRACE tungstenite::protocol] Frames still in queue: 0
[2023-02-15T13:46:53Z TRACE headless_chrome::browser::transport::waiting_call_registry] Resolving call
[2023-02-15T13:46:53Z TRACE headless_chrome::browser::transport] received response for: 0 "SetDiscoverTargets { discover: true }"
[2023-02-15T13:46:53Z TRACE tungstenite::protocol] Frames still in queue: 0
[2023-02-15T13:46:53Z TRACE tungstenite::protocol] Frames still in queue: 0
[2023-02-15T13:46:53Z TRACE tungstenite::protocol] Frames still in queue: 0
[2023-02-15T13:46:53Z TRACE tungstenite::protocol] Frames still in queue: 0
[2023-02-15T13:46:54Z TRACE tungstenite::protocol] Frames still in queue: 0
[2023-02-15T13:46:54Z TRACE tungstenite::protocol] Frames still in queue: 0
[2023-02-15T13:46:54Z TRACE tungstenite::protocol] Frames still in queue: 0
[2023-02-15T13:46:54Z TRACE tungstenite::protocol] Frames still in queue: 0
[2023-02-15T13:46:54Z TRACE tungstenite::protocol] Frames still in queue: 0
[2023-02-15T13:46:55Z TRACE tungstenite::protocol] Frames still in queue: 0
[2023-02-15T13:46:55Z TRACE tungstenite::protocol] Frames still in queue: 0
[2023-02-15T13:46:55Z TRACE tungstenite::protocol] Frames still in queue: 0
[2023-02-15T13:46:55Z TRACE tungstenite::protocol] Frames still in queue: 0
[2023-02-15T13:46:55Z TRACE tungstenite::protocol] Frames still in queue: 0
[2023-02-15T13:46:56Z TRACE tungstenite::protocol] Frames still in queue: 0

I also have the log from the debian version (90), it's much longer but I can provide it if you want it. I technically have a workaround as mentioned in the issue but something funky is going on and it has gotten my inquisitiveness started, if you need any more information I'll happily provide whatever you need.

[HollowMan6]

That's interesting. Technically I would say that it would be something related to rust-headless-chrome, and I'm afraid I can't help you more. I have already updated rust-headless-chrome to the latest version, and I can't find an issue related to snap chromium at their side. I'll try to reproduce this and meanwhile you can open an issue there to see if there's some kind of solution.

[HollowMan6]

Hi! I don't think there's any issue using the snap chromium with mdbook-pdf. I have tested the snap chromium to generate pdf file using the vagrant file I just committed to the master branch and everything works well. I would assume that it's because something related to your snapd is broken, and I will close this issue since I can't reproduce this.

[kristianLundkvist]

Fair enough, thanks for looking into it, appreciate the effort!