Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Version 4.17.0 + fail #557

Closed
Demosteneus opened this issue Jan 15, 2024 · 22 comments
Closed

Version 4.17.0 + fail #557

Demosteneus opened this issue Jan 15, 2024 · 22 comments

Comments

@Demosteneus
Copy link
Contributor

Hi,

All sp versions after 4.16.0 are failing with errors.
Version 4.16.0 works
Starting with 4.17.0 all are failing with below errors:
I mention, I am running the Windows version.

<Status><Error code="1">Error executing sdluatex (bin\sdluatex.exe)</Error><Errors>1</Errors></Status>

in terminal I get below errors:

Run speedata publisher 4.17.4
runtime: VirtualAlloc of 19177472 bytes failed with errno=1455
fatal error: out of memory

runtime stack:
runtime.throw({0x58a4aa10?, 0xc17bbde000?})
        /usr/local/go/src/runtime/panic.go:1077 +0x65 fp=0x10ff1b8 sp=0x10ff188 pc=0x58837de5
runtime.sysUsedOS(0xc17bb8c000, 0x124a000)
        /usr/local/go/src/runtime/mem_windows.go:83 +0x1bb fp=0x10ff218 sp=0x10ff1b8 pc=0x5881771b
runtime.sysUsed(...)
        /usr/local/go/src/runtime/mem.go:77
runtime.(*mheap).allocSpan(0x58be9dc0, 0x925, 0x0, 0x85?)
        /usr/local/go/src/runtime/mheap.go:1351 +0x487 fp=0x10ff2b8 sp=0x10ff218 pc=0x58828d27
runtime.(*mheap).alloc.func1()
        /usr/local/go/src/runtime/mheap.go:968 +0x5c fp=0x10ff300 sp=0x10ff2b8 pc=0x588284dc
traceback: unexpected SPWRITE function runtime.systemstack
runtime.systemstack()
        /usr/local/go/src/runtime/asm_amd64.s:509 +0x49 fp=0x10ff310 sp=0x10ff300 pc=0x58864a89

goroutine 17 [running, locked to thread]:
runtime.systemstack_switch()
        /usr/local/go/src/runtime/asm_amd64.s:474 +0x8 fp=0xc001a50480 sp=0xc001a50470 pc=0x58864a28
runtime.(*mheap).alloc(0x124a000?, 0x925?, 0x0?)
        /usr/local/go/src/runtime/mheap.go:962 +0x5b fp=0xc001a504c8 sp=0xc001a50480 pc=0x5882843b
runtime.(*mcache).allocLarge(0x0?, 0x124a000, 0x0?)
        /usr/local/go/src/runtime/mcache.go:234 +0x85 fp=0xc001a50510 sp=0xc001a504c8 pc=0x588165e5
runtime.mallocgc(0x124a000, 0x0, 0x0)
        /usr/local/go/src/runtime/malloc.go:1127 +0x4f6 fp=0xc001a50578 sp=0xc001a50510 pc=0x5880dcf6
runtime.growslice(0xc159180000, 0x7?, 0xc000028820?, 0xc001a50628?, 0x588c0a7e?)
        /usr/local/go/src/runtime/slice.go:266 +0x4cf fp=0xc001a505e8 sp=0xc001a50578 pc=0x5884c92f
strings.(*Builder).Write(0xc14b975f80, {0xc17abba000, 0xfd0d88, 0xc001a50838?})
        /usr/local/go/src/strings/builder.go:91 +0x8b fp=0xc001a50638 sp=0xc001a505e8 pc=0x588a33ab
fmt.Fprintf({0x58aa7bc0, 0xc14b975f80}, {0x58a446a3, 0x2}, {0xc001a50838, 0x1, 0x1})
        /usr/local/go/src/fmt/print.go:225 +0x97 fp=0xc001a50698 sp=0xc001a50638 pc=0x588c0f77
speedatapublisher/splibaux.readXMLFile({0x58aa7b20?, 0xc000046248}, 0x2, 0x23)
        /tmp/publisher-git/src/go/splibaux/xmlparser.go:55 +0x1705 fp=0xc001a50bf8 sp=0xc001a50698 pc=0x589a3f45
speedatapublisher/splibaux.handleXInclude({0xc14bb13ac0?, 0xc0012392e0?}, 0x0?, 0x0?)
        /tmp/publisher-git/src/go/splibaux/splibaux.go:295 +0x5d fp=0xc001a50c38 sp=0xc001a50bf8 pc=0x589a261d
speedatapublisher/splibaux.readXMLFile({0x58aa7b20?, 0xc0000e40b8}, 0x2, 0x7)
        /tmp/publisher-git/src/go/splibaux/xmlparser.go:51 +0x16a5 fp=0xc001a51198 sp=0xc001a50c38 pc=0x589a3ee5
speedatapublisher/splibaux.handleXInclude({0xc0011cb9b0?, 0xc0011371c0?}, 0x0?, 0x0?)
        /tmp/publisher-git/src/go/splibaux/splibaux.go:295 +0x5d fp=0xc001a511d8 sp=0xc001a51198 pc=0x589a261d
speedatapublisher/splibaux.readXMLFile({0x58aa7b20?, 0xc0000e40b0}, 0x6, 0x2)
        /tmp/publisher-git/src/go/splibaux/xmlparser.go:51 +0x16a5 fp=0xc001a51738 sp=0xc001a511d8 pc=0x589a3ee5
speedatapublisher/splibaux.handleXInclude({0xc00113dab8?, 0xc00004b920?}, 0x0?, 0x0?)
        /tmp/publisher-git/src/go/splibaux/splibaux.go:295 +0x5d fp=0xc001a51778 sp=0xc001a51738 pc=0x589a261d
speedatapublisher/splibaux.readXMLFile({0x58aa7b20?, 0xc000046198}, 0x1, 0x0)
        /tmp/publisher-git/src/go/splibaux/xmlparser.go:51 +0x16a5 fp=0xc001a51cd8 sp=0xc001a51778 pc=0x589a3ee5
speedatapublisher/splibaux.ReadXMLFile({0xc0002b97c0?, 0xc000045dc8?})
        /tmp/publisher-git/src/go/splibaux/splibaux.go:306 +0x4a fp=0xc001a51d48 sp=0xc001a51cd8 pc=0x589a26aa
main.sdReadXMLFile(0x0?)
        /tmp/publisher-git/src/go/splib/splib.go:299 +0x34 fp=0xc001a51e10 sp=0xc001a51d48 pc=0x589abeb4
_cgoexp_1875e5957e34_sdReadXMLFile(0x10ff450)
        _cgo_gotypes.go:248 +0x1e fp=0xc001a51e30 sp=0xc001a51e10 pc=0x589ace5e
runtime.cgocallbackg1(0x589ace40, 0xc000045fe0?, 0x0)
        /usr/local/go/src/runtime/cgocall.go:329 +0x2c2 fp=0xc001a51f00 sp=0xc001a51e30 pc=0x58805682
runtime.cgocallbackg(0x0?, 0x0?, 0x0?)
        /usr/local/go/src/runtime/cgocall.go:245 +0x109 fp=0xc001a51f90 sp=0xc001a51f00 pc=0x588052e9
runtime.cgocallbackg(0x589ace40, 0x10ff450, 0x0)
        <autogenerated>:1 +0x2e fp=0xc001a51fb8 sp=0xc001a51f90 pc=0x5886b36e
runtime.cgocallback(0x0, 0x0, 0x0)
        /usr/local/go/src/runtime/asm_amd64.s:1035 +0xec fp=0xc001a51fe0 sp=0xc001a51fb8 pc=0x588667ec
runtime.goexit()
        /usr/local/go/src/runtime/asm_amd64.s:1650 +0x1 fp=0xc001a51fe8 sp=0xc001a51fe0 pc=0x58866a61

goroutine 6 [GC worker (idle)]:
runtime.gopark(0xc0d83218184?, 0x3?, 0x0?, 0x0?, 0x0?)
        /usr/local/go/src/runtime/proc.go:398 +0xce fp=0xc000045f50 sp=0xc000045f30 pc=0x5883aaee
runtime.gcBgMarkWorker()
        /usr/local/go/src/runtime/mgc.go:1295 +0xe5 fp=0xc000045fe0 sp=0xc000045f50 pc=0x5881bee5
runtime.goexit()
        /usr/local/go/src/runtime/asm_amd64.s:1650 +0x1 fp=0xc000045fe8 sp=0xc000045fe0 pc=0x58866a61
created by runtime.gcBgMarkStartWorkers in goroutine 17
        /usr/local/go/src/runtime/mgc.go:1219 +0x1c

goroutine 2 [force gc (idle)]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
        /usr/local/go/src/runtime/proc.go:398 +0xce fp=0xc00003ffa8 sp=0xc00003ff88 pc=0x5883aaee
runtime.goparkunlock(...)
        /usr/local/go/src/runtime/proc.go:404
runtime.forcegchelper()
        /usr/local/go/src/runtime/proc.go:322 +0xb8 fp=0xc00003ffe0 sp=0xc00003ffa8 pc=0x5883a978
runtime.goexit()
        /usr/local/go/src/runtime/asm_amd64.s:1650 +0x1 fp=0xc00003ffe8 sp=0xc00003ffe0 pc=0x58866a61
created by runtime.init.6 in goroutine 1
        /usr/local/go/src/runtime/proc.go:310 +0x1a

goroutine 3 [GC sweep wait]:
runtime.gopark(0x1?, 0x0?, 0x0?, 0x0?, 0x0?)
        /usr/local/go/src/runtime/proc.go:398 +0xce fp=0xc000041f78 sp=0xc000041f58 pc=0x5883aaee
runtime.goparkunlock(...)
        /usr/local/go/src/runtime/proc.go:404
runtime.bgsweep(0x0?)
        /usr/local/go/src/runtime/mgcsweep.go:321 +0xdf fp=0xc000041fc8 sp=0xc000041f78 pc=0x5882519f
runtime.gcenable.func1()
        /usr/local/go/src/runtime/mgc.go:200 +0x25 fp=0xc000041fe0 sp=0xc000041fc8 pc=0x5881a4e5
runtime.goexit()
        /usr/local/go/src/runtime/asm_amd64.s:1650 +0x1 fp=0xc000041fe8 sp=0xc000041fe0 pc=0x58866a61
created by runtime.gcenable in goroutine 1
        /usr/local/go/src/runtime/mgc.go:200 +0x66

goroutine 4 [GC scavenge wait]:
runtime.gopark(0xf4a808?, 0xfeb523?, 0x0?, 0x0?, 0x0?)
        /usr/local/go/src/runtime/proc.go:398 +0xce fp=0xc000051f70 sp=0xc000051f50 pc=0x5883aaee
runtime.goparkunlock(...)
        /usr/local/go/src/runtime/proc.go:404
runtime.(*scavengerState).park(0x58bd4420)
        /usr/local/go/src/runtime/mgcscavenge.go:425 +0x49 fp=0xc000051fa0 sp=0xc000051f70 pc=0x58822a29
runtime.bgscavenge(0x0?)
        /usr/local/go/src/runtime/mgcscavenge.go:658 +0x59 fp=0xc000051fc8 sp=0xc000051fa0 pc=0x58822fd9
runtime.gcenable.func2()
        /usr/local/go/src/runtime/mgc.go:201 +0x25 fp=0xc000051fe0 sp=0xc000051fc8 pc=0x5881a485
runtime.goexit()
        /usr/local/go/src/runtime/asm_amd64.s:1650 +0x1 fp=0xc000051fe8 sp=0xc000051fe0 pc=0x58866a61
created by runtime.gcenable in goroutine 1
        /usr/local/go/src/runtime/mgc.go:201 +0xa5

goroutine 5 [finalizer wait]:
runtime.gopark(0x0?, 0x58a74b90?, 0x60?, 0x80?, 0x2000000020?)
        /usr/local/go/src/runtime/proc.go:398 +0xce fp=0xc000043e20 sp=0xc000043e00 pc=0x5883aaee
runtime.runfinq()
        /usr/local/go/src/runtime/mfinal.go:193 +0x107 fp=0xc000043fe0 sp=0xc000043e20 pc=0x58819547
runtime.goexit()
        /usr/local/go/src/runtime/asm_amd64.s:1650 +0x1 fp=0xc000043fe8 sp=0xc000043fe0 pc=0x58866a61
created by runtime.createfing in goroutine 1
        /usr/local/go/src/runtime/mfinal.go:163 +0x3d

goroutine 19 [GC worker (idle)]:
runtime.gopark(0xc0d83218184?, 0x2?, 0x0?, 0x0?, 0x0?)
        /usr/local/go/src/runtime/proc.go:398 +0xce fp=0xc0000e1f50 sp=0xc0000e1f30 pc=0x5883aaee
runtime.gcBgMarkWorker()
        /usr/local/go/src/runtime/mgc.go:1295 +0xe5 fp=0xc0000e1fe0 sp=0xc0000e1f50 pc=0x5881bee5
runtime.goexit()
        /usr/local/go/src/runtime/asm_amd64.s:1650 +0x1 fp=0xc0000e1fe8 sp=0xc0000e1fe0 pc=0x58866a61
created by runtime.gcBgMarkStartWorkers in goroutine 17
        /usr/local/go/src/runtime/mgc.go:1219 +0x1c

goroutine 35 [GC worker (idle)]:
runtime.gopark(0xc0d41867fa4?, 0x3?, 0x0?, 0x0?, 0x0?)
        /usr/local/go/src/runtime/proc.go:398 +0xce fp=0xc00004ff50 sp=0xc00004ff30 pc=0x5883aaee
runtime.gcBgMarkWorker()
        /usr/local/go/src/runtime/mgc.go:1295 +0xe5 fp=0xc00004ffe0 sp=0xc00004ff50 pc=0x5881bee5
runtime.goexit()
        /usr/local/go/src/runtime/asm_amd64.s:1650 +0x1 fp=0xc00004ffe8 sp=0xc00004ffe0 pc=0x58866a61
created by runtime.gcBgMarkStartWorkers in goroutine 17
        /usr/local/go/src/runtime/mgc.go:1219 +0x1c

goroutine 36 [GC worker (idle)]:
runtime.gopark(0xc0d41867fa4?, 0x3?, 0x0?, 0x0?, 0x0?)
        /usr/local/go/src/runtime/proc.go:398 +0xce fp=0xc0000ddf50 sp=0xc0000ddf30 pc=0x5883aaee
runtime.gcBgMarkWorker()
        /usr/local/go/src/runtime/mgc.go:1295 +0xe5 fp=0xc0000ddfe0 sp=0xc0000ddf50 pc=0x5881bee5
runtime.goexit()
        /usr/local/go/src/runtime/asm_amd64.s:1650 +0x1 fp=0xc0000ddfe8 sp=0xc0000ddfe0 pc=0x58866a61
created by runtime.gcBgMarkStartWorkers in goroutine 17
        /usr/local/go/src/runtime/mgc.go:1219 +0x1c

goroutine 7 [GC worker (idle)]:
runtime.gopark(0x58c28900?, 0x2?, 0xe0?, 0x1?, 0x0?)
        /usr/local/go/src/runtime/proc.go:398 +0xce fp=0xc000053f50 sp=0xc000053f30 pc=0x5883aaee
runtime.gcBgMarkWorker()
        /usr/local/go/src/runtime/mgc.go:1295 +0xe5 fp=0xc000053fe0 sp=0xc000053f50 pc=0x5881bee5
runtime.goexit()
        /usr/local/go/src/runtime/asm_amd64.s:1650 +0x1 fp=0xc000053fe8 sp=0xc000053fe0 pc=0x58866a61
created by runtime.gcBgMarkStartWorkers in goroutine 17
        /usr/local/go/src/runtime/mgc.go:1219 +0x1c

goroutine 8 [GC worker (idle)]:
runtime.gopark(0xc095385fb98?, 0xc000108040?, 0x1a?, 0x14?, 0x0?)
        /usr/local/go/src/runtime/proc.go:398 +0xce fp=0xc0003e5f50 sp=0xc0003e5f30 pc=0x5883aaee
runtime.gcBgMarkWorker()
        /usr/local/go/src/runtime/mgc.go:1295 +0xe5 fp=0xc0003e5fe0 sp=0xc0003e5f50 pc=0x5881bee5
runtime.goexit()
        /usr/local/go/src/runtime/asm_amd64.s:1650 +0x1 fp=0xc0003e5fe8 sp=0xc0003e5fe0 pc=0x58866a61
created by runtime.gcBgMarkStartWorkers in goroutine 17
        /usr/local/go/src/runtime/mgc.go:1219 +0x1c
Total run time: 1m27.1728225s
exit status 2

image

@pgundlach
Copy link
Member

Thank you very much for the report!

@pgundlach
Copy link
Member

Is this with a simple layout? Which version of Windows are you using?

I have tried Windows 10 on an Intel chip and created a new small layout (sp new hw) and successfully created a PDF.

@Demosteneus
Copy link
Contributor Author

I am running the standard version 4.17.4

Running a simple layout works, but running a more complex layout fails. But I cannot debug what exactly from the more complex layout breaks the publishing as the error messages don't say anything related to the layouts.

@pgundlach
Copy link
Member

I assume that the XML file is “too big” for the memory. I'll test it and create a work around...

@pgundlach
Copy link
Member

(Sorry for spamming you). I assume that the error also happens when you use 4.16 and sp --xpath lxpath?

@Demosteneus
Copy link
Contributor Author

Hi,

Tried:
sp 4.16.0 with sp --xpath lxpath and indeed it fails

then tried
sp 4.17.4 with sp --xpath luxor and it finishes without errors

so the issue is with the XPath parser.

I see the new XPath parser lxpath is supposed to be better.
I also see in the manual now there are 2 pages regarding the XPath and Layout Functions.
Are there any differences in the layout or xpath functions?
How could I start migrating to the new parser, if I don't know what's wrong?

@pgundlach
Copy link
Member

There are currently no difference in the layout or xpath functions. The XPath expressions can now access parent nodes (../) and you can use predicates in square brackets (element[ . mod 3 = 4]).

I hoped that there is no migration necessary, everything should work out of the box.

I'll provide a workaround to save the XML that is currently held in memory to an intermediate file. This might help with the out of memory error.

@pgundlach
Copy link
Member

Version 4.17.5 has a new option (still experimental, undocumented):

sp --option xmlfile=true

or in publisher.cfg

xmlfile=true

Which writes the internal representation of the XML data to intermediate files and skips passing big strings. This might be a workaround for using the default lxpath XPath parser.

pgundlach added a commit that referenced this issue Jan 17, 2024
This option makes the XML parser (lxpath) to write the Lua table to
a file instead of passing a string.

This is related to #557
@pgundlach
Copy link
Member

(now online at https://download.speedata.de)

@Demosteneus
Copy link
Contributor Author

Hi,

I tried sp 4.17.7 with --option xmlfile=true

It still failed, but now I have this error in the publisher.log file:

attempt to index a nil value
stack traceback:
	[C]: in for iterator 'for iterator'
	sw/lua/lxpath.lua:1080: in method 'childaxis'
	sw/lua/lxpath.lua:2428: in function sw/lua/lxpath.lua:2423>
	(...tail calls...)
	sw/lua/publisher\commands.lua:3812: in function 'publisher.commands.setvariable'
	sw/lua/publisher.lua:771: in function 'publisher.dispatch'
	(...tail calls...)
	sw/lua/publisher.lua:771: in function 'publisher.dispatch'
	sw/lua/publisher.lua:1285: in function 'publisher.initialize_luatex_and_generate_pdf'
	sw/lua/publisher.lua:1007: in function 'publisher.dothings'
	sw/lua/publisher\spinit.lua:389: in function 'main_loop'
	sw/lua/publisher\spinit.lua:400: in main chunk
	[C]: in function 'require'
	[\directlua]:1: in main chunk.
l.5 \directlua{require("publisher.spinit")}
                                         
The lua interpreter ran into a problem, so the
remainder of this lua chunk will be ignored.

sw\lua\common\sd-callbacks.lua:82: bad argument #2 to 'format' (number expected, got nil).
<*> publisher.tex 
               layout.xml C:/User...
The lua interpreter ran into a problem, so the
remainder of this lua chunk will be ignored.

@pgundlach
Copy link
Member

This looks much better. But unfortunately impossible to track down without layout or data. If you think you can send a copy.. The contact data is at https://www.speedata.de/imprint/

@Demosteneus
Copy link
Contributor Author

Hi,
Some updates:
I managed to debug a bit further using --verbose --trace --loglevel=debug
and saving the output to a file > debug.txt

First error message was regarding a setvariable. It was on the 61 setvariable from 67 so I found it was this:
<SetVariable variable="paraCount" select="none" />

Not sure why I was setting it to none, but this was working with luxor.

After changing none to 0 and re-running the publishing, it never finishes.
And I got this error now:

File lookup (request=publisher-aux.xml,found=)
internal error (where=sdCreateXMLFile (2),message=open : The system cannot find the file specified.)

Also in the protocol the last line is not finished, as below:

  <entry level="DEBUG" msg="Call command" name="Margin" line="6"></entry>
  <entry level="DEBUG" msg="Call command" name="PositioningArea" line="7"></entry>
  <entry level="DEBUG" msg="Call command" name="AtPageC

@pgundlach
Copy link
Member

Still hard to debug. lxpath is more strict than the old parser but there can be errors of course. I feel your pain but currently I cannot do very much.

@pgundlach
Copy link
Member

I think you should stay with the luxor xpath parser, it won't go away. Just set it to default in your project.

For new projects I'd recommend keeping the new default (lxpath) and complain when errors occur.

@pgundlach
Copy link
Member

Just in case you are still interested: the version 4.17.10 has a new implementation of the lxpath parser which should use much less memory while parsing XML files.

Since I was not able to reproduce the problem, I don't know if this influences the problem.

@pr-apes
Copy link
Contributor

pr-apes commented Mar 21, 2024

@pgundlach,

sorry for not elaborating this further (right now, I will do it as soon as I have time to investigate this).

I have an error code 1 just by compiling a script (that I use to extract images from other files) with version 4.17.19 instead of version 4.17.0.

That being said, if error code is 1, do you want a new issue reporting what triggers the error or do I report it in this already opened report?

(Sorry for the confusion, but I think that part of it comes from not considering that issues are what people experience and reports are what GitHub calls [and numbers as] issues.)

@pgundlach
Copy link
Member

This issue is okay.

@pr-apes
Copy link
Contributor

pr-apes commented Mar 26, 2024

@pgundlach.

I get this error message:

Run speedata publisher 4.17.20
C:\speedata-publisher\sw\lua\sdini.lua:14: module 'libsplib' not found:
        no field package.preload['libsplib']
        no file 'C:\speedata-publisher\sw/lua/libsplib.lua'
        no file 'C:\speedata-publisher/lib/libsplib.lua'
        no file 'C:\speedata-publisher\sw/lua/common/libsplib.lua'
        no file 'C:\speedata-publisher\share\lib/libsplib.so'
        no file 'C:\speedata-publisher\share\lib/libsplib.dll'
Total run time: 281.8818ms
exit status 1

If this is a missing file/dependency, I wonder whether you need the sample code that might trigger this.

Many thanks for your help.

@pgundlach
Copy link
Member

I can reproduce the problem, thank you very much for the report. I am not sure how fast I can fix it, but I give my very best...

@pr-apes
Copy link
Contributor

pr-apes commented Mar 26, 2024

Fine for me. I cannot use the newest version, so I stick to 4.17.0.

@pr-apes
Copy link
Contributor

pr-apes commented Mar 26, 2024

Many thanks for your help.

@pgundlach
Copy link
Member

I also want to close this issue. Don't hesitate to open a new one if you still see errors.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants