Timeout error on matching server

[adlersantos]

Hi! I'm trying to call the matching server using the following command:

$ python util/submit/batch.py --host localhost --port 1234  --file samples/sample.json

where the contents of sample.json are (coordinates in Singapore, time between consecutive points is around 10 seconds)

[
  {"id":"1", "time":1478473108000, "point":"POINT (1.32918 103.926589)"},
  {"id":"2", "time":1478473119000, "point":"POINT (1.329221 103.925728)"},
  {"id":"3", "time":1478473130000, "point":"POINT (1.329668 103.924459)"},
  {"id":"4", "time":1478473139000, "point":"POINT (1.32956 103.924051)"},
  {"id":"5", "time":1478473150000, "point":"POINT (1.329864 103.922148)"}
]

I was able to setup the matching server using a singapore.osm.pbf, and I also double checked the docker container's database if it's populated. So far everything's okay.

But when I run the batch.py script above on the command line, I get

$ python util/submit/batch.py --host localhost --port 1234  --file sample/sample.json         [ruby-2.3.3]
TIMEOUT

Also, the matching server logs says:

2017-02-09 15:53:03,339 ERROR [Thread-13] AbstractServer: 127.0.0.1:51529 request handler timeout

I also tried the following approaches just to check if I'm missing some aspect/s of the setup:

• I was using a custom built .osm.pbf file for the importing. So I tried to use a pre-built one for Singapore (https://mapzen.com/data/metro-extracts/metro/singapore/). Then, I re-did the data importing and server setup process, but still get the timeout.
• I'm using the default road-types.json provided for the road type configuration. I tried to change the sample.json input above so that the points are located along a highway in Singapore. I still get the timeout.

Here's what my server.properties have, just in case it's needed:

server.port=1234
server.timeout.request=5000
server.timeout.response=60000
server.connections=20
matcher.sigma=4.5
matcher.lambda=0.0
matcher.distance.max=15000
matcher.radius.max=200
matcher.interval.min=1000
matcher.distance.min=0
matcher.threads=8

Hope you can help. Thank you!

[smattheis]

Do you get a timeout with only 5 sample points, or do you actually send more and this was only an example? (In a dense city area, map matching can take longer because of intense routing efforts.) You could try with a higher server.timeout.response value than - as in your configuration - 60 seconds. Also, you can tune parameters a bit:

• If you know that you have a quite fixed time interval where your objects can travel only some maximum distance, then you can decrease the matcher.distance.max to a lower value. This parameter limits route search depth in case of unconnected graph components in the map to - in your configuration - 15 kilometers. A car with maximum speed of 300 km/h can travel at most 1.250 meters in 15 seconds. However, this only decreases computation time, if worst-case scenarios occur!
  • If you have good quality of position measurements or can accept some errors in map matching, you can also decrease the search radius for map matching candidates, i.e., matcher.radius.max, to something like 100 meters instead of 200 meters. Thils will decrease computation costs for map matching a lot, especially in dense city areas. 200 meters is an extremely high (but reasonable) tolerance of position measurement errors, because GPS has a standard deviation of 4.5 meters (see matcher.sigma).

For detailed info about parameters, see here: https://github.com/bmwcarit/barefoot/wiki#parameters

Note: Regarding your concerns about the setup, you could try matching one sample and see if you get an output. In that case, the matcher would not do any routing, but you will see if map import works and spatial access to map is working. Afterwards, you can send two samples and see if you a get routes between candidates. If that works too, your setup should be fine.

[adlersantos]

Thanks for the quick response and clear explanation! (It would be nice to add those above in the docs)

I tried with the following changes to my server.properties:

server.timeout.request=20000 (previously 5000)
server.timeout.response=100000 (previously 60000)
matcher.distance.max=100 (previously 15000)
matcher.radius.max=20 (previously 200)

and with just one sample point:

[{"id":"x001", "time":1478473108000, "point":"POINT (1.3440974 103.8579043)"}]

Unfortunately, I'm still getting the timeout. I added some additional outputs in AbstractServer.run() around here and here where request handler timeout is being printed. Here's what I got:

2017-02-09 20:20:13,338 ERROR [Thread-14] AbstractServer: ===== Printing `maxRequestTime`: 20000
2017-02-09 20:20:18,344 ERROR [Thread-14] AbstractServer: ===== Printing `client.getInetAddress().getHostAddress()`: 127.0.0.1
2017-02-09 20:20:18,344 ERROR [Thread-14] AbstractServer: ===== Printing `client.getPort()`: 51785
2017-02-09 20:20:18,344 ERROR [Thread-14] AbstractServer: ===== Printing `request`: null
2017-02-09 20:20:18,344 ERROR [Thread-14] AbstractServer: 127.0.0.1:51785 request handler timeout

I think it's odd for a request containing only one sample point to continue being null after waiting of 20 seconds?

[smattheis]

Sorry, I mixed up the request and response handler in my previous comment as I thought you have timeout of the response handler which does the map matching. If there's a timeout of the request handler which just waits for and accepts the sample data, it means that it doesn't get the (request) data in time. There may be something wrong with the data format you send or with submission script. Can you send me the complete server log from server startup?

[adlersantos]

No worries! Here you go for the server startup log:

$ java -jar target/barefoot-0.1.0-matcher-jar-with-dependencies.jar --slimjson config/server.properties config/singapore.properties
2017-02-09 21:33:13,366 INFO  [main] ServerControl: initialize server
2017-02-09 21:33:13,369 INFO  [main] ServerControl: read database properties from file config/singapore.properties
2017-02-09 21:33:13,371 INFO  [main] Loader: load map from file /Users/adler/swat/barefoot/barefoot-singapore.bfmap
2017-02-09 21:33:13,448 INFO  [main] RoadMap: inserting roads ...
2017-02-09 21:33:14,414 INFO  [main] RoadMap: inserted 100000 (174389) roads
2017-02-09 21:33:14,812 INFO  [main] RoadMap: inserted 146573 (255474) roads and finished
2017-02-09 21:33:15,112 INFO  [main] RoadMap: ~50 megabytes used for road data (estimate)
2017-02-09 21:33:15,263 INFO  [main] RoadMap: index and topology constructing ...
2017-02-09 21:33:16,148 INFO  [main] RoadMap: index and topology constructed
2017-02-09 21:33:16,413 INFO  [main] RoadMap: ~23 megabytes used for spatial index (estimate)
2017-02-09 21:33:16,413 INFO  [main] ServerControl: read tracker properties from file config/server.properties
2017-02-09 21:33:16,438 INFO  [main] MatcherServer: matcher.radius.max=10.0
2017-02-09 21:33:16,438 INFO  [main] MatcherServer: matcher.distance.max=200.0
2017-02-09 21:33:16,438 INFO  [main] MatcherServer: matcher.lambda=0.0
2017-02-09 21:33:16,438 INFO  [main] MatcherServer: matcher.sigma=4.5
2017-02-09 21:33:16,438 INFO  [main] MatcherServer: matcher.threads=8
2017-02-09 21:33:16,439 INFO  [main] MatcherServer: matcher.interval.min=1000
2017-02-09 21:33:16,439 INFO  [main] MatcherServer: matcher.distance.min=0.0
2017-02-09 21:33:16,439 INFO  [main] AbstractServer: server.port=1234
2017-02-09 21:33:16,439 INFO  [main] AbstractServer: server.timeout.request=20000
2017-02-09 21:33:16,439 INFO  [main] AbstractServer: server.timeout.response=100000
2017-02-09 21:33:16,439 INFO  [main] AbstractServer: server.connections=20
2017-02-09 21:33:16,439 INFO  [main] ServerControl: starting server on port 1234 with map barefoot-singapore
2017-02-09 21:33:16,445 INFO  [main] AbstractServer: listening on port 1234 ...

[adlersantos]

Just to check if the submission script or data format isn't working, I tried calling the matching server manually via the Postman app on Chrome.

The POST request is as follows (which I may be missing some parameters or headers):

POST  HTTP/1.1
Host: localhost:1234
Content-Type: application/json
Cache-Control: no-cache
Postman-Token: 7edb93c4-98bb-06ea-312a-600314012e08

[
  {"id":"x001", "time":1478473108000, "point":"POINT (1.32918 103.926589)"},
  {"id":"x001", "time":1478473119000, "point":"POINT (1.329221 103.925728)"},
  {"id":"x001", "time":1478473130000, "point":"POINT (1.329668 103.924459)"},
  {"id":"x001", "time":1478473139000, "point":"POINT (1.32956 103.924051)"},
  {"id":"x001", "time":1478473150000, "point":"POINT (1.329864 103.922148)"}
]

And the server logs now output

2017-02-09 21:45:19,056 ERROR [pool-2-thread-6] MatcherServer: java.lang.String cannot be cast to org.json.JSONArray
java.lang.ClassCastException: java.lang.String cannot be cast to org.json.JSONArray
    at com.bmwcarit.barefoot.matcher.MatcherServer$InputFormatter.format(MatcherServer.java:76)
    at com.bmwcarit.barefoot.matcher.MatcherServer$MatcherResponseFactory$1.response(MatcherServer.java:288)
    at com.bmwcarit.barefoot.util.AbstractServer$ResponseHandler.call(AbstractServer.java:143)
    at com.bmwcarit.barefoot.util.AbstractServer$ResponseHandler.call(AbstractServer.java:119)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)

Let me know what you think.

[smattheis]

Yep, I just saw it: Since the input format requires WKT (see https://en.wikipedia.org/wiki/Well-known_text) you need to swap the coordinates in your input. That means a point must read "POINT (103.926589 1.32918)" for latitude 1.32918 and longitude 103.926589. ~Then it should work out.~ Then, there must be another issue with the JSON format. The log message says, it's not valid JSON. I tried with the input shown below and received the respective output:

[
  {"id":"1", "time":1478473108000, "point":"POINT (103.926589 1.32918)"},
  {"id":"2", "time":1478473119000, "point":"POINT (103.925728 1.329221)"},
  {"id":"3", "time":1478473130000, "point":"POINT (103.924459 1.329668)"},
  {"id":"4", "time":1478473139000, "point":"POINT (103.924051 1.32956)"},
  {"id":"5", "time":1478473150000, "point":"POINT (103.922148 1.329864)"}
]

{"coordinates":[[[103.92648814303926,1.329166141921034],[103.9264802,1.3292247],[103.92647020000001,1.32931],[103.92638190000001,1.3293943],[103.9263149,1.3294211],[103.9262639,1.3294265],[103.9261244,1.3294461],[103.9260608,1.3294185],[103.92574060000001,1.3293322],[103.9257077762015,1.3293257825909168]],[[103.9257077762015,1.3293257825909168],[103.925402,1.329266],[103.9246788,1.3292275],[103.9245934,1.3292266],[103.92442349260621,1.3292409089589028]],[[103.92442349260621,1.3292409089589028],[103.92402724586837,1.3292742793160395]],[[103.92402724586837,1.3292742793160395],[103.9238382,1.3292902],[103.9233195,1.3294236],[103.92286510000001,1.3296081],[103.9222000293965,1.3299628170223883]]],"type":"MultiLineString"}

(By the way, I would increase the radius back to 200 and the max distance to at least 1000 meters.)

[adlersantos]

Oh I see, I didn't know that I need to swap the latitude and longitude in the input format.

I'm still strangely getting the timeout after swapping and changing the radius and max distance to your suggestions. :( But good to know that it works on your end with the same JSON file I have. I probably did something differently during the setup, and I need to double check my JSON input/s.

Just in case, I'm skipping the tests when I'm building the jar file ($ mvn package -DskipTests) since the tests were failing, because I don't have the test server setup (?). Is this okay? Everything else I followed as the documentation says.

I'll try to run through all the setup steps again and see if the issue goes away. Thank you!

[smattheis]

Can you please provide the command that you use to submit the request? Did you modify the MatcherServer code? (I'm asking this because your exception is thrown in line 76 where there is nothing that could throw an exception.)

[adlersantos]

Sure! For the one using the python script giving the timeout:

$ python util/submit/batch.py --host localhost --port 1234  --file sample/sample.json

For the curl command that gives the String cannot be cast to org.json.JSONArray error:

$ curl -X POST -H "Content-Type: application/json" -d '[{"id":"x001","time":1478473108000,"point":"POINT (1.32918 103.926589)"}]' localhost:1234

[smattheis]

The server doesn't provide a REST API. Therefore, the curl command won't work. To make sure your setup works, please follow the setup instructions (quick start) and check if you can successfully submit the provided example.

[lusccc]

I ran this command in my terminal and it worked: cat src/test/resources/com/bmwcarit/barefoot/matcher/x0001-015.json |netcat localhost 1234

[smattheis]

Seems to be resolved. Closing this issue for now.