(Linux) Memory Leak in 1.28.0

[ppfeufer]

The current version - 1.28.0 - seems top have a massive memory leak.

The app won't start and after eating up roughly 8GB of RAM and 5GB of my swap drive I managed to finally kill the application.

~/downloads/pyfa-1.28.0-yc119.3-1.0-linux/pyfa $ python2.7 pyfa.py [2017-03-16 21:30:49.189095] WARNING: config: Failed to import: configforced [2017-03-16 21:30:49.327758] DEBUG: config: Configuring Pyfa [2017-03-16 21:30:49.503067] DEBUG: service.prefetch: Run database migration. [2017-03-16 21:30:49.507228] DEBUG: service.prefetch: Import Required Database Values. [2017-03-16 21:30:49.581644] DEBUG: service.prefetch: Starting database validation. [2017-03-16 21:30:49.581758] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for character skills. [2017-03-16 21:30:49.582639] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for orphaned characters attached to fits. [2017-03-16 21:30:49.583363] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for orphaned damage patterns attached to fits. [2017-03-16 21:30:49.584073] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for missing damage pattern names. [2017-03-16 21:30:49.584728] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for missing target resist names. [2017-03-16 21:30:49.585380] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for orphaned drones items. [2017-03-16 21:30:49.586140] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for orphaned cargo items. [2017-03-16 21:30:49.587061] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for orphaned fighters items. [2017-03-16 21:30:49.587753] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for orphaned modules items. [2017-03-16 21:30:49.589932] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for null damagePatterns values. (em) [2017-03-16 21:30:49.590614] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for null damagePatterns values. (thermal) [2017-03-16 21:30:49.591270] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for null damagePatterns values. (kinetic) [2017-03-16 21:30:49.591938] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for null damagePatterns values. (explosive) [2017-03-16 21:30:49.592603] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for null targetResists values. (em) [2017-03-16 21:30:49.593266] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for null targetResists values. (thermal) [2017-03-16 21:30:49.593911] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for null targetResists values. (kinetic) [2017-03-16 21:30:49.594568] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for null targetResists values. (explosive) [2017-03-16 21:30:49.595263] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for duplicated selected ammo profiles. [2017-03-16 21:30:49.595918] DEBUG: service.prefetch: Completed database validation.

At this point it eats up all memory

killed

[Ebag333]

Can you check the Pyfa.log file in your home directory?

Can you try running with debugging turned on?

python pyfa.py --debug --logginglevel Debug

[blitzmann]

@ppfeufer does this happen consistently? Are you able to use the program at all? Which distro? Can you send me your ~/.pyfa directory in email (sable.blitzmann@gmail.com) - send the whole thing in a .zip, not just the database file. I want to know what you have for settings as well.

Also, you are having DEBUG statements show even without specifying a debug flag. That is odd. @Ebag333 and ideas on that? I am worried this may actually be due to the logger since it buffers to memory now, but I don't see how it could eat up 8GB+ of space.

This is a breaking issue that is highest priority. I'll have to test it out in my Linux VM.

[Ebag333]

I'm not seeing this all on Windows, and there are other Linux users.

A serious issue to be sure, but I don't think that the world is on fire yet.

[blitzmann]

If it's happening for one person, probably happens for others.

[blitzmann]

I checked on my Linux Mint machine, can't reproduce. pyfa starts up as expected :(

Can you revert back to 1.27.2 and see if it still has the issue?

[ppfeufer]

So,

Some fun facts .... If I start it with the debug options, it starts just fine.

[2017-03-17 06:18:20.594790] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for null targetResists values. (kinetic)
[2017-03-17 06:18:20.595416] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for null targetResists values. (explosive)
[2017-03-17 06:18:20.596062] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for duplicated selected ammo profiles.
[2017-03-17 06:18:20.596690] DEBUG: service.prefetch: Completed database validation.
[2017-03-17 06:18:20.599654] INFO: __main__: Starting Pyfa
[2017-03-17 06:18:20.599817] INFO: __main__: Running in logging mode: Debug
[2017-03-17 06:18:20.618183] INFO: gui.bitmapLoader: Using local image files.
[2017-03-17 06:18:21.025959] DEBUG: gui.statsPane: Setting full view for: resources
[2017-03-17 06:18:21.026148] DEBUG: gui.statsPane: Setting full view for: resistances

And so on until it starts ..... so all fine

If i start it without the debug option, it leaks memory like hell.

[2017-03-17 06:17:46.072596] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for null targetResists values. (kinetic)
[2017-03-17 06:17:46.073228] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for null targetResists values. (explosive)
[2017-03-17 06:17:46.074001] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for duplicated selected ammo profiles.
[2017-03-17 06:17:46.074640] DEBUG: service.prefetch: Completed database validation.
Killed

Starts leaking memory .....

There is no Pyfa.log in my home directory @blitzmann :: You got a mail with the zip of my .pyfa directory. Running the whole thing on a Gentoo machine. v1.27.2 starts just fine.

[Ebag333]

@ppfeufer can you please try this version of pyfa.py? Make a backup first.

https://raw.githubusercontent.com/Ebag333/Pyfa/717db2f9066a517c71b31c84f01610c02a1295ed/pyfa.py

Is there a PyfaDebug log file after running in debug mode?

[ppfeufer]

@Ebag333 No log file is written, it just spams all the stuff into my console.

paste here for reference:

python2.7 pyfa.py --debug --logginglevel Debug

[2017-03-17 06:35:49.490895] WARNING: config: Failed to import: configforced
[2017-03-17 06:35:49.622125] DEBUG: config: Configuring Pyfa
[2017-03-17 06:35:49.627243] INFO: __main__: Starting Pyfa
[2017-03-17 06:35:49.629988] INFO: __main__: wxPython is installed. Version: ['3.0-gtk2', '2.8-gtk2-unicode'].
[2017-03-17 06:35:49.786102] DEBUG: service.prefetch: Run database migration.
[2017-03-17 06:35:49.790354] DEBUG: service.prefetch: Import Required Database Values.
[2017-03-17 06:35:49.866363] DEBUG: service.prefetch: Starting database validation.
[2017-03-17 06:35:49.866552] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for character skills.
[2017-03-17 06:35:49.867482] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for orphaned characters attached to fits.
[2017-03-17 06:35:49.868269] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for orphaned damage patterns attached to fits.
[2017-03-17 06:35:49.869013] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for missing damage pattern names.
[2017-03-17 06:35:49.869696] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for missing target resist names.
[2017-03-17 06:35:49.870365] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for orphaned drones items.
[2017-03-17 06:35:49.871143] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for orphaned cargo items.
[2017-03-17 06:35:49.872100] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for orphaned fighters items.
[2017-03-17 06:35:49.872831] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for orphaned modules items.
[2017-03-17 06:35:49.875027] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for null damagePatterns values. (em)
[2017-03-17 06:35:49.875832] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for null damagePatterns values. (thermal)
[2017-03-17 06:35:49.876626] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for null damagePatterns values. (kinetic)
[2017-03-17 06:35:49.877323] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for null damagePatterns values. (explosive)
[2017-03-17 06:35:49.878059] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for null targetResists values. (em)
[2017-03-17 06:35:49.878749] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for null targetResists values. (thermal)
[2017-03-17 06:35:49.879428] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for null targetResists values. (kinetic)
[2017-03-17 06:35:49.880147] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for null targetResists values. (explosive)
[2017-03-17 06:35:49.880883] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for duplicated selected ammo profiles.
[2017-03-17 06:35:49.881563] DEBUG: service.prefetch: Completed database validation.
[2017-03-17 06:35:49.884579] INFO: __main__: Running in logging mode: Debug
[2017-03-17 06:35:49.918550] INFO: gui.bitmapLoader: Using local image files.
[2017-03-17 06:35:50.418583] DEBUG: gui.statsPane: Setting full view for: resources
[2017-03-17 06:35:50.418779] DEBUG: gui.statsPane: Setting full view for: resistances
[2017-03-17 06:35:50.418893] DEBUG: gui.statsPane: Setting full view for: recharge
[2017-03-17 06:35:50.419002] DEBUG: gui.statsPane: Setting full view for: firepower
[2017-03-17 06:35:50.419109] DEBUG: gui.statsPane: Setting full view for: outgoing
[2017-03-17 06:35:50.419211] DEBUG: gui.statsPane: Setting full view for: capacitor
[2017-03-17 06:35:50.419312] DEBUG: gui.statsPane: Setting minimal view for: targetingMisc
[2017-03-17 06:35:50.419412] DEBUG: gui.statsPane: Setting full view for: price
[2017-03-17 06:35:50.505762] DEBUG: gui.mainFrame: Initialize MainFrame
[2017-03-17 06:35:50.508285] DEBUG: service.fit: Initialize Fit class
[2017-03-17 06:35:50.804371] DEBUG: gui.marketBrowser: Initialize marketBrowser
[2017-03-17 06:35:50.805810] DEBUG: service.market: Initialize PriceWorkerThread.
[2017-03-17 06:35:50.806064] DEBUG: service.market: Run start
[2017-03-17 06:35:50.806202] DEBUG: service.market: Initialize SearchWorkerThread.
[2017-03-17 06:35:50.806508] DEBUG: service.market: Initialize ShipBrowserWorkerThread.
[2017-03-17 06:35:50.856210] DEBUG: gui.marketBrowser: Initialize marketTree
[2017-03-17 06:35:50.885786] DEBUG: gui.marketBrowser: Initialize ItemView
[2017-03-17 06:35:50.886010] DEBUG: gui.marketBrowser: Fill up recently used modules set
[2017-03-17 06:35:50.913036] DEBUG: gui.shipBrowser: Populate ship category list.
[2017-03-17 06:35:51.339783] DEBUG: gui.statsPane: Load view: resourcesViewFull
[2017-03-17 06:35:51.364299] DEBUG: gui.statsPane: Load view: resistancesViewFull
[2017-03-17 06:35:51.377044] DEBUG: gui.statsPane: Load view: rechargeViewFull
[2017-03-17 06:35:51.388207] DEBUG: gui.statsPane: Load view: firepowerViewFull
[2017-03-17 06:35:51.394097] DEBUG: gui.statsPane: Load view: outgoingViewFull
[2017-03-17 06:35:51.398256] DEBUG: gui.statsPane: Load view: capacitorViewFull
[2017-03-17 06:35:51.406934] DEBUG: gui.statsPane: Load view: targetingMiscViewMinimal
[2017-03-17 06:35:51.414871] WARNING: __main__: labelName
[2017-03-17 06:35:51.418269] DEBUG: gui.statsPane: Load view: priceViewFull
[2017-03-17 06:35:51.422247] DEBUG: gui.mainMenuBar: Initialize MainMenuBar
[2017-03-17 06:35:51.510085] DEBUG: service.update: Starting Check Update Thread.
[2017-03-17 06:35:51.578187] DEBUG: gui.mainMenuBar: fitChanged triggered
[2017-03-17 06:35:51.589897] WARNING: __main__: labelName

[Ebag333]

At least you have the console. That helps some.

So here's what I'd like you to try, if you can.

