3. Deadlock

Deadlock

  • D

    Yesterday my service tried to render about 90 PDFs at the same time via jsReport (still 2.3.0, self-hosted in a docker container).

    Unfortunately, this didn't work. Instead, I got this exception:

    Transaction (Process ID 69) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.
RequestError: Transaction (Process ID 69) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction. at handleError (/app/node_modules/mssql/lib/tedious.js:544:15) at emitOne (events.js:116:13) at Connection.emit (events.js:211:7) at Parser. (/app/node_modules/tedious/lib/connection.js:618:16) at emitOne (events.js:116:13) at Parser.emit (events.js:211:7) at Parser. (/app/node_modules/tedious/lib/token/token-stream-parser.js:54:15) at emitOne (events.js:116:13) at Parser.emit (events.js:211:7) at addChunk (/app/node_modules/readable-stream/lib/_stream_readable.js:291:12) at readableAddChunk (/app/node_modules/readable-stream/lib/_stream_readable.js:278:11) at Parser.Readable.push (/app/node_modules/readable-stream/lib/_stream_readable.js:245:10) at Parser.Transform.push (/app/node_modules/readable-stream/lib/_stream_transform.js:148:32) at doneParsing (/app/node_modules/tedious/lib/token/stream-parser.js:110:18) at /app/node_modules/tedious/lib/token/infoerror-token-parser.js:46:5 at /app/node_modules/tedious/lib/token/infoerror-token-parser.js:13:19 at /app/node_modules/tedious/lib/token/stream-parser.js:247:9 at Parser.awaitData (/app/node_modules/tedious/lib/token/stream-parser.js:144:9) at Parser.readUInt32LE (/app/node_modules/tedious/lib/token/stream-parser.js:244:12) at /app/node_modules/tedious/lib/token/infoerror-token-parser.js:12:90 at /app/node_modules/tedious/lib/token/stream-parser.js:446:11 at /app/node_modules/tedious/lib/token/stream-parser.js:433:9 at Parser.awaitData (/app/node_modules/tedious/lib/token/stream-parser.js:144:9) at Parser.readBuffer (/app/node_modules/tedious/lib/token/stream-parser.js:430:12) at /app/node_modules/tedious/lib/token/stream-parser.js:445:17 at /app/node_modules/tedious/lib/token/stream-parser.js:170:9 at Parser.awaitData (/app/node_modules/tedious/lib/token/stream-parser.js:144:9) at Parser.readUInt8 (/app/node_modules/tedious/lib/token/stream-parser.js:167:12) at Parser.readBVarChar (/app/node_modules/tedious/lib/token/stream-parser.js:444:12) at /app/node_modules/tedious/lib/token/infoerror-token-parser.js:11:22 at /app/node_modules/tedious/lib/token/stream-parser.js:446:11 at /app/node_modules/tedious/lib/token/stream-parser.js:433:9 at Parser.awaitData (/app/node_modules/tedious/lib/token/stream-parser.js:144:9) at Parser.readBuffer (/app/node_modules/tedious/lib/token/stream-parser.js:430:12) at /app/node_modules/tedious/lib/token/stream-parser.js:445:17 at /app/node_modules/tedious/lib/token/stream-parser.js:170:9 at Parser.awaitData (/app/node_modules/tedious/lib/token/stream-parser.js:144:9) at Parser.readUInt8 (/app/node_modules/tedious/lib/token/stream-parser.js:167:12) at Parser.readBVarChar (/app/node_modules/tedious/lib/token/stream-parser.js:444:12) at /app/node_modules/tedious/lib/token/infoerror-token-parser.js:10:20 at /app/node_modules/tedious/lib/token/stream-parser.js:460:11 at /app/node_modules/tedious/lib/token/stream-parser.js:433:9 at Parser.awaitData (/app/node_modules/tedious/lib/token/stream-parser.js:144:9) at Parser.readBuffer (/app/node_modules/tedious/lib/token/stream-parser.js:430:12) at /app/node_modules/tedious/lib/token/stream-parser.js:459:17 at /app/node_modules/tedious/lib/token/stream-parser.js:203:9 at Parser.awaitData (/app/node_modules/tedious/lib/token/stream-parser.js:144:9) at Parser.readUInt16LE (/app/node_modules/tedious/lib/token/stream-parser.js:200:12) at Parser.readUsVarChar (/app/node_modules/tedious/lib/token/stream-parser.js:458:12) at /app/node_modules/tedious/lib/token/infoerror-token-parser.js:9:18 at /app/node_modules/tedious/lib/token/stream-parser.js:170:9 at Parser.awaitData (/app/node_modules/tedious/lib/token/stream-parser.js:144:9)


+0	Starting rendering request 10049 (user: admin)
+1343	Rendering template { name: stempelkarte20190808, recipe: wkhtmltopdf, engine: handlebars, preview: false }
+2233	Inline data specified.
+2349	Resources not defined for this template.
+8112	Replaced assets ["archivonarrow-regular-webfont.woff","archivonarrow-bold-webfont.woff","styles20190808.css"]
+9802	Replaced assets ["helper20190808.js"]
+10346	Base url not specified, skipping its injection.
+10436	Rendering engine handlebars
+10955	Taking compiled template from engine cache
+11178	Executing recipe wkhtmltopdf
+11254	Starting child request to render pdf header
+11254	Starting rendering request 10125 (user: admin)
+12029	Rendering template { name: stempelkarte20190808, recipe: html, engine: handlebars, preview: false }
+12416	Inline data specified.
+12464	Resources not defined for this template.
+15598	Base url not specified, skipping its injection.
+15716	Rendering engine handlebars
+17167	Taking compiled template from engine cache
+18705	Executing recipe html
+19175	Skipping storing report.
+20112	Rendering request 10125 finished in 8858 ms
+20704	Starting child request to render pdf footer
+20714	Starting rendering request 10170 (user: admin)
+22065	Rendering template { name: stempelkarte20190808, recipe: html, engine: handlebars, preview: false }
+22776	Inline data specified.
+22919	Resources not defined for this template.
+35366	Replaced assets ["archivonarrow-regular-webfont.woff","archivonarrow-bold-webfont.woff"]
+39524	Base url not specified, skipping its injection.
+40242	Rendering engine handlebars
+41126	Taking compiled template from engine cache
+44188	Executing recipe html
+44625	Skipping storing report.
+47679	Rendering request 10170 finished in 26965 ms
+52457	wkhtmltopdf --debug-javascript --disable-local-file-access --javascript-delay 1 --page-height 297mm --page-width 210mm --margin-bottom 14mm --margin-left 10mm --margin-right 10mm --margin-top 10mm --header-spacing 0 --header-html file:////tmp/jsreport/autocleanup/f57fc6e5-270f-42ee-9d14-71ec9d50708cheader.html --footer-spacing 0 --footer-html file:////tmp/jsreport/autocleanup/f57fc6e5-270f-42ee-9d14-71ec9d50708cfooter.html --print-media-type /tmp/jsreport/autocleanup/f57fc6e5-270f-42ee-9d14-71ec9d50708c.html /tmp/jsreport/autocleanup/f57fc6e5-270f-42ee-9d14-71ec9d50708c.pdf
+75399	Loading pages (1/6) [> ] 0% [======> ] 10% [==============================> ] 50% [========================================> ] 68% [================================================> ] 81% [============================================================] 100% Counting pages (2/6) [============================================================] Object 1 of 1 Resolving links (4/6) [============================================================] Object 1 of 1 Loading headers and footers (5/6) [===> ] 5% [======> ] 10% [==================> ] 30% [=================================> ] 55% [=============================================> ] 75% [============================================================] 100% Printing pages (6/6) [> ] Preparing [============================================================] Page 1 of 1 Done

    Seems like the rendering worked, but some SQL command (I can't figure out what) had a problem.
    Is this a known issue?

    I couldn't find anything relating to my issue in the changelog. So it doesn't look like this has been resolved and a simple update would help.

    0

  • Do you a specific isolation level in your db?

    jsreport mssql store driver uses just the implicit transactions. I would guess these can't deadlock.
    I tried many parallel requests with my mssql and it seems to work fine.

    0
  • D

    I use an Azure SQL DB.
    This leads to a relatively low max. connection count of 300.

    0

  • Just the default one? Have you run some alters like ALTER DATABASE CURRENT SET ALLOW_SNAPSHOT_ISOLATION ON; or something like that?
    Do you have other software using that database?

    0
  • D

    Nothing else uses the DB and I've never touched that db myself

    0

  • What azure SQL layer do you use? I have an S0 layer in azure and a test like this. No deadlock.
    Please try the same and help me isolating your problem.

    const client = require('jsreport-client')('http://localhost:5488')
const Promise = require('bluebird')

function run (i) {
  return client.render({
    template: {
      name: 'invoice-main'    
    }
  }).then(() => console.log(i))
}

function runMany () {
  const promises = []
  for (let i = 0; i < 60; i++) {
    promises.push(run(i))
  }

  return Promise.all(promises)
}

runMany().then(() => console.log('done')).catch(console.error)
    0
  • D

    I'm using the basic tier. This means I only got 5 DTUs at my disposal.

    Could you provide me the invoice-main template so I can run the experiment?

    0

  • Here for example https://playground.jsreport.net/w/admin/hBfqC7af

    0
  • D

    ok, when I try that, I get a timeout exception:

    Timeout Error: pdf generation not completed after 30000ms
Error: Timeout Error: pdf generation not completed after 30000ms at Timeout.setTimeout (/app/node_modules/jsreport-chrome-pdf/lib/conversion.js:122:19) at ontimeout (timers.js:498:11) at tryOnTimeout (timers.js:323:5) at Timer.listOnTimeout (timers.js:290:5)


+0	Starting rendering request 7127 (user: admin)
+861	Rendering template { name: Invoice, recipe: chrome-pdf, engine: handlebars, preview: false }
+1029	Adding sample data B1Ns-r1M
+1032	Resources not defined for this template.
+2049	Replaced assets ["Invoice styles.css," "Invoice logo.png"]
+2461	Base url not specified, skipping its injection.
+2497	Rendering engine handlebars
+2727	Taking compiled template from engine cache
+2729	Calculating item Website design; you should see this message in debug run
+4167	Executing recipe chrome-pdf
+23423	Converting with chrome HeadlessChrome/72.0.3626.14 using dedicated-process strategy

    However, I can create an invoice pdf, if I try it in the jsReport web application.
    I can also successfully create a single pdf with your sample client.

    0

  • Yes, this problem is fine. It just spawns too many chrome processes and timeouts on some.
    This can be solved using configuration to limit number of chrome processes
    https://jsreport.net/learn/chrome-pdf#reuse-chrome-instances

    or by some throttling, before jsreport is called, but it has nothing to do with deadlock.

    0
Log in to reply
 

Looks like your connection to jsreport forum was lost, please wait while we try to reconnect.