Deadlock



  • 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.



  • 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.



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



  • 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?



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



  • 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)
    


  • 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?





  • 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.



  • 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.


Log in to reply
 

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