Thread: [Announce] modRana: a flexible GPS navigation system
View Single Post
MartinK is offline MartinK
2014-10-06 , 21:42
Posts: 1,548 | Thanked: 7,510 times | Joined on Apr 2010 @ Czech Republic
#1658
What's new in modRana 0.49.2
New features described in nice, friendly letters.

Proper logging infrastructure
While really interesting for normal modRana users, if you ever needed to debug a modRana issue or just are interested what is modRana actually doing behind the scenes, you might want to make note.

Up till now, modRana had no logging system - all messages went directly to stdout through a simple print call. There have been many issues with this system (messages from threads mixing up, no log on console is log file was enabled). This now a thing of the past and modRana now uses the marvelous Python logging module - even for logging messages in the QtQuick 2.0 based Qt 5 GUI (possible thanks to the powerful asynchronous architecture of the PyOtherSide project).
  • log levels - log messages now have levels that make it easy to see how important a given message is (INFO, DEBUG, ERROR, CRITICAL, etc.)
  • no messages are lost from the log file - the log file (if enabled) has even the earliest log messages
  • even if log file is enabled console still shows log output (this was not possible with the old "stdout" log)
    • If you have any issues with modRana and you want to help me with debugging them, just leave the log files to be always enabled, there should be no noticable performance penalty and you can send me the log files once you hit an issue.
  • the log file has timestamps for all messages, which the console omits them for easier readability
  • messages from threads no longer mix-up
  • all messages have nice prefixes that make it possible to easily see their origin

You can enable logging Options->Debug->Logging in the GTK GUI and in Options->Debug in the Qt 5 GUI.

As for how the new log output now looks like, this is a log file from just starting and shutting down modRana:

Code:
2014-10-06 23:24:30,666 INFO : == modRana Starting == 
2014-10-06 23:24:30,667 INFO :  testing version1
2014-10-06 23:24:30,667 INFO :  Python 2.7.5
2014-10-06 23:24:30,668 INFO : * device: A modRana device-specific module for PC (0.99 ms)
2014-10-06 23:24:30,668 INFO :loading options
2014-10-06 23:24:30,669 INFO :log file enabled: /home/user/.modrana/debug_logs/modrana_20141006#21-24-30.log
2014-10-06 23:24:30,760 DEBUG mod.gui.gtk:size allocation: gtk.gdk.Rectangle(0, 0, 800, 480)
2014-10-06 23:24:30,760 ERROR mod.gui.gtk:error in screen invalidating function
Traceback (most recent call last):
  File "modules/gui_modules/gui_gtk.py", line 454, in forceRedraw
    self.window.invalidate_rect((0, 0, self.rect.width, self.rect.height), False)
AttributeError: 'NoneType' object has no attribute 'invalidate_rect'
2014-10-06 23:24:30,763 INFO : * gui: A GTK GUI module (68.30 ms)
2014-10-06 23:24:30,764 INFO :importing modules:
2014-10-06 23:24:30,805 INFO : * turnByTurn: A turn by turn navigation module. (40.41 ms)
2014-10-06 23:24:30,805 INFO : * textEntry: A module for handling text entry. (0.15 ms)
2014-10-06 23:24:30,805 INFO : * interfaceFeedback: A sample pyroute module (0.09 ms)
2014-10-06 23:24:30,806 INFO : * updateTiles: Update stored map tiles. (0.09 ms)
2014-10-06 23:24:30,807 INFO : * theme: ModRana theming module (1.06 ms)
2014-10-06 23:24:30,807 INFO : * clickHandler: handle mouse clicks (0.26 ms)
2014-10-06 23:24:30,814 INFO : * mapLayers: Map layer handling (6.74 ms)
2014-10-06 23:24:30,815 INFO mod.location:using GPSD
2014-10-06 23:24:30,815 INFO mod.location.gpsd:location: gpsd not used, so there is no debug output to enable
2014-10-06 23:24:30,815 INFO : * location: Supplies position info from a position source (0.89 ms)
2014-10-06 23:24:30,815 INFO : * showPOI: Show POI on the map and in the menu. (0.19 ms)
2014-10-06 23:24:30,816 INFO : * askMenu: A module providing yes/no question dialogs (0.12 ms)
2014-10-06 23:24:30,816 INFO : * info: A modRana information handling module (0.16 ms)
2014-10-06 23:24:30,816 INFO : * example: A sample modRana module (0.13 ms)
2014-10-06 23:24:30,817 INFO : * sketch: Sketching functionality (0.21 ms)
2014-10-06 23:24:30,817 INFO : * notification: This module provides notification support. (0.24 ms)
2014-10-06 23:24:30,817 INFO : * display: A platform independent display device control module (0.16 ms)
2014-10-06 23:24:30,817 INFO : * input: Handle input from keyboard, buttons, etc. (0.10 ms)
2014-10-06 23:24:30,829 INFO : * onlineServices: A module for talking to various online services (11.13 ms)
2014-10-06 23:24:30,831 INFO : * menu: Handle menus (1.84 ms)
2014-10-06 23:24:30,831 INFO : * animatedMapView: A sample pyroute module (0.36 ms)
2014-10-06 23:24:30,846 INFO : * tileserver: A modRana built-in tileserver (14.66 ms)
2014-10-06 23:24:30,847 INFO : * units: a unit handling module  (0.38 ms)
2014-10-06 23:24:30,848 INFO : * tracklog: Record tracklogs (0.43 ms)
2014-10-06 23:24:30,852 INFO mod.storeTiles:sqlite tile database commit interval: 150 s
2014-10-06 23:24:30,852 INFO : * storeTiles: Single-file-fs tile storage (3.86 ms)
2014-10-06 23:24:30,852 INFO : * search: Search for POI (0.42 ms)
2014-10-06 23:24:30,853 INFO : * showTracklogs: draws a GPX track on the map (0.31 ms)
2014-10-06 23:24:30,855 INFO : * mapData: Handle downloading of map data (2.29 ms)
2014-10-06 23:24:30,858 INFO : * routeProfile: Creates a route profile (an elevation chart) (2.79 ms)
2014-10-06 23:24:30,859 INFO mod.storePOI:POI database path:
2014-10-06 23:24:30,860 INFO mod.storePOI:/home/user/.modrana/poi/modrana_poi.db
2014-10-06 23:24:30,860 INFO mod.storePOI:connection to POI db established
2014-10-06 23:24:30,860 INFO : * storePOI: Store POI data. (1.40 ms)
2014-10-06 23:24:30,861 INFO : * stats: Handles statistics (0.28 ms)
2014-10-06 23:24:30,861 INFO : * markers: A module handling markers on the map. (0.58 ms)
2014-10-06 23:24:30,862 INFO : * voice: Handle text to speech. (0.24 ms)
2014-10-06 23:24:30,864 INFO : * route: Routes (1.60 ms)
2014-10-06 23:24:30,864 INFO : * projection: Projection code (lat/long to screen conversions) (0.62 ms)
2014-10-06 23:24:30,865 INFO : * keys: A keyboard input handling module (0.21 ms)
2014-10-06 23:24:30,865 INFO : * positionMarker: A sample pyroute module (0.20 ms)
2014-10-06 23:24:30,868 INFO : * icons: Draw icons (2.37 ms)
2014-10-06 23:24:30,868 INFO : * mapView: Controls the view being displayed on the map (0.33 ms)
2014-10-06 23:24:30,869 INFO : * showOSD: Draw OSD (On Screen Display). (0.32 ms)
2014-10-06 23:24:30,869 INFO : * tracklogManager: Module for managing tracklogs (0.28 ms)
2014-10-06 23:24:30,921 WARNING mod.mapTiles:import of image manipulation tools unsuccessful - tile image manipulation disabled
2014-10-06 23:24:30,921 INFO mod.mapTiles:in memory tile cache size: 150
2014-10-06 23:24:30,934 INFO mod.mapTiles:map folder path: /home/user/.modrana/maps
2014-10-06 23:24:30,934 INFO : * mapTiles: Display map images (48.41 ms)
2014-10-06 23:24:30,935 INFO : * messages: Handles messages (0.26 ms)
2014-10-06 23:24:30,940 INFO : * options: Handle options (4.89 ms)
2014-10-06 23:24:30,941 INFO : * loadTracklogs: A sample pyroute module (0.72 ms)
2014-10-06 23:24:30,942 INFO : * cron: A GTK timing and scheduling module for modRana (0.39 ms)
2014-10-06 23:24:30,942 INFO :Loaded all modules in 160.80 ms, initialising
2014-10-06 23:24:30,945 DEBUG mod.mapTiles:automatic tile download queue size: 100
2014-10-06 23:24:30,946 INFO core.threads:Running Thread: automaticTileDownloadWorker1 (139698080937728)
2014-10-06 23:24:30,946 INFO core.threads:Running Thread: automaticTileDownloadWorker2 (139698072545024)
2014-10-06 23:24:30,947 INFO core.threads:Running Thread: automaticTileDownloadWorker3 (139698064152320)
2014-10-06 23:24:30,952 INFO mod.icons:switched theme to: default
2014-10-06 23:24:30,955 INFO mod.options:reloading Monav data pack list
2014-10-06 23:24:30,955 INFO mod.location:starting GPSD 1 second timer
2014-10-06 23:24:30,956 INFO mod.location:enabling location
2014-10-06 23:24:30,957 WARNING mod.location.gpsd:GPS daemon refused initial connection
2014-10-06 23:24:30,957 INFO mod.location.gpsd:gpsd debugging output turned OFF
2014-10-06 23:24:30,957 INFO core.threads:Running Thread: modRanaGPSDConsumer (139697158350592)
2014-10-06 23:24:30,958 INFO mod.loadTracklogs:** making a list of available tracklogs
2014-10-06 23:24:30,958 INFO core.threads:Thread Done: modRanaGPSDConsumer (139697158350592)
2014-10-06 23:24:30,960 INFO mod.loadTracklogs:*  using this tracklog folder:
2014-10-06 23:24:30,960 INFO mod.loadTracklogs:* /home/user/.modrana/tracklogs
2014-10-06 23:24:30,960 INFO mod.loadTracklogs:*  there are 26 tracklogs available
2014-10-06 23:24:30,960 INFO mod.loadTracklogs:**
2014-10-06 23:24:30,961 INFO mod.mapView:switching map drag mode to default
2014-10-06 23:24:30,961 INFO mod.mapView:switching centering disable threshold to 2048
2014-10-06 23:24:30,961 INFO :Initialization complete in 19.82 ms
2014-10-06 23:24:30,961 INFO :** modRana startup timing **
2014-10-06 23:24:30,961 INFO :# device: A generic Personal Computer (pc)
2014-10-06 23:24:30,961 INFO :* modRana start (0 ms), 0/354 ms
2014-10-06 23:24:30,962 INFO :* imports done (56 ms), 56/354 ms
2014-10-06 23:24:30,962 INFO :* GUI creation (0 ms), 57/354 ms
2014-10-06 23:24:30,962 INFO :* window created (75 ms), 131/354 ms
2014-10-06 23:24:30,962 INFO :* map widget created (0 ms), 131/354 ms
2014-10-06 23:24:30,962 INFO :* window finalized (25 ms), 156/354 ms
2014-10-06 23:24:30,962 INFO :* all modules loaded (179 ms), 335/354 ms
2014-10-06 23:24:30,962 INFO :* all modules initialized (19 ms), 354/354 ms
2014-10-06 23:24:30,962 INFO :** whole startup: 354 ms **
2014-10-06 23:24:30,962 INFO mod.display:redraw ON (window not hidden or minimised)
2014-10-06 23:24:30,963 INFO mod.display:redraw ON (window is un-obscured or partially obscured)
2014-10-06 23:24:33,696 INFO mod.clickHandler:Clicked, sending menu:screenClicked
2014-10-06 23:24:33,696 INFO mod.clickHandler:Clicked, sending set:menu:main
2014-10-06 23:24:34,576 INFO mod.clickHandler:Clicked, sending set:menu:None
2014-10-06 23:24:35,617 INFO :Shutting-down modules
2014-10-06 23:24:35,618 INFO core.threads:Running Thread: automaticTileDownloadShutdown (139697158350592)
2014-10-06 23:24:35,618 INFO mod.mapTiles:automatic tile download management thread shutting down
2014-10-06 23:24:35,619 INFO mod.mapData:stopping batch tile download
2014-10-06 23:24:35,619 INFO mod.storeTiles:shutdown imminent, committing all uncommitted tiles
2014-10-06 23:24:35,620 INFO core.threads:Thread Done: modRanaTileDownloadManager (139697720366848)
2014-10-06 23:24:35,620 INFO core.threads:Thread Done: automaticTileDownloadWorker1 (139698080937728)
2014-10-06 23:24:35,620 INFO core.threads:Thread Done: automaticTileDownloadWorker3 (139698064152320)
2014-10-06 23:24:35,621 INFO core.threads:Thread Done: automaticTileDownloadWorker2 (139698072545024)
2014-10-06 23:24:35,622 INFO mod.mapData:stopping batch size estimation
2014-10-06 23:24:35,622 DEBUG mod.storeTiles:sqlite commit OK (0 tiles)
2014-10-06 23:24:35,623 INFO core.threads:Thread Done: automaticTileDownloadWorker5 (139697770723072)
2014-10-06 23:24:35,627 INFO mod.storePOI:disconnecting from POI db
2014-10-06 23:24:35,627 INFO mod.storeTiles:all tiles committed, breaking, goodbye :)
2014-10-06 23:24:35,630 INFO mod.location:location: disabling location
2014-10-06 23:24:35,630 INFO core.threads:Thread Done: modRanaTileStorageLoader (139697166743296)
2014-10-06 23:24:35,630 INFO mod.location.gpsd:GPSDConsumer: stopping
2014-10-06 23:24:35,631 INFO mod.turnByTurn:stopped
2014-10-06 23:24:35,631 INFO :saving options
2014-10-06 23:24:35,632 INFO :options successfully saved
2014-10-06 23:24:37,632 INFO :Shutdown complete
Also on paste, as TMO seems to have some issues with properly formatting the log.

A number of internal tunables now have a configuration option in the GTK GUI
As requested for debugging or finding a workaround for the crashing & freezing issues on the N900 I have exposed a number of tunables in the GTK GUI:
  • periodic screen redraw time - not needed
    Manual map movement generates much more redraw events than periodic updates, so the current once-per-second update is unlikely to influence the N900 crashes,
    also the most demanding automatic updates happen during fast movement and you want to have updates as often as possible in such cases (highway, airplane, speedboat, etc.).
  • don't redraw when tile is loaded
    Options->Debug->Tiles->"Redraw screen once a new tile is loaded" (ON/OFF)
  • number of automatic download threads
    Options->Network->Network usage->"Auto tile download thread count"
  • number of batch download threads - done
    Options->Network->Network usage->"Batch tile download thread count"
  • tile cache size - done
    Options->Debug->Tiles->"In memory tile cache size"
  • tile download queue size - done
    Options->Debug->Tiles->"Auto tile download queue size"
  • sqlite commit interval
    Options->Map->Tile storage->"Sqlite tile db commit interval"
Please not that the tunables are primarily intended for debugging purposes and are not non-default values are not well tested and some values and combinations might might not even work at all.

Looking forward to your feedback and lets hope that this gets use closer to debugging the N900 freezes/crashes or at least makes it possible to find a workaround that could be enabled by default.

Sailfish OS improvements
The main user-visible Sailfish OS improvement in this modRana update is volume rocker support - while you are at the map screen, you can use the volume rocker to zoom the map in and out. On other screen the volume rocker currently work just like normal volume control. Field testing shows that this feature is quite handy when using modRana while walking.

It is also now possible to turn the log file on and off in Options->Debug (as already mentioned above), but the page also display the full path ti the currently active log file (if any).

And on the Options->Map page you can now see the path to the currently used map data folder and the amount of free space in the folder (but keep in mind that BTRFS has a rather special interpretation of the term "free space").

Also the combo boxes now should look a bit more Sailfishy.

GTK GUI (Maemo 5/Fremantle) improvements
You can now tell modRana to always start in fullscreen and to always show a quite button - both can be configured in Options->View->UI.
__________________
modRana: a flexible GPS navigation system
Mieru: a flexible manga and comic book reader
Universal Components - a solution for native looking yet component set independent QML appliactions (QtQuick Controls 2 & Silica supported as backends)
Last edited by MartinK; 2014-10-06 at 21:46.
 

The Following 15 Users Say Thank You to MartinK For This Useful Post: