search

Secretchronicles / TSC

An open source two-dimensional platform game.
https://secretchronicles.org/
GNU General Public License v3.0
205 stars 49 forks source link

TSC 2.1.0-RC1 Linux 64bit .deb version freezed at caching images 80% #680

Closed xet7 closed 4 years ago

xet7 commented 4 years ago

Hi, when starting TSC, TSC freezes at Saving images to cache at 80% for many minutes. I'm still waiting for TSC to start. This is on Linux Mint 19.3 64bit, on Core 2 Duo 17" laptop that has SSD disk and 8 GB RAM, and also at another laptop that has non-SSD harddisk and 4 GB RAM. Does anyone else have same issue?

TSC does work for me on:

xet7 commented 4 years ago

How can I build non-debug release version of TSC ? Maybe that would help.

xet7 commented 4 years ago

It seems that it happens at Applying preferences stage. I will try on other distros and kernels.

Quintus commented 4 years ago

Am 07. April 2020 um 09:52 Uhr -0700 schrieb Lauri Ojansivu:

How can I build non-debug release version of TSC ?

Pass this option to cmake: -DCMAKE_BUILD_TYPE=Release

and remove -DCMAKE_BUILD_TYPE=Debug of course.

xet7 commented 4 years ago

It seems that on Ubuntu Mate 64bit with kernel 5.0.0-37-generic there is no freeze.

xet7 commented 4 years ago

I mean Ubuntu Mate 18.04.04 LTS 64bit

xet7 commented 4 years ago

When I installed updates, with Ubuntu Mate 64bit with kernel 5.3.0-46-generic it freezes at 80%, using RC1 debug build.

xet7 commented 4 years ago

When that freeze happens, it takes about 30 minutes, then TSC game main screen is visible and theme music plays.

refi64 commented 4 years ago

Maybe helpful, try installing strace and run TSC from the command line but prefix it with strace -f, it might show if there's a particular system call / operation it's hanging on.

Also of course, if you can reproduce it with a debug build, pop it into gdb and ctrl-c at some point when it's stuck, then bt for a backtrace.

On Tue, Apr 7, 2020, 2:07 PM Lauri Ojansivu notifications@github.com wrote:

When that freeze happens, it takes about 30 minutes, then TSC game main screen is visible and theme music plays.

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/Secretchronicles/TSC/issues/680#issuecomment-610567359, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAM4YSKH5KB3Q2MQOIF27TDRLN2V5ANCNFSM4MDIUX3A .

xet7 commented 4 years ago

Does this help?

Applying preferences

Thread 1 "tsc" received signal SIGINT, Interrupt.
0x00007ffff45045d7 in ioctl () at ../sysdeps/unix/syscall-template.S:78
78  ../sysdeps/unix/syscall-template.S: File or directory does not exist.
xet7 commented 4 years ago

Some more...

[pid  5638] getpid( <unfinished ...>
[pid  5637] futex(0x7f0f8c009c50, FUTEX_LOCK_PI_PRIVATE, NULL <unfinished ...>
[pid  5638] <... getpid resumed> )      = 5628
[pid  5638] getpid()                    = 5628
[pid  5638] futex(0x7f0f8c009c50, FUTEX_UNLOCK_PI_PRIVATE) = 0
[pid  5637] <... futex resumed> )       = 0
[pid  5638] futex(0x55c42ef9a83c, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  5637] write(9, "\1\0\0\0\0\0\0\0", 8) = 8
[pid  5637] read(7, "W", 10)            = 1
[pid  5637] clock_gettime(CLOCK_MONOTONIC, {tv_sec=1320, tv_nsec=78980093}) = 0
[pid  5637] futex(0x7f0f8c009c50, FUTEX_UNLOCK_PI_PRIVATE) = 0
[pid  5637] poll([{fd=7, events=POLLIN}, {fd=10, events=POLLIN}, {fd=11, events=POLLIN}], 3, 735) = 1 ([{fd=11, revents=POLLIN}])
[pid  5637] clock_gettime(CLOCK_MONOTONIC, {tv_sec=1320, tv_nsec=100335566}) = 0
[pid  5637] read(11, "\1\0\0\0\0\0\0\0", 8) = 8
[pid  5637] futex(0x55c42ef9a83c, FUTEX_WAKE_PRIVATE, 2147483647 <unfinished ...>
[pid  5638] <... futex resumed> )       = 0
[pid  5638] futex(0x7f0f8c009c50, FUTEX_LOCK_PI_PRIVATE, NULL <unfinished ...>
[pid  5637] <... futex resumed> )       = 1
[pid  5637] read(7, 0x7f0f996cdc5e, 10) = -1 EAGAIN (Resource temporarily unavailable)
[pid  5637] clock_gettime(CLOCK_MONOTONIC, {tv_sec=1320, tv_nsec=101086785}) = 0
[pid  5637] futex(0x7f0f8c009c50, FUTEX_UNLOCK_PI_PRIVATE <unfinished ...>
[pid  5638] <... futex resumed> )       = 0
[pid  5637] <... futex resumed> )       = 0
[pid  5638] getpid( <unfinished ...>
[pid  5637] poll([{fd=7, events=POLLIN}, {fd=10, events=POLLIN}, {fd=11, events=POLLIN}], 3, 712 <unfinished ...>
[pid  5638] <... getpid resumed> )      = 5628
[pid  5638] getpid()                    = 5628
[pid  5638] getpid()                    = 5628
[pid  5638] write(8, "W", 1)            = 1
[pid  5637] <... poll resumed> )        = 1 ([{fd=7, revents=POLLIN}])
[pid  5638] getpid( <unfinished ...>
[pid  5637] futex(0x7f0f8c009c50, FUTEX_LOCK_PI_PRIVATE, NULL <unfinished ...>
[pid  5638] <... getpid resumed> )      = 5628
[pid  5638] getpid()                    = 5628
[pid  5638] futex(0x7f0f8c009c50, FUTEX_UNLOCK_PI_PRIVATE) = 0
[pid  5637] <... futex resumed> )       = 0
[pid  5638] futex(0x55c42ef9a838, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  5637] write(9, "\1\0\0\0\0\0\0\0", 8) = 8
[pid  5637] read(7, "W", 10)            = 1
[pid  5637] clock_gettime(CLOCK_MONOTONIC, {tv_sec=1320, tv_nsec=102988579}) = 0
[pid  5637] futex(0x7f0f8c009c50, FUTEX_UNLOCK_PI_PRIVATE) = 0
[pid  5637] poll([{fd=7, events=POLLIN}, {fd=10, events=POLLIN}, {fd=11, events=POLLIN}], 3, 711) = 1 ([{fd=11, revents=POLLIN}])
[pid  5637] clock_gettime(CLOCK_MONOTONIC, {tv_sec=1320, tv_nsec=123804523}) = 0
[pid  5637] read(11, "\1\0\0\0\0\0\0\0", 8) = 8
[pid  5637] futex(0x55c42ef9a838, FUTEX_WAKE_PRIVATE, 2147483647 <unfinished ...>
[pid  5638] <... futex resumed> )       = 0
[pid  5638] futex(0x7f0f8c009c50, FUTEX_LOCK_PI_PRIVATE, NULL <unfinished ...>
[pid  5637] <... futex resumed> )       = 1
[pid  5637] read(7, 0x7f0f996cdc5e, 10) = -1 EAGAIN (Resource temporarily unavailable)
[pid  5637] clock_gettime(CLOCK_MONOTONIC, {tv_sec=1320, tv_nsec=124638086}) = 0
[pid  5637] futex(0x7f0f8c009c50, FUTEX_UNLOCK_PI_PRIVATE <unfinished ...>
[pid  5638] <... futex resumed> )       = 0
[pid  5638] getpid()                    = 5628
[pid  5638] getpid()                    = 5628
[pid  5638] getpid()                    = 5628
[pid  5638] write(8, "W", 1)            = 1
[pid  5638] getpid()                    = 5628
[pid  5638] getpid()                    = 5628
[pid  5638] futex(0x7f0f8c009c50, FUTEX_UNLOCK_PI_PRIVATE) = 0
[pid  5638] futex(0x55c42ef9a83c, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  5637] <... futex resumed> )       = 0
[pid  5637] poll([{fd=7, events=POLLIN}, {fd=10, events=POLLIN}, {fd=11, events=POLLIN}], 3, 689) = 1 ([{fd=7, revents=POLLIN}])
[pid  5637] write(9, "\1\0\0\0\0\0\0\0", 8) = 8
[pid  5637] read(7, "W", 10)            = 1
[pid  5637] clock_gettime(CLOCK_MONOTONIC, {tv_sec=1320, tv_nsec=126566280}) = 0
[pid  5637] poll([{fd=7, events=POLLIN}, {fd=10, events=POLLIN}, {fd=11, events=POLLIN}], 3, 687) = 1 ([{fd=11, revents=POLLIN}])
[pid  5637] clock_gettime(CLOCK_MONOTONIC, {tv_sec=1320, tv_nsec=144267697}) = 0
[pid  5637] read(11, "\1\0\0\0\0\0\0\0", 8) = 8
[pid  5637] read(7, 0x7f0f996cdc5e, 10) = -1 EAGAIN (Resource temporarily unavailable)
[pid  5637] clock_gettime(CLOCK_MONOTONIC, {tv_sec=1320, tv_nsec=144737244}) = 0
[pid  5637] poll([{fd=7, events=POLLIN}, {fd=10, events=POLLIN}, {fd=11, events=POLLIN}], 3, 669) = 1 ([{fd=11, revents=POLLIN}])
[pid  5637] clock_gettime(CLOCK_MONOTONIC, {tv_sec=1320, tv_nsec=150183930}) = 0
[pid  5637] read(11, "\1\0\0\0\0\0\0\0", 8) = 8
[pid  5637] futex(0x55c42ef9a83c, FUTEX_WAKE_PRIVATE, 2147483647 <unfinished ...>
[pid  5638] <... futex resumed> )       = 0
[pid  5638] futex(0x7f0f8c009c50, FUTEX_LOCK_PI_PRIVATE, NULL <unfinished ...>
[pid  5637] <... futex resumed> )       = 1
[pid  5637] read(7, 0x7f0f996cdc5e, 10) = -1 EAGAIN (Resource temporarily unavailable)
[pid  5637] clock_gettime(CLOCK_MONOTONIC, {tv_sec=1320, tv_nsec=150879974}) = 0
[pid  5637] futex(0x7f0f8c009c50, FUTEX_UNLOCK_PI_PRIVATE <unfinished ...>
[pid  5638] <... futex resumed> )       = 0
[pid  5637] <... futex resumed> )       = 0
xet7 commented 4 years ago

Here are photos of various steps where TSC did get struck:

https://ftp.secretchronicles.org/misc/strace-tsc-images.zip

Quintus commented 4 years ago

Does this only happen in release mode? It not: Please make a debug build and start the game via GDB:

$ gdb path/to/tsc

When it freezes, hit CTRL+C in the console. This will return control to GDB. Then dump a backtrace:

> bt

Please post the result.

It looks to me like it was doing lots of I/O for whatever reason.

-quintus

Am 07. April 2020 um 13:28 Uhr -0700 schrieb Lauri Ojansivu:

Here are photos of various steps where TSC did get struck:

https://ftp.secretchronicles.org/misc/strace-tsc-images.zip

-- You are receiving this because you commented. Reply to this email directly or view it on GitHub: https://github.com/Secretchronicles/TSC/issues/680#issuecomment-610603906

-- Blog: https://mg.guelker.eu

xet7 commented 4 years ago

First I pressed CTRL+C when it went to 80%, after that wrote continue, so desktop screen freezed and I had to kill -9 it with ssh. This happens on Core 2 Duo laptop that has SSD disk, 8 GB RAM, Mint 19.3 64bit with kernel 5.3.0-46-generic. I translated some of the text to English.

Starting program: /usr/bin/tsc 
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
[New Thread 0x7fffe3bd6700 (LWP 31449)]
[New Thread 0x7fffe310e700 (LWP 31450)]
[Thread 0x7fffe310e700 (LWP 31450) exited]
[New Thread 0x7fffe16fd700 (LWP 31451)]
[New Thread 0x7fffe16fd700 (LWP 31452)]
[Thread 0x7fffe16fd700 (LWP 31451) exited]
[New Thread 0x7fffe0efc700 (LWP 31453)]
Warning: Preferences file '/home/user/.config/tsc/config.xml' does not exist. Using default values.
^C
Thread 1 "tsc" received signal SIGINT, Interrupt.
0x00007ffff119914b in adler32_z () from /lib/x86_64-linux-gnu/libz.so.1
(gdb) bt
#0  0x00007ffff119914b in adler32_z () at /lib/x86_64-linux-gnu/libz.so.1
#1  0x00007ffff11a3375 in inflate () at /lib/x86_64-linux-gnu/libz.so.1
#2  0x00007ffff5d482cd in  () at /usr/lib/x86_64-linux-gnu/libpng16.so.16
#3  0x00007ffff5d3aae3 in png_read_row ()
    at /usr/lib/x86_64-linux-gnu/libpng16.so.16
#4  0x00007ffff5d3c72a in png_read_image ()
    at /usr/lib/x86_64-linux-gnu/libpng16.so.16
#5  0x00007ffff330a603 in readpng_get_image ()
    at /usr/lib/x86_64-linux-gnu/libIL.so.1
#6  0x00007ffff330a91d in iLoadPngInternal ()
    at /usr/lib/x86_64-linux-gnu/libIL.so.1
#7  0x00007ffff7329d3f in CEGUI::DevILImageCodec::load(CEGUI::RawDataContainer const&, CEGUI::Texture*) () at /usr/lib/cegui-0.8/libCEGUIDevILImageCodec.so
#8  0x00007ffff7bc4c02 in CEGUI::OpenGLTexture::loadFromFile(CEGUI::String const&, CEGUI::String const&) () at /usr/lib/libCEGUIOpenGLRenderer-0.so.2
#9  0x00007ffff7bc6982 in CEGUI::OpenGLTexture::OpenGLTexture(CEGUI::OpenGLRendererBase&, CEGUI::String const&, CEGUI::String const&, CEGUI::String const&) ()
---Type <return> to continue, or q <return> to quit---
   t /usr/lib/libCEGUIOpenGLRenderer-0.so.2
#10 0x00007ffff7bc06bf in CEGUI::OpenGLRendererBase::createTexture(CEGUI::String const&, CEGUI::String const&, CEGUI::String const&) () at /usr/lib/libCEGUIOpenGLRenderer-0.so.2
#11 0x00007ffff76e1d39 in CEGUI::ImageManager::addFromImageFile(CEGUI::String const&, CEGUI::String const&, CEGUI::String const&) () at /usr/lib/libCEGUIBase-0.so.2
#12 0x00005555556f4418 in TSC::cEditor_Level::load_background_images_into_cegui() ()
#13 0x00005555556f4b46 in TSC::cEditor_Level::cEditor_Level() ()
#14 0x000055555562f984 in TSC::Init_Game() ()
#15 0x00005555555e8e98 in main ()
(gdb) continue
Continuing.
^C
Thread 1 "tsc" received signal SIGINT, Interrupt.
0x00007ffff45045d7 in ioctl () at ../sysdeps/unix/syscall-template.S:78
78  ../sysdeps/unix/syscall-template.S: File or directory does not exist.
(gdb) Tracking/cuttingdottrap (created core-file)
Quintus commented 4 years ago

Am 10. April 2020 um 03:11 Uhr -0700 schrieb Lauri Ojansivu:

10 0x00007ffff7bc06bf in CEGUI::OpenGLRendererBase::createTexture(CEGUI::String const&, CEGUI::String const&, CEGUI::String const&) () at /usr/lib/libCEGUIOpenGLRenderer-0.so.2

11 0x00007ffff76e1d39 in CEGUI::ImageManager::addFromImageFile(CEGUI::String const&, CEGUI::String const&, CEGUI::String const&) () at /usr/lib/libCEGUIBase-0.so.2

12 0x00005555556f4418 in TSC::cEditor_Level::load_background_images_into_cegui() ()

Ah. It is stalling when the background images are loaded into CEGUI (`load_background_images_into_cegui()'). This is understandable; the backgorund images are our hugest image files. I assume it is the upload to the graphics card which takes that long. The weaker your graphics card, the slower the process will be. I assume your machine's graphics card is not exactly a gamer's graphics card.

The background files are loaded into CEGUI for the background preview in the editor. Maybe we should make this a configuration option, but I do not think that this problem warrants delaying the 2.1.0 release.

-quintus

-- Blog: https://mg.guelker.eu

xet7 commented 4 years ago

@Quintus

I'll try installing NVidia drivers to that Core 2 Duo laptop, to see does it help.

This freeze does not exist on my i5 desktop.

xet7 commented 4 years ago

That Core 2 Duo laptop is currently using nouveau Open Source drivers 1.0.15-2 so I'm changing to NVidia-340 v340.107 driver.

xet7 commented 4 years ago

And there is no big slowdowns on NVidia driver.

Quintus commented 4 years ago

Am 11. April 2020 um 03:13 Uhr -0700 schrieb Lauri Ojansivu:

And there is no big slowdowns on NVidia driver.

This is good to know. You should consider filing this as a bug against nouveau then. Thanks for the investigation!

-quintus

-- Blog: https://mg.guelker.eu