Playwright: [BUG] Page crashes in headless chromium in Docker

Created on 2 Nov 2020  路  8Comments  路  Source: microsoft/playwright

Context:

  • Playwright Version: 1.5.2 chromium (in 1.4.0 with previous browser version it was fine)
  • Operating System: Ubuntu Bionic
  • Node.js version: 12.18.3
  • Browser: Chromium 88.0.4287.0

Description:
We have tests run in Docker. Image based on official PW image (check the Dockerfile below). From time to time some of tests fail because of page crash (usually during opening website main page after logging in). It happens randomly and I was not able to reproduce it in headless mode. I even don't know how to reproduce it at all. So it has been happening only when run in Docker.

I turned on pw:browser logging and was able to grab browser logs:

2020-11-02T09:35:21.342Z pw:browser [err] [1102/093521.342698:ERROR:bus.cc(393)] Failed to connect to the bus: Failed to connect to socket /var/run/dbus/system_bus_socket: No such file or directory
2020-11-02T09:35:23.307Z pw:browser [err] [1102/093523.307796:ERROR:cert_issuer_source_aia.cc(104)] AiaRequest::OnFetchCompleted got error -301
2020-11-02T09:35:23.308Z pw:browser [err] [1102/093523.308301:ERROR:ssl_client_socket_impl.cc(962)] handshake failed; returned -1, SSL error code 1, net_error -202
2020-11-02T09:35:24.269Z pw:browser [err] Received signal 11 SEGV_MAPERR 7f9adb995000
2020-11-02T09:35:24.343Z pw:browser [err] #0 0x55afd03ae2f9 base::debug::CollectStackTrace()
2020-11-02T09:35:24.358Z pw:browser [err] #1 0x55afd0324743 base::debug::StackTrace::StackTrace()
2020-11-02T09:35:24.414Z pw:browser [err] #2 0x55afd03ade9b base::debug::(anonymous namespace)::StackDumpSignalHandler()
2020-11-02T09:35:24.414Z pw:browser [err] #3 0x7f9adb35f8a0 (/lib/x86_64-linux-gnu/libpthread-2.27.so+0x1289f)
2020-11-02T09:35:24.421Z pw:browser [err] #4 0x55afce35b444 device::OneWriterSeqLock::WriteBegin()
2020-11-02T09:35:24.465Z pw:browser [err] #5 0x55afd17fa079 cc::DroppedFrameCounter::ReportFrames()
2020-11-02T09:35:24.490Z pw:browser [err] #6 0x55afd1845b81 cc::CompositorFrameReporter::TerminateReporter()
2020-11-02T09:35:24.517Z pw:browser [err] #7 0x55afd184559f cc::CompositorFrameReporter::~CompositorFrameReporter()
2020-11-02T09:35:24.540Z pw:browser [err] #8 0x55afd18455ca cc::CompositorFrameReporter::~CompositorFrameReporter()
2020-11-02T09:35:24.566Z pw:browser [err] #9 0x55afd18449b6 base::internal::VectorBuffer<>::DestructRange<>()
2020-11-02T09:35:24.598Z pw:browser [err] #10 0x55afd1844d31 base::circular_deque<>::erase()
2020-11-02T09:35:24.626Z pw:browser [err] #11 0x55afd1844568 cc::CompositorFrameReportingController::DidPresentCompositorFrame()
2020-11-02T09:35:24.655Z pw:browser [err] #12 0x55afd1873ccf cc::ProxyImpl::DidPresentCompositorFrameOnImplThread()
2020-11-02T09:35:24.676Z pw:browser [err] #13 0x55afd1806602 cc::LayerTreeHostImpl::DidPresentCompositorFrame()
2020-11-02T09:35:24.707Z pw:browser [err] #14 0x55afd1b66a70 cc::mojo_embedder::AsyncLayerTreeFrameSink::OnBeginFrame()
2020-11-02T09:35:24.719Z pw:browser [err] #15 0x55afce4973dd viz::mojom::CompositorFrameSinkClientStubDispatch::Accept()
2020-11-02T09:35:24.746Z pw:browser [err] #16 0x55afd0a92696 mojo::InterfaceEndpointClient::HandleValidatedMessage()
2020-11-02T09:35:24.773Z pw:browser [err] #17 0x55afd0a98f98 mojo::internal::MultiplexRouter::ProcessIncomingMessage()
2020-11-02T09:35:24.792Z pw:browser [err] #18 0x55afd0a9879c mojo::internal::MultiplexRouter::Accept()
2020-11-02T09:35:24.824Z pw:browser [err] #19 0x55afd0a90cfe mojo::Connector::DispatchMessage()
2020-11-02T09:35:24.840Z pw:browser [err] #20 0x55afd0a9142e mojo::Connector::ReadAllAvailableMessages()
2020-11-02T09:35:24.861Z pw:browser [err] #21 0x55afd0aa8209 mojo::SimpleWatcher::OnHandleReady()
2020-11-02T09:35:24.893Z pw:browser [err] #22 0x55afd0370bc6 base::TaskAnnotator::RunTask()
2020-11-02T09:35:24.914Z pw:browser [err] #23 0x55afd038173d base::sequence_manager::internal::ThreadControllerWithMessagePumpImpl::DoWorkImpl()
2020-11-02T09:35:25.007Z pw:browser [err] #24 0x55afd0381438 base::sequence_manager::internal::ThreadControllerWithMessagePumpImpl::DoWork()
2020-11-02T09:35:25.040Z pw:browser [err] #25 0x55afd0338b6a base::MessagePumpDefault::Run()
2020-11-02T09:35:25.076Z pw:browser [err] #26 0x55afd0381d5d base::sequence_manager::internal::ThreadControllerWithMessagePumpImpl::Run()
2020-11-02T09:35:25.126Z pw:browser [err] #27 0x55afd035895e base::RunLoop::Run()
2020-11-02T09:35:25.149Z pw:browser [err] #28 0x55afcfef8105 blink::scheduler::WorkerThread::SimpleThreadImpl::Run()
2020-11-02T09:35:25.166Z pw:browser [err] #29 0x55afd03bf17a base::(anonymous namespace)::ThreadFunc()
2020-11-02T09:35:25.166Z pw:browser [err] #30 0x7f9adb3546db start_thread
2020-11-02T09:35:25.166Z pw:browser [err] #31 0x7f9ad59caa3f clone
2020-11-02T09:35:25.166Z pw:browser [err]   r8: 0000000000000003  r9: 0000000000000bf7 r10: 0000000000000006 r11: 0018e64030ddfc9e
2020-11-02T09:35:25.166Z pw:browser [err]  r12: 000000000000002e r13: aaaaaaaaaaaaaaaa r14: 0000014a6353ad48 r15: aaaaaaaaaaaaaaaa
2020-11-02T09:35:25.166Z pw:browser [err]   di: 00007f9adb995000  si: 0000400000000000  bp: 00007f9ac9e63be0  bx: 0000000000000000
2020-11-02T09:35:25.166Z pw:browser [err]   dx: ffff800000000000  ax: 000000000000002e  cx: 0000000000000000  sp: 00007f9ac9e63be0
2020-11-02T09:35:25.167Z pw:browser [err]   ip: 000055afce35b444 efl: 0000000000010206 cgf: aaaa000000000033 erf: 0000000000000006
2020-11-02T09:35:25.167Z pw:browser [err]  trp: 000000000000000e msk: 0000000000000000 cr2: 00007f9adb995000
2020-11-02T09:35:25.167Z pw:browser [err] [end of stack trace]
2020-11-02T09:35:25.167Z pw:browser [err] Calling _exit(1). Core file will not be generated.

Dockerfile:

FROM mcr.microsoft.com/playwright:bionic

USER root

RUN  apt-get update \
     && apt-get install -y gnupg2 \
     && apt-get install -y wget --no-install-recommends \
     && curl -sS https://dl.yarnpkg.com/debian/pubkey.gpg | apt-key add - \
     && echo "deb https://dl.yarnpkg.com/debian/ stable main" | tee /etc/apt/sources.list.d/yarn.list \
     && apt update \
     && apt install yarn \
     && yarn add [email protected]

ENV NODE_TLS_REJECT_UNAUTHORIZED=0

WORKDIR e2e

# Configure yarn
RUN npm set strict-ssl false \
    && export NODE_OPTIONS=--max_old_space_size=4096 \
    && yarn config set registry https://nexus.devops.bfsaws.net/repository/NPMPROXY

COPY package.json /e2e/
COPY yarn.lock /e2e/
COPY tsconfig.json /e2e/
COPY .env.dev-secrets /e2e/

# Restore packages
RUN yarn
P2-bug
Source
picture DJ-Glock
👀2

All 8 comments

Small update:
I've just realised that I performed docker build without --pull flag. So probably base image is outdated and it can be a root cause (doubtfully).
I'll rebuild our image and will see if the issue still exists.

DJ-Glock picture DJ-Glock on 2 Nov 2020

@DJ-Glock its recommended to use the versioned Docker images e.g. docker pull mcr.microsoft.com/playwright:v1.5.2-bionic or docker pull mcr.microsoft.com/playwright:v1.5.2-focal. So these kind of Docker caching issues won't occur.
(lets see if the issues are still reproducible, probably)

mxschmitt picture mxschmitt on 2 Nov 2020

@mxschmitt okay, I changed my Dockerfile to use mcr.microsoft.com/playwright:v1.5.2-bionic. I will keep an eye on tests and will comment here. Let's keep it opened for a week.

DJ-Glock picture DJ-Glock on 2 Nov 2020
👍1

@mxschmitt I've run tests several times after change and finally got a page crash. So it looks like the issue was not in Docker image.

2020-11-02T15:06:14.824Z pw:browser [err] Received signal 11 SEGV_MAPERR 7fed5d377000
2020-11-02T15:06:14.855Z pw:browser [err] #0 0x560ef498d2f9 base::debug::CollectStackTrace()
2020-11-02T15:06:14.927Z pw:browser [err] #1 0x560ef4903743 base::debug::StackTrace::StackTrace()
2020-11-02T15:06:14.959Z pw:browser [err] #2 0x560ef498ce9b base::debug::(anonymous namespace)::StackDumpSignalHandler()
2020-11-02T15:06:14.959Z pw:browser [err] #3 0x7fed5cd418a0 (/lib/x86_64-linux-gnu/libpthread-2.27.so+0x1289f)
2020-11-02T15:06:14.995Z pw:browser [err] #4 0x560ef293a444 device::OneWriterSeqLock::WriteBegin()
2020-11-02T15:06:15.057Z pw:browser [err] #5 0x560ef5dd9079 cc::DroppedFrameCounter::ReportFrames()
2020-11-02T15:06:15.126Z pw:browser [err] #6 0x560ef5e1bd1e cc::FrameSequenceTrackerCollection::StopSequence()
2020-11-02T15:06:15.209Z pw:browser [err] #7 0x560ef5dec3f3 cc::LayerTreeHostImpl::AnimateLayers()
2020-11-02T15:06:15.273Z pw:browser [err] #8 0x560ef5de1104 cc::LayerTreeHostImpl::AnimateInternal()
2020-11-02T15:06:15.329Z pw:browser [err] #9 0x560ef5de8096 cc::LayerTreeHostImpl::WillBeginImplFrame()
2020-11-02T15:06:15.399Z pw:browser [err] #10 0x560ef5e597dd cc::Scheduler::BeginImplFrame()
2020-11-02T15:06:15.454Z pw:browser [err] #11 0x560ef5e59295 cc::Scheduler::BeginImplFrameWithDeadline()
2020-11-02T15:06:15.517Z pw:browser [err] #12 0x560ef5e58844 cc::Scheduler::OnBeginFrameDerivedImpl()
2020-11-02T15:06:15.607Z pw:browser [err] #13 0x560ef5e5d0c3 viz::BeginFrameObserverBase::OnBeginFrame()
2020-11-02T15:06:15.666Z pw:browser [err] #14 0x560ef5e5ec3c viz::ExternalBeginFrameSource::OnBeginFrame()
2020-11-02T15:06:15.748Z pw:browser [err] #15 0x560ef6145b8e cc::mojo_embedder::AsyncLayerTreeFrameSink::OnBeginFrame()
2020-11-02T15:06:15.756Z pw:browser [err] #16 0x560ef2a763dd viz::mojom::CompositorFrameSinkClientStubDispatch::Accept()
2020-11-02T15:06:15.781Z pw:browser [err] [1102/150615.781183:ERROR:cert_issuer_source_aia.cc(104)] AiaRequest::OnFetchCompleted got error -301
2020-11-02T15:06:15.782Z pw:browser [err] [1102/150615.781797:ERROR:ssl_client_socket_impl.cc(962)] handshake failed; returned -1, SSL error code 1, net_error -202
2020-11-02T15:06:15.800Z pw:browser [err] #17 0x560ef5071696 mojo::InterfaceEndpointClient::HandleValidatedMessage()
2020-11-02T15:06:15.831Z pw:browser [err] #18 0x560ef5077f98 mojo::internal::MultiplexRouter::ProcessIncomingMessage()
2020-11-02T15:06:15.861Z pw:browser [err] #19 0x560ef507779c mojo::internal::MultiplexRouter::Accept()
2020-11-02T15:06:15.900Z pw:browser [err] #20 0x560ef506fcfe mojo::Connector::DispatchMessage()
2020-11-02T15:06:15.941Z pw:browser [err] #21 0x560ef507042e mojo::Connector::ReadAllAvailableMessages()
2020-11-02T15:06:15.969Z pw:browser [err] #22 0x560ef5087209 mojo::SimpleWatcher::OnHandleReady()
2020-11-02T15:06:16.001Z pw:browser [err] #23 0x560ef494fbc6 base::TaskAnnotator::RunTask()
2020-11-02T15:06:16.030Z pw:browser [err] #24 0x560ef496073d base::sequence_manager::internal::ThreadControllerWithMessagePumpImpl::DoWorkImpl()
2020-11-02T15:06:16.055Z pw:browser [err] #25 0x560ef4960438 base::sequence_manager::internal::ThreadControllerWithMessagePumpImpl::DoWork()
2020-11-02T15:06:16.073Z pw:browser [err] #26 0x560ef4917b6a base::MessagePumpDefault::Run()
2020-11-02T15:06:16.087Z pw:browser [err] #27 0x560ef4960d5d base::sequence_manager::internal::ThreadControllerWithMessagePumpImpl::Run()
2020-11-02T15:06:16.103Z pw:browser [err] #28 0x560ef493795e base::RunLoop::Run()
2020-11-02T15:06:16.117Z pw:browser [err] #29 0x560ef44d7105 blink::scheduler::WorkerThread::SimpleThreadImpl::Run()
2020-11-02T15:06:16.129Z pw:browser [err] #30 0x560ef499e17a base::(anonymous namespace)::ThreadFunc()
2020-11-02T15:06:16.129Z pw:browser [err] #31 0x7fed5cd366db start_thread
2020-11-02T15:06:16.129Z pw:browser [err] #32 0x7fed573aca3f clone
2020-11-02T15:06:16.129Z pw:browser [err]   r8: 0000000000000003  r9: 00000000000019be r10: 0000000000000006 r11: 0019f4643597dd90
2020-11-02T15:06:16.129Z pw:browser [err]  r12: 0000000000000001 r13: aaaaaaaaaaaaaaaa r14: 00001180a1f22d48 r15: aaaaaaaaaaaaaaaa
2020-11-02T15:06:16.129Z pw:browser [err]   di: 00007fed5d377000  si: 0000000188d8b79d  bp: 00007fed4b845b20  bx: 0000000000000000
2020-11-02T15:06:16.129Z pw:browser [err]   dx: 3ff0000000000000  ax: 0000000000000001  cx: 0000000000000000  sp: 00007fed4b845b20
2020-11-02T15:06:16.129Z pw:browser [err]   ip: 0000560ef293a444 efl: 0000000000010206 cgf: 0000000000000033 erf: 0000000000000006
2020-11-02T15:06:16.129Z pw:browser [err]  trp: 000000000000000e msk: 0000000000000000 cr2: 00007fed5d377000
2020-11-02T15:06:16.129Z pw:browser [err] [end of stack trace]

Just in case, options for launching browser context:

{
      viewport: null,
      ignoreHTTPSErrors: true,
      bypassCSP: true,
      acceptDownloads: true,
      // videosPath: `${path.join(globalRootDir, 'videos')}`,
    }
DJ-Glock picture DJ-Glock on 2 Nov 2020
👍1

This definitely looks like an upstream bug. Thanks for getting a stack trace, it should be very helpful. I just want to confirm some questions so that I can complain to the correct people!

  • You say you can't reproduce this in headless mode? That means you are running it with headless: false yes? Can you paste the full set of browser options here? Also are you running with xvfb?
  • You have the videosPath option commented out. Just to confirm, are videos being recorded when this crash happens?

Also for my own attempts to solve this, I'd like to try to reproduce it locally.

  • How often does the crash happen?
  • Is the website you are logging into public? There is likely some javascript triggering the crash there, so it would be helpful to reproduce.

The code in chromium: https://source.chromium.org/chromium/chromium/src/+/master:device/base/synchronization/one_writer_seqlock.cc;l=65?q=OneWriterSeqLock::WriteBegin&ss=chromium

JoelEinbinder picture JoelEinbinder on 2 Nov 2020

Hey @JoelEinbinder

You say you can't reproduce this in headless mode? That means you are running it with headless: false yes? Can you paste the full set of browser options here? Also are you running with xvfb?

I've been trying to reproduce it by running the same tests in headless mode - headless: true (I guess you made a type) in the same hours when was getting errors in launches in Docker. But was unable to catch any crashes. Probably I tried too few times, not sure. In the same time it could be related to launch options and to Docker itself. I put launching options below. No, not with xvfb. I tried running in headless mode on Windows machine, not linux.

You have the videosPath option commented out. Just to confirm, are videos being recorded when this crash happens?

No, video recording was disabled that times. I tried to use video recording, but faced some issue with tests when video was enabled. It was probably related to CPU workload and video recording itself (we run tests in 8 parallels and tests became unstable when video was enabled). So it could be not related to this issue at all. But I will check tomorrow and see if I would be able to record video with crash.

How often does the crash happen?

Hard to say. It was fine on Friday, but started to occur today again (on Monday).

Is the website you are logging into public? There is likely some javascript triggering the crash there, so it would be helpful to reproduce.

Unfortunately our website is internal. There is a public version, but I am not sure if we will be able to use it to reproduce a bug (corporate policies and so on). But I'll check if it's possible and will get back to you. This crash happens only after logging in:

  1. Open a login page (it's powered by https://identityserver.io).
  2. Enter credentials.
  3. Click Login button to login and be redirected to main page.
  4. Crash (not every time).

I cannot see any errors in a chrome console during the crash or after login. The only error that appears in chrome console happens when login page is being loaded:
Cannot read property 'isExcluded' of undefined
It should be fixed, but does not look critical and happens before login.

I will also try tomorrow to reproduce it with some other site, but not sure if I succeed.

Here is browser launch options. Please note that some of these options are conditional and depends on other variables. In case of running via Docker variable isDocker = true.

const opts: LaunchOptions = {
  headless: argv.headless as boolean, // not passed by default (false)
  slowMo: argv.slowMo as number, // not passed by default (false)
  timeout: 60000,
  args: [
    '--start-maximized',
    '--window-size=1920,1080',
    isDocker && '--no-sandbox',
    isDocker && '--disable-setuid-sandbox',
    isDocker && '--disable-dev-shm-usage',
    '--enable-logging',
    // Flag for running in headful mode via VScode
    // Workaround for issue https://github.com/microsoft/playwright/issues/3148
    (argv.disablegpu as boolean) && '--disable-gpu', // not passed by default (false)
  ].filter(Boolean) as string[],
  logger: {
    isEnabled: name => name === 'api',
    log: (name, severity, message) =>
      console.log(
        `\x1b[1;32m${Generic.getTimeForLog()} [${process.pid}]:`,
        '\x1b[1;35m',
        `${name}:${severity} ${message}`,
        '\x1b[0m'
      ),
  },
};

Browser context options (just in case):

global.globalBrowserContext = await globalBrowser.newContext({
      viewport: null,
      ignoreHTTPSErrors: true,
      bypassCSP: true,
      acceptDownloads: true,
      // videosPath: `${path.join(globalRootDir, 'videos')}`,
    });

Hope it will help.

DJ-Glock picture DJ-Glock on 2 Nov 2020

Update: I was not able to reproduce it with other site and at the moment we cannot use our internal website for it.

DJ-Glock picture DJ-Glock on 3 Nov 2020

@JoelEinbinder did you have a chance to find right right people to address this issue?
Is there anything else I can do to help? To get some other logs pw:protocol?

DJ-Glock picture DJ-Glock on 12 Nov 2020
Was this page helpful?
0 / 5 - 0 ratings

Related issues

etnbrd picture etnbrd  路  4Comments
KevinGrandon picture KevinGrandon  路  4Comments
jperl picture jperl  路  3Comments
saltyshiomix picture saltyshiomix  路  3Comments
kblok picture kblok  路  4Comments