1. Grab a screenshot of the Help -> About menu.
2. In the Preferences window, double check the Database preference and make sure that the User Path is what you expected it to be (I'm sure it is, but just want to double check).
3. Backup your existing pyfa.py file and replace with the one linked above. It adds a ton of additional logging, so I'm curious to see if we get any more info out of it.

[ppfeufer]

@Ebag333 to 1:

to 2: Checked all paths, so the debug log is not in my home directoy, it's in me .pyfa dir.

to 3: Did that, here's the log ... (looks like the same as I have in my console though ...)

[2017-03-17 06:57:06.121026] INFO: __main__: Starting Pyfa
[2017-03-17 06:57:06.123812] INFO: __main__: wxPython is installed. Version: ['3.0-gtk2', '2.8-gtk2-unicode'].
[2017-03-17 06:57:06.251991] DEBUG: service.prefetch: Run database migration.
[2017-03-17 06:57:06.256425] DEBUG: service.prefetch: Import Required Database Values.
[2017-03-17 06:57:06.332746] DEBUG: service.prefetch: Starting database validation.
[2017-03-17 06:57:06.332946] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for character skills.
[2017-03-17 06:57:06.333831] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for orphaned characters attached to fits.
[2017-03-17 06:57:06.334662] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for orphaned damage patterns attached to fits.
[2017-03-17 06:57:06.335531] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for missing damage pattern names.
[2017-03-17 06:57:06.336230] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for missing target resist names.
[2017-03-17 06:57:06.336922] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for orphaned drones items.
[2017-03-17 06:57:06.337721] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for orphaned cargo items.
[2017-03-17 06:57:06.338684] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for orphaned fighters items.
[2017-03-17 06:57:06.339408] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for orphaned modules items.
[2017-03-17 06:57:06.341904] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for null damagePatterns values. (em)
[2017-03-17 06:57:06.342672] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for null damagePatterns values. (thermal)
[2017-03-17 06:57:06.343369] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for null damagePatterns values. (kinetic)
[2017-03-17 06:57:06.344090] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for null damagePatterns values. (explosive)
[2017-03-17 06:57:06.345017] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for null targetResists values. (em)
[2017-03-17 06:57:06.345890] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for null targetResists values. (thermal)
[2017-03-17 06:57:06.346584] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for null targetResists values. (kinetic)
[2017-03-17 06:57:06.347274] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for null targetResists values. (explosive)
[2017-03-17 06:57:06.347975] DEBUG: eos.db.saveddata.databaseRepair: Running database cleanup for duplicated selected ammo profiles.
[2017-03-17 06:57:06.348654] DEBUG: service.prefetch: Completed database validation.
[2017-03-17 06:57:06.351863] INFO: __main__: Running in logging mode: Debug
[2017-03-17 06:57:06.371157] INFO: gui.bitmapLoader: Using local image files.
[2017-03-17 06:57:06.807145] DEBUG: gui.statsPane: Setting full view for: resources
[2017-03-17 06:57:06.807340] DEBUG: gui.statsPane: Setting full view for: resistances
[2017-03-17 06:57:06.807506] DEBUG: gui.statsPane: Setting full view for: recharge
[2017-03-17 06:57:06.807612] DEBUG: gui.statsPane: Setting full view for: firepower
[2017-03-17 06:57:06.807819] DEBUG: gui.statsPane: Setting full view for: outgoing
[2017-03-17 06:57:06.807920] DEBUG: gui.statsPane: Setting full view for: capacitor
[2017-03-17 06:57:06.808020] DEBUG: gui.statsPane: Setting minimal view for: targetingMisc
[2017-03-17 06:57:06.808122] DEBUG: gui.statsPane: Setting full view for: price
[2017-03-17 06:57:06.865560] DEBUG: gui.mainFrame: Initialize MainFrame
[2017-03-17 06:57:06.869426] DEBUG: service.fit: Initialize Fit class
[2017-03-17 06:57:07.155240] DEBUG: gui.marketBrowser: Initialize marketBrowser
[2017-03-17 06:57:07.156796] DEBUG: service.market: Initialize PriceWorkerThread.
[2017-03-17 06:57:07.157223] DEBUG: service.market: Initialize SearchWorkerThread.
[2017-03-17 06:57:07.157635] DEBUG: service.market: Initialize ShipBrowserWorkerThread.
[2017-03-17 06:57:07.208246] DEBUG: gui.marketBrowser: Initialize marketTree
[2017-03-17 06:57:07.237366] DEBUG: gui.marketBrowser: Initialize ItemView
[2017-03-17 06:57:07.237625] DEBUG: gui.marketBrowser: Fill up recently used modules set
[2017-03-17 06:57:07.258813] DEBUG: gui.shipBrowser: Populate ship category list.
[2017-03-17 06:57:07.688824] DEBUG: gui.statsPane: Load view: resourcesViewFull
[2017-03-17 06:57:07.709384] DEBUG: gui.statsPane: Load view: resistancesViewFull
[2017-03-17 06:57:07.720956] DEBUG: gui.statsPane: Load view: rechargeViewFull
[2017-03-17 06:57:07.729330] DEBUG: gui.statsPane: Load view: firepowerViewFull
[2017-03-17 06:57:07.734785] DEBUG: gui.statsPane: Load view: outgoingViewFull
[2017-03-17 06:57:07.738328] DEBUG: gui.statsPane: Load view: capacitorViewFull
[2017-03-17 06:57:07.744183] DEBUG: gui.statsPane: Load view: targetingMiscViewMinimal
[2017-03-17 06:57:07.750510] WARNING: __main__: labelName
[2017-03-17 06:57:07.752627] DEBUG: gui.statsPane: Load view: priceViewFull
[2017-03-17 06:57:07.756372] DEBUG: gui.mainMenuBar: Initialize MainMenuBar
[2017-03-17 06:57:07.839598] DEBUG: service.update: Starting Check Update Thread.
[2017-03-17 06:57:07.893342] DEBUG: gui.mainMenuBar: fitChanged triggered
[2017-03-17 06:57:07.905409] WARNING: __main__: labelName

[Ebag333]

Did that, here's the log ... (looks like the same as I have in my console though ...)

Did it behave any differently when you aren't launching in debug mode?

[ppfeufer]

Nope, without debug mode still eating my RAM

Only difference, I don't get all that jazz in the console .....

python2.7 pyfa.py

[2017-03-17 07:03:10.024242] WARNING: config: Failed to import: configforced
[2017-03-17 07:03:10.154030] DEBUG: config: Configuring Pyfa
Killed

[blitzmann]

This is very weird.

When you say "start with debugging", does that mean with the --debug flag and the --logginglevel flag? What happens if you remove just the debug, and leave the logging. Or viceversa?

From the results of that, you could also try the different log levels found starting here: https://github.com/pyfa-org/Pyfa/blob/master/pyfa.py#L81

Maybe if we find out what is triggering it to break.

@Ebag333 does logbook have a NullLogger? Basically a logger that we can initialize so that all the logging statements don't break things, but it more or less ignores and goes into a black hole. If possible, I'd like to get a Null logger set up for @ppfeufer and see if he's having the same problems, but you know logbook better than I. Trying to narrow what exactly is causing the issue.

@ppfeufer I did not receive an email to my sable.blitzmann@gmail.com mailbox. Please double check the address and resend. Otherwise you can pop into our Slack and send me the .zip directly through the Slack Interface.

[ppfeufer]

Double checked the mail address, looks pretty right to me.

pyfa.zip But here ya go ...

Yes, with debug means with all the parameters given here in the conversation so far.

It starts with only the --debug option It doesn't start with only the --logginglevel option

So, --debug has to be set

[Ebag333]

@blitzmann due to the....special....nature of Gentoo, we might simply be limited in how much support we can provide.

Since everything is built on demand by the user, Gentoo tends to be very different than even other Linux distros.

I'm going to try and download the live USB and replicate this, but if I can't there might not be much we can do.

[blitzmann]

There shouldn't be anything special with Gentoo simply because everything is compiled by the user instead of installed from a repo. Especially since 1.27.2 works.

I'll be taking a look at the commits between 1.27.2 and 1.28.0 and having @ppfeufer test a few packages to see where it's breaking. I still have a high suspicion it's the logger for some reason.

@ppfeufer how dev savvy are you? Ever worked with git before? You username looks familiar so I'm not sure if you've ever contributed or if I just recognize it from tickets

[minlexx]

I have a new fresh Gentoo on laptop, and tried to test pyfa. I downloaded zip, extracted, cd into. Trying to run ./pyfa.py directly:

lexx@fsociety ~/dev/pyfa-1.28.0-yc119.3-1.0-linux $ ./pyfa.py 
  File "./pyfa.py", line 252
    except Exception, e:
                    ^
SyntaxError: invalid syntax

Ok, this is because default python is version 3.4 on my system. Next try:

lexx@fsociety ~/dev/pyfa-1.28.0-yc119.3-1.0-linux $ /usr/bin/python2.7 pyfa.py
Traceback (most recent call last):
  File "pyfa.py", line 25, in <module>
    import config
  File "/home/lexx/dev/pyfa-1.28.0-yc119.3-1.0-linux/config.py", line 4, in <module>
    from logbook import Logger
ImportError: No module named logbook

I see, not all required dependencies are included in distribution archives. But why sqlalchemy, wxwidgets or python-dateutil existence and presence is checked in pyfa.py startup lines, and logbook is not. Okay, in gentoo we have these versions of logbook: 0.9.1 stable and unstable ~0.10.0 ~0.12.3 ~0.12.5 ~1.0.0. Which one is required?

So, first I have to emerge dev-python/logbook dev-python/wxpython dev-python/sqlaclchemy dev-python/python-dateutil what else? :) Guess that's all. Finally, after all this, it tries to start and slowly eats all memory as described, can confirm.

I didn't wait for it to eat all my 8 Gb, but 2.5 Gb I think is not good already. (Update: yes, it can eat all 8 Gb.)

Also, it starts fine with --debug option. Without --debug it hangs eating 1 cpu core 100% and comsuming memory. Even with empty database (I removed ~/.pyfa dir each time).

I'm familiar with git, can try to run from source or apply any patches, If you have any ideas :)

[Ebag333]

There is a requirement_linux.txt file. That should help you with the required files to run.

OFC that doesn't mean that Gentoo will have exactly those with the versions...

[minlexx]

There is a requirement_linux.txt file. That should help you with the required files to run.

Where? Only README.md and that doesn't mention logbook.

But bug is not about it. I modified pyfa.py lines around line 263 this way:

    pyfalog.debug('Before logging_setup.threadbound():')
    with logging_setup.threadbound():
        pyfalog.debug('inside with logging_setup.threadbound():')

and run pyfa without --debug. The first message was printed, the second wasn't, and python2.7 continued to consume memory.

lexx@fsociety ~/dev/pyfa-1.28.0-yc119.3-1.0-linux $ /usr/bin/python2.7 pyfa.py
[2017-03-18 08:05:31.664159] WARNING: config: Failed to import: configforced
[2017-03-18 08:05:31.932257] DEBUG: config: Configuring Pyfa
[2017-03-18 08:05:32.226381] DEBUG: service.prefetch: Existing database not found, creating new database.
[2017-03-18 08:05:33.617084] DEBUG: __main__: Before logging_setup.threadbound():

[minlexx]

Oh, maybe I'm wrong, after that all logging goes into log file in ~/.pyfa/Pyfa-xxx.log? I looks like some thread is eating all cpu core and (because Pyhton is single-threaded internally) other threads do not get enough time. Log contents:

[2017-03-18 08:41:57.844052] INFO: __main__: Starting Pyfa
[2017-03-18 08:41:57.844207] INFO: __main__: Running in logging mode: User
[2017-03-18 08:41:57.904173] INFO: gui.bitmapLoader: Using zipped image files.
[2017-03-18 08:41:58.398067] DEBUG: gui.statsPane: Setting full view for: resources
[2017-03-18 08:41:58.398338] DEBUG: gui.statsPane: Setting full view for: resistances
[2017-03-18 08:41:58.398489] DEBUG: gui.statsPane: Setting full view for: recharge
[2017-03-18 08:41:58.398622] DEBUG: gui.statsPane: Setting full view for: firepower
[2017-03-18 08:41:58.398749] DEBUG: gui.statsPane: Setting full view for: outgoing
[2017-03-18 08:41:58.398874] DEBUG: gui.statsPane: Setting full view for: capacitor
[2017-03-18 08:41:58.399000] DEBUG: gui.statsPane: Setting minimal view for: targetingMisc
[2017-03-18 08:41:58.399122] DEBUG: gui.statsPane: Setting full view for: price
[2017-03-18 08:41:58.537194] DEBUG: gui.mainFrame: Initialize MainFrame
[2017-03-18 08:41:58.542343] DEBUG: service.fit: Initialize Fit class
[2017-03-18 08:41:58.862312] DEBUG: gui.marketBrowser: Initialize marketBrowser
[2017-03-18 08:41:58.865870] DEBUG: service.market: Initialize PriceWorkerThread.
[2017-03-18 08:41:58.941637] DEBUG: service.market: Initialize SearchWorkerThread.
[2017-03-18 08:41:59.173638] DEBUG: service.market: Initialize ShipBrowserWorkerThread.
[2017-03-18 08:42:16.270590] DEBUG: gui.marketBrowser: Initialize marketTree
[2017-03-18 08:42:54.446518] DEBUG: gui.marketBrowser: Initialize ItemView
[2017-03-18 08:42:55.615556] DEBUG: gui.marketBrowser: Fill up recently used modules set
[2017-03-18 08:42:55.633607] DEBUG: gui.marketBrowser: END Fill up recently used modules set
[2017-03-18 08:43:48.045562] DEBUG: gui.shipBrowser: Populate ship category list.

I've added a bit logging here and there, and notice time difference between those:

[2017-03-18 08:42:55.633607] DEBUG: gui.marketBrowser: END Fill up recently used modules set
[2017-03-18 08:43:48.045562] DEBUG: gui.shipBrowser: Populate ship category list.

Almost a minute has passed. Looks like GUI is starting, but very very very slowly. 3 minutes are enough for pyfa to consume all my RAM and get killed, so I never see if GUI completes its startup :)

Again, with --debug pyfa starts in 4 seconds fully, and consumes only around 90 Mb RAM.

[ppfeufer]

@blitzmann :: Well, I'm not a pro with git, but what ever you need me to do, just let me know and I see if I can get it done.

@minlexx :: Thanks for stepping in and helping as well.

[Ebag333]

So here are the differences that I can think of.

1. In debug mode we aren't redirecting StdErr to the log.
2. In debug mode we are always printing to the console.

If I had to guess, I would say that it's the second one. Something about the way that Python was built on Gentoo is forcing all output to the console. When we try to use the FingerCrossed handler, there's an error getting spammed that's not tripping the handler.

So, from there we have two likely scenarios.

1) Python itself is built differently. 2) Logbook is broken.

If we did a Linux build, which would include Logbook and Python, it might solve the problem. Or Gentoo might not be able to run it anyway because it's built differently.

For Python being different, maybe @minlexx can figure out how Python is built on Ubuntu/Debian/Arch and build it that way.

For Logbook being broken, not much we can do about that. Try a different version, or figure out a way to get the version off another distro.

Either way, I don't think that this is something solved in the code. This works for Windows, Mac, and every Linux distro (that we've seen tested so far) except Gentoo.

The only thing that we could do in the code (given what we know right now) is to disable Logbook entirely if Gentoo, or always be in debug mode.

[minlexx]

and every Linux distro (that we've seen tested so far)

If you have other distro where it works fine, can you plz tell logbook version there? This would be the easiest thing to test...

[Ebag333]

I couldn't get Gentoo live USB to work for me. could get to the selection screen, but when it launches just goes to a blank screen. :(

I need to rebuild my Ubuntu environment. I trashed it testing locale issues. Once I've done that, I'll get the logbook version for you.

[blitzmann]

@minlexx thanks a ton for the additional information

logbook is a new thing, and we forgot to add it to the requirements. Will do that. The Linux package that we release is basically just the source, it's up to the user to gather all dependencies. We may change this in the future depending on how new build solutions go, but this has been the case forever (we assume linux users know their way around enough to figure out how to get it running).

From you're testing, it seem it's choking here: with logging_setup.threadbound():. I'm not familiar with what this does, but will look into it.

On my Mint machine, logbook is v1.0.0 and this is working fine.

@minlexx @ppfeufer please confirm logbook version. python -m pip show logbook

I'm also looking into logbook documentation / posts to find out if there's anything that has been brought up before.

@Ebag333 I don't think this is a matter of how python is was compiled. Pretty sure there isn't a "eat my RAM plz" option - indeed, if compiled with more debugging options and whatnot it would be heftier and not as lean, but my gut tells me that this is something else entirely. Hopefully it's simply a version issue.

[blitzmann]

And as for more information:

The debug flag simply switches the handlers that we use. When it's on, it uses stdout and TimedRotatingFileHandler. If it's not on, then it uses FingersCrossedHandler (which uses TimedRotatingFileHandler if we trigger an error) - this may be the issue here

If the issue still persists after version checks, please replace the contents of pyfa.py with this: https://gist.github.com/blitzmann/74a85a53ae4fd6dbe9cd844a6cab59dd

This removes the FingersCrossedHandler and simply writes the logs to ~/.pyfa/. This isn't really a long-term solution, instead it's simply to narrow down what exactly is causing the issue.

Thanks everyone, will hopefully get you guys sorted

[blitzmann]

Actually, I went ahead and downgraded to 0.9.1 on my Mint VM.

Results:

GUI popped up, but shortly thereafter everything went to shit and became unresponsive - had to force quit. So I'm like 99.5% sure using v1.0.0 will fix those issues. Please confirm when you can :)

[Ebag333]

FingersCrossedHandler is relatively new. We may need to check the version of Logbook, and if it's below 1 force it into a debug like mode.

[blitzmann]

FingersCrossedHandler is relatively new.

Naw, I'm showing documentation from way back in 0.3

And this from 7 years ago: https://github.com/getlogbook/logbook/commit/a2b259cf1d63d5fdd88d478b6efb08a043ceec3b

;)

[Ebag333]

Since I'm working on a 10 year old bug, I did say relatively. ;)

I've been dealing with people using 10+ year old software all week. Kinda changes your perspective....

[ppfeufer]

Ok, I tested several logbook versions and version 1.0.0 (which is not marked as stable) did the trick. So it is indeed an issue with logbook. It's worth adding that to the readme I guess.

[blitzmann]

Ok, I tested several logbook versions and version 1.0.0 (which is not marked as stable) did the trick.

Awesome. I'm not sure hoe Gentoo handles the stable / unstable flag, but v1.0.0 is the latest release. It's been added as the minimum version for pyfa. :D

[minlexx]

I'll test it tomorrow, too (had no time today) 😭

[minlexx]

Can confirm, with dev-python/logbook-1.0.0 pyfa starts fine here without --debug option. Gentoo users have to unkeyword unstable versions of packages to be able to install them, with command like this:

echo "=dev-python/logbook-1.0.0 ~amd64" >> /etc/portage/package.accept_keywords/dev-python"

But I guess @ppfeufer already knows that.

[blitzmann]

I'm assuming it can also be added via python's pip rather than going through the distros repo.

Anyway, glad we got that sorted out. :D