search

Project-OSRM / osrm-backend

Open Source Routing Machine - C++ backend
http://map.project-osrm.org
BSD 2-Clause "Simplified" License
6.28k stars 3.32k forks source link

osrm-routed aborts due to 'std::out_of_range' #189

Closed emiltin closed 12 years ago

emiltin commented 12 years ago

i have a my own demo server running, but once in a while osmr-routed aborts. the log file shows:

[server] starting up engines, saved at Sun Feb 26 09:42:44 2012 [server] http 1.1 compression handled by zlib version 1.2.3.4 [info Plugins/ObjectForPluginStruct.h:42] loading graph data [info Plugins/ObjectForPluginStruct.h:48] Data checksum is 746045511 [info Plugins/ObjectForPluginStruct.h:52] Loading nearest neighbor indices [info Plugins/ObjectForPluginStruct.h:59] Loading names index [info Plugins/ObjectForPluginStruct.h:76] All query data structures loaded [handler] registering plugin hello [handler] registering plugin locate [handler] registering plugin nearest [handler] registering plugin viaroute [server] running and waiting for requests terminate called after throwing an instance of 'std::out_of_range' what(): basic_string::substr Aborted

emiltin commented 12 years ago

i've experienced this twice. i will rebuild the binaries on the server from the latest version and see if it still occurs.

emiltin commented 12 years ago

more detailing logging showing each request would make it much eaiser to debug issues like this

DennisOSRM commented 12 years ago

Could you compile as debug, run in gdb and post a stack trace here?

DennisOSRM commented 12 years ago

I may have already an idea where this is coming from.

emiltin commented 12 years ago

i don't know what triggers it. what was your hunch?

emiltin commented 12 years ago

got this again with revision f8fb79a8388009b973ad124de172d45b9b045d63. after running for a few days the process is suddently not running anymore, the log file shows

... [debug Plugins/ViaRoutePlugin.h:144] Error occurred, single path not found [debug Plugins/ViaRoutePlugin.h:144] Error occurred, single path not found [debug Plugins/ViaRoutePlugin.h:144] Error occurred, single path not found [debug Plugins/ViaRoutePlugin.h:144] Error occurred, single path not found [debug Plugins/ViaRoutePlugin.h:144] Error occurred, single path not found [debug Plugins/ViaRoutePlugin.h:144] Error occurred, single path not found [debug Plugins/ViaRoutePlugin.h:144] Error occurred, single path not found [debug Plugins/ViaRoutePlugin.h:144] Error occurred, single path not found [debug Plugins/ViaRoutePlugin.h:144] Error occurred, single path not found [debug Plugins/ViaRoutePlugin.h:144] Error occurred, single path not found [debug Plugins/ViaRoutePlugin.h:144] Error occurred, single path not found [debug Plugins/ViaRoutePlugin.h:144] Error occurred, single path not found terminate called after throwing an instance of 'std::out_of_range' what(): basic_string::substr Aborted

i tried runnign it with gdb, but since it's a virtual server and doesnt' happen all the time, it's hard to get a stack trace

emiltin commented 12 years ago

all these 'single path not found' makes me wonder if this could be related to the old #37?

emiltin commented 12 years ago

it seems i was in fact running the older f8fb79a8388009b973ad124de172d45b9b045d63. will post if it occurs with latest

DennisOSRM commented 12 years ago

Concerning the cluttering, are you running debug builds? Because in release builds, the DEBUG() switch is turned off:

#ifdef NDEBUG
#define DEBUG(x)
#define GUARANTEE(x,y)
#else
#define DEBUG(x) do {std::cout << "[debug " << __FILE__ << ":" << __LINE__ << "] " << x << std::endl;} while(0);
#define GUARANTEE(x,y) do { {do{ if(false == (x)) { ERR(y) } } while(0);} } while(0);
#endif
emiltin commented 12 years ago

you're right, i was running debug mode, since i was trying to get a stack trace

DennisOSRM commented 12 years ago

Well, debug mode is more verbose.

emiltin commented 12 years ago

did you figure out wha causes the std::out_of_range?

DennisOSRM commented 12 years ago

Not entirely sure yet. I fixed a bug today that causes segfaults and I suspect it to fix some other bug, too. Unfortunately, we don't have a query that caused the std::out_of_range, so it's a bit guessing ;)

DennisOSRM commented 12 years ago

Any news on this issue? Did it occur again?

emiltin commented 12 years ago

sorry didn't have time to check. i need to update the code on my test server to latest version of osrm, which will include updating the gui (which i ported to rails) to match api changes in osrm. but yes, with rev f8fb79a8388009b973ad124de172d45b9b045d63 osrm-routed had aborted again with the same error

DennisOSRM commented 12 years ago

Uncomment Server/RequestHandler.h:60-61

It will print out every request and the last one before the crash will be the guy we are looking for.

DennisOSRM commented 12 years ago

Any news on this one?

emiltin commented 12 years ago

not sure, i think it was still aborting once it a while, but now i'm running it with linux upstart, so it restarts. perhaps i can check the log file

emiltin commented 12 years ago

just got this again on my server, running version 1173ac17eee9e8e1f94534f20ee9956680161c8e.

the log file shows:

(cloud.dk) ~/Project-OSRM/sandbox$ (master) tail osrm-routed.log 
[info Server/RequestHandler.h:61] 06-04-2012 14:00:28 190.146.154.9 /web/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:29 190.146.154.9 /websql/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:29 190.146.154.9 /wp-content/plugins/wp-phpmyadmin/wp-phpmyadmin/phpmyadmin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:30 190.146.154.9 /wp-phpmyadmin/phpmyadmin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:30 190.146.154.9 /wp-phpmyadmin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:31 190.146.154.9 /xampp/phpmyadmin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:31 190.146.154.9 
terminate called after throwing an instance of 'std::out_of_range'
  what():  basic_string::substr
Aborted

someone is obviously hoping to find an unprotected php admin interface... but i don't think that is the cause?

emiltin commented 12 years ago

on second thought, maybe it is in fact the parsing of an invalid incoming url that bombs out? it seems they did manage to take down my osrm server :-(

emiltin commented 12 years ago

looks like it's the romanian branch of anti-sec :-)

[info Server/RequestHandler.h:61] 06-04-2012 13:59:18 190.146.154.9 /w00tw00t.at.blackhats.romanian.anti-sec:)
[info Server/RequestHandler.h:61] 06-04-2012 13:59:21 190.146.154.9 /admin/mysql/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 13:59:22 190.146.154.9 /admin/phpmyadmin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 13:59:22 190.146.154.9 /admin/pma/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 13:59:22 190.146.154.9 /_admin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 13:59:23 190.146.154.9 /admin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 13:59:23 190.146.154.9 admin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 13:59:24 190.146.154.9 /admm/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 13:59:24 190.146.154.9 /admn/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 13:59:25 190.146.154.9 /backup/phpmyadmin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 13:59:25 190.146.154.9 /backup/phpMyAdmin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 13:59:25 190.146.154.9 /bbs/data/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 13:59:26 190.146.154.9 /bkup/phpmyadmin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 13:59:26 190.146.154.9 /bkup/phpMyAdmin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 13:59:27 190.146.154.9 /cpadmindb/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 13:59:27 190.146.154.9 /cpadmin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 13:59:27 190.146.154.9 /cpanelmysql/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 13:59:28 190.146.154.9 /cpanelphpmyadmin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 13:59:28 190.146.154.9 /cpanelsql/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 13:59:32 190.146.154.9 /cpphpmyadmin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 13:59:35 190.146.154.9 /dbadmin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 13:59:36 190.146.154.9 /db/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 13:59:36 190.146.154.9 /myadmin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 13:59:42 190.146.154.9 /MyAdmin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 13:59:42 190.146.154.9 /mysqladminconfig/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 13:59:42 190.146.154.9 /mysql-admin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 13:59:43 190.146.154.9 /mysqladmin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 13:59:43 190.146.154.9 /MySQLAdmin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 13:59:46 190.146.154.9 /mysql/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 13:59:50 190.146.154.9 /phpmanager/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 13:59:53 190.146.154.9 /phpmyadmin1/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:00 190.146.154.9 /php-my-admin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:03 190.146.154.9 /phpmy-admin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:03 190.146.154.9 /phpmyadmin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:04 190.146.154.9 /_phpMyAdmin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:05 190.146.154.9 /phpMyAdmin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:11 190.146.154.9 /phpMyAdmi/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:12 190.146.154.9 /phpmyad/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:12 190.146.154.9 /phpMyAds/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:13 190.146.154.9 /phpmyad-sys/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:13 190.146.154.9 /phpmya/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:14 190.146.154.9 /phpMyA/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:14 190.146.154.9 /phpmy/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:14 190.146.154.9 /pHpMy/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:15 190.146.154.9 /php/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:15 190.146.154.9 /pma2005/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:16 190.146.154.9 /PMA2005/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:16 190.146.154.9 /p/m/a/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:16 190.146.154.9 /pma/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:17 190.146.154.9 /pMA/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:17 190.146.154.9 /~/PMA/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:18 190.146.154.9 /PMA/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:18 190.146.154.9 /roundcube/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:19 190.146.154.9 /scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:19 190.146.154.9 /sl2/data/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:19 190.146.154.9 /sqladmin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:20 190.146.154.9 /sqlmanager/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:20 190.146.154.9 /sql/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:21 190.146.154.9 /SQL/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:21 190.146.154.9 /sqlweb/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:22 190.146.154.9 /SSLMySQLAdmin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:22 190.146.154.9 /typo3/phpmyadmin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:22 190.146.154.9 /vhcs2/tools/pma/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:23 190.146.154.9 /webadmin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:28 190.146.154.9 /web/phpmyadmin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:28 190.146.154.9 /web/phpMyAdmin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:28 190.146.154.9 /web/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:29 190.146.154.9 /websql/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:29 190.146.154.9 /wp-content/plugins/wp-phpmyadmin/wp-phpmyadmin/phpmyadmin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:30 190.146.154.9 /wp-phpmyadmin/phpmyadmin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:30 190.146.154.9 /wp-phpmyadmin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:31 190.146.154.9 /xampp/phpmyadmin/scripts/setup.php
[info Server/RequestHandler.h:61] 06-04-2012 14:00:31 190.146.154.9 
terminate called after throwing an instance of 'std::out_of_range'
  what():  basic_string::substr
Aborted
emiltin commented 12 years ago

i'm running osrm-routed with an upstart config file. upstart reports that the osrm-routed process is still running:

(cloud.dk) ~/Project-OSRM$ (master) initctl status osrm
osrm start/running, process 666

but it's not responding to request.

DennisOSRM commented 12 years ago

This may be very well an ill-parsed command.

emiltin commented 12 years ago

you mean a specific ill-formed request that causes the parser to break?

emiltin commented 12 years ago

had this again - osrm-routed aborted. log shows:

cloud.dk) ~/Project-OSRM/sandbox$ (alpha) tail osrm-routed.log.1
[info Server/RequestHandler.h:61] 26-07-2012 02:07:52 220.165.246.85  /phpMyAdmin-2.5.5-pl1/index.php
[info Server/RequestHandler.h:61] 26-07-2012 02:07:52 220.165.246.85  /phpMyAdmin-2.5.6-rc1/index.php
[info Server/RequestHandler.h:61] 26-07-2012 02:07:53 220.165.246.85  /phpMyAdmin-2.5.6-rc2/index.php
[info Server/RequestHandler.h:61] 26-07-2012 02:07:54 220.165.246.85  /phpMyAdmin-2.5.6/index.php
[info Server/RequestHandler.h:61] 26-07-2012 02:07:54 220.165.246.85  /phpMyAdmin-2.5.7/index.php
[info Server/RequestHandler.h:61] 26-07-2012 02:07:55 220.165.246.85  /phpMyAdmin-2.5.7-pl1/index.php
[info Server/RequestHandler.h:61] 26-07-2012 02:07:56 220.165.246.85  
terminate called after throwing an instance of 'std::out_of_range'
  what():  basic_string::substr
Aborted

again it seems someone is hoping to find an php admin page, and some empty (or non-printing) url causes osrm-routed to abort.

it's a build from a while ago:

commit a3949737624d203d68ae50e68abc32db27d0c85a
Author: DennisOSRM <luxen@kit.edu>
Date:   Fri May 4 22:25:56 2012 +0200

    Merging 4f73b47 into master

with some local edits, mainly related to rake tasks.

DennisOSRM commented 12 years ago

Fixed