Web socket connection error

Vladimir Dimitrow6 years ago

Hello,

I read all themes about this notification, but cant find a solution. I migrate my existing server on new pc (same windows version, same ISP, different hardware configuration). Now, I get this notification on every minute. I ran a test on http://websocketstest.com - everything seems to be fine.

alt text
alt text

2018-07-31 22:09:07  WARN: Geocoding failed - Empty address - GeocoderException (JsonGeocoder:69 < *:34 < *:96 < ...)
2018-07-31 22:09:07  INFO: [56559096] id: 865205033094383, time: 2018-07-31 22:09:09, lat: 43.21578, lon: 23.55458, course: 23.0
2018-07-31 22:09:07  WARN: Empty address
2018-07-31 22:09:17 DEBUG: [56559096: 5023 < 212.39.89.168] HEX: 78781f1212071f160913ca04a2f4f10286f220003417011c03086600f4b104e177bf0d0a
2018-07-31 22:09:17 DEBUG: [56559096: 5023 > 212.39.89.168] HEX: 7878051204e133430d0a
2018-07-31 22:09:17 DEBUG: [73F4DA79: 5023 < 212.39.89.52] HEX: 78781f1212071f160913ca04a2798a0287256000340f011c03086600f431020a23ea0d0a
2018-07-31 22:09:17 DEBUG: [73F4DA79: 5023 > 212.39.89.52] HEX: 78780512020a3e4e0d0a
2018-07-31 22:09:17  WARN: Geocoding failed - Empty address - GeocoderException (JsonGeocoder:69 < *:34 < *:96 < ...)
2018-07-31 22:09:17  INFO: [56559096] id: 865205033094383, time: 2018-07-31 22:09:19, lat: 43.21578, lon: 23.55458, course: 23.0
2018-07-31 22:09:17  WARN: Empty address
2018-07-31 22:09:17  WARN: Incorrect string value: '\xD0\x90 ul....' for column 'address' at row 1 - SQLException (... < QueryBuilder:477 < DataManager:452 < DefaultDataHandler:27 < ...)
2018-07-31 22:09:17  INFO: [73F4DA79] id: 355488020808147, time: 2018-07-31 22:09:19, lat: 43.19823, lon: 23.56187, course: 15.0
2018-07-31 22:09:27 DEBUG: [56559096: 5023 < 212.39.89.168] HEX: 78781f1212071f16091dca04a2f4f10286f220003417011c03086600f4b104e207ad0d0a
2018-07-31 22:09:27 DEBUG: [56559096: 5023 > 212.39.89.168] HEX: 7878051204e201d80d0a
2018-07-31 22:09:27  INFO: [56559096] id: 865205033094383, time: 2018-07-31 22:09:29, lat: 43.21578, lon: 23.55458, course: 23.0
WARNING|wrapper|Service traccar|18-07-31 20:36:11|YAJSW: yajsw-stable-12.12
WARNING|wrapper|Service traccar|18-07-31 20:36:11|OS   : Windows 7/6.1/amd64
WARNING|wrapper|Service traccar|18-07-31 20:36:11|JVM  : Oracle Corporation/1.8.0_181/C:\Program Files\Java\jre1.8.0_181/64
INFO|wrapper|Service traccar|18-07-31 20:36:11|start delay: 0
INFO|wrapper|Service traccar|18-07-31 20:36:11|started process with pid 3288
INFO|3288/0|Service traccar|18-07-31 20:36:20|[INFO] StandardFileSystemManager - Using "C:\Windows\TEMP\vfs_cache" as temporary files store.
INFO|3288/0|Service traccar|18-07-31 20:36:20|SLF4J: Class path contains multiple SLF4J bindings.
INFO|3288/0|Service traccar|18-07-31 20:36:20|SLF4J: Found binding in [jar:file:/D:/Program%20Files/Traccar/lib/slf4j-simple-1.7.25.jar!/org/slf4j/impl/StaticLoggerBinder.class]
INFO|3288/0|Service traccar|18-07-31 20:36:20|SLF4J: Found binding in [jar:file:/D:/Program%20Files/Traccar/lib/logback-classic-1.2.3.jar!/org/slf4j/impl/StaticLoggerBinder.class]
INFO|3288/0|Service traccar|18-07-31 20:36:20|SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
INFO|3288/0|Service traccar|18-07-31 20:36:21|SLF4J: Actual binding is of type [org.slf4j.impl.SimpleLoggerFactory]
INFO|3288/0|Service traccar|18-07-31 20:36:23|[main] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Starting...
INFO|3288/0|Service traccar|18-07-31 20:36:24|[main] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Start completed.
INFO|3288/0|Service traccar|18-07-31 20:36:25|[main] INFO liquibase.Liquibase - Clearing database change log checksums
INFO|3288/0|Service traccar|18-07-31 20:36:25|[main] INFO liquibase.executor.jvm.JdbcExecutor - SELECT COUNT(*) FROM traccar.DATABASECHANGELOGLOCK
INFO|3288/0|Service traccar|18-07-31 20:36:25|[main] INFO liquibase.executor.jvm.JdbcExecutor - SELECT COUNT(*) FROM traccar.DATABASECHANGELOGLOCK
INFO|3288/0|Service traccar|18-07-31 20:36:25|[main] INFO liquibase.executor.jvm.JdbcExecutor - SELECT LOCKED FROM traccar.DATABASECHANGELOGLOCK WHERE ID=1
INFO|3288/0|Service traccar|18-07-31 20:36:25|[main] INFO liquibase.lockservice.StandardLockService - Successfully acquired change log lock
INFO|3288/0|Service traccar|18-07-31 20:36:26|[main] INFO liquibase.executor.jvm.JdbcExecutor - SELECT MD5SUM FROM traccar.DATABASECHANGELOG WHERE MD5SUM IS NOT NULL LIMIT 1
INFO|3288/0|Service traccar|18-07-31 20:36:26|[main] INFO liquibase.executor.jvm.JdbcExecutor - UPDATE traccar.DATABASECHANGELOG SET MD5SUM = NULL
INFO|3288/0|Service traccar|18-07-31 20:36:26|[main] INFO liquibase.lockservice.StandardLockService - Successfully released change log lock
INFO|3288/0|Service traccar|18-07-31 20:36:26|[main] INFO liquibase.executor.jvm.JdbcExecutor - SELECT COUNT(*) FROM traccar.DATABASECHANGELOGLOCK
INFO|3288/0|Service traccar|18-07-31 20:36:26|[main] INFO liquibase.executor.jvm.JdbcExecutor - SELECT COUNT(*) FROM traccar.DATABASECHANGELOGLOCK
INFO|3288/0|Service traccar|18-07-31 20:36:26|[main] INFO liquibase.executor.jvm.JdbcExecutor - SELECT LOCKED FROM traccar.DATABASECHANGELOGLOCK WHERE ID=1
INFO|3288/0|Service traccar|18-07-31 20:36:26|[main] INFO liquibase.lockservice.StandardLockService - Successfully acquired change log lock
INFO|3288/0|Service traccar|18-07-31 20:36:28|[main] INFO liquibase.executor.jvm.JdbcExecutor - SELECT MD5SUM FROM traccar.DATABASECHANGELOG WHERE MD5SUM IS NOT NULL LIMIT 1
INFO|3288/0|Service traccar|18-07-31 20:36:28|[main] INFO liquibase.executor.jvm.JdbcExecutor - SELECT COUNT(*) FROM traccar.DATABASECHANGELOG
INFO|3288/0|Service traccar|18-07-31 20:36:28|[main] INFO liquibase.changelog.StandardChangeLogHistoryService - Reading from traccar.DATABASECHANGELOG
INFO|3288/0|Service traccar|18-07-31 20:36:28|[main] INFO liquibase.executor.jvm.JdbcExecutor - SELECT * FROM traccar.DATABASECHANGELOG ORDER BY DATEEXECUTED ASC, ORDEREXECUTED ASC
INFO|3288/0|Service traccar|18-07-31 20:36:28|[main] INFO liquibase.executor.jvm.JdbcExecutor - UPDATE traccar.DATABASECHANGELOG SET MD5SUM = '8:ea6f202534dc7845fd1a49e1d8384d9c' WHERE ID = 'changelog-3.3' AND AUTHOR = 'author' AND FILENAME = 'changelog-3.3'
INFO|3288/0|Service traccar|18-07-31 20:36:28|[main] INFO liquibase.executor.jvm.JdbcExecutor - UPDATE traccar.DATABASECHANGELOG SET MD5SUM = '8:194e3ae7ec6d201917136e04a26e237b' WHERE ID = 'changelog-3.5' AND AUTHOR = 'author' AND FILENAME = 'changelog-3.5'
INFO|3288/0|Service traccar|18-07-31 20:36:28|[main] INFO liquibase.executor.jvm.JdbcExecutor - UPDATE traccar.DATABASECHANGELOG SET MD5SUM = '8:1ec7941b03749f24e365bc6126b07e1a' WHERE ID = 'changelog-3.6' AND AUTHOR = 'author' AND FILENAME = 'changelog-3.6'
INFO|3288/0|Service traccar|18-07-31 20:36:28|[main] INFO liquibase.executor.jvm.JdbcExecutor - UPDATE traccar.DATABASECHANGELOG SET MD5SUM = '8:2e444e379f31d0b8e09273ec7ffe87a0' WHERE ID = 'changelog-3.7' AND AUTHOR = 'author' AND FILENAME = 'changelog-3.7'
INFO|3288/0|Service traccar|18-07-31 20:36:28|[main] INFO liquibase.executor.jvm.JdbcExecutor - UPDATE traccar.DATABASECHANGELOG SET MD5SUM = '8:974c33d2fb399ef6477c3897450fb078' WHERE ID = 'changelog-3.7-notmssql' AND AUTHOR = 'author' AND FILENAME = 'changelog-3.7'
INFO|3288/0|Service traccar|18-07-31 20:36:28|[main] INFO liquibase.executor.jvm.JdbcExecutor - UPDATE traccar.DATABASECHANGELOG SET MD5SUM = '8:74d68027951f8d2ae6bb2e24df8365bc' WHERE ID = 'changelog-3.8' AND AUTHOR = 'author' AND FILENAME = 'changelog-3.8'
INFO|3288/0|Service traccar|18-07-31 20:36:28|[main] INFO liquibase.executor.jvm.JdbcExecutor - UPDATE traccar.DATABASECHANGELOG SET MD5SUM = '8:34822842d65deb843a7d16f857d52ecc' WHERE ID = 'changelog-3.9' AND AUTHOR = 'author' AND FILENAME = 'changelog-3.9'
INFO|3288/0|Service traccar|18-07-31 20:36:28|[main] INFO liquibase.executor.jvm.JdbcExecutor - UPDATE traccar.DATABASECHANGELOG SET MD5SUM = '8:e1ddbe83e1ecf856a912755fc118f82e' WHERE ID = 'changelog-3.10' AND AUTHOR = 'author' AND FILENAME = 'changelog-3.10'
INFO|3288/0|Service traccar|18-07-31 20:36:28|[main] INFO liquibase.executor.jvm.JdbcExecutor - UPDATE traccar.DATABASECHANGELOG SET MD5SUM = '8:191c21d8f0f921845cf93bbc9d0639b9' WHERE ID = 'changelog-3.10-notmssql' AND AUTHOR = 'author' AND FILENAME = 'changelog-3.10'
INFO|3288/0|Service traccar|18-07-31 20:36:28|[main] INFO liquibase.executor.jvm.JdbcExecutor - UPDATE traccar.DATABASECHANGELOG SET MD5SUM = '8:ad1f63566e8d08812fbf0b93a118ef6e' WHERE ID = 'changelog-3.10-mssql' AND AUTHOR = 'author' AND FILENAME = 'changelog-3.10'
INFO|3288/0|Service traccar|18-07-31 20:36:28|[main] INFO liquibase.executor.jvm.JdbcExecutor - UPDATE traccar.DATABASECHANGELOG SET MD5SUM = '8:127b36b9d32a9d236df51d19b18c3766' WHERE ID = 'changelog-3.7-mssql' AND AUTHOR = 'author' AND FILENAME = 'changelog-3.10'
INFO|3288/0|Service traccar|18-07-31 20:36:28|[main] INFO liquibase.executor.jvm.JdbcExecutor - UPDATE traccar.DATABASECHANGELOG SET MD5SUM = '8:7800f890b9706a480bd5a79b591b6ca7' WHERE ID = 'changelog-3.11' AND AUTHOR = 'author' AND FILENAME = 'changelog-3.11'
INFO|3288/0|Service traccar|18-07-31 20:36:28|[main] INFO liquibase.executor.jvm.JdbcExecutor - UPDATE traccar.DATABASECHANGELOG SET MD5SUM = '8:5ce520811d626ad325a014b9fcbb1a13' WHERE ID = 'changelog-3.12' AND AUTHOR = 'author' AND FILENAME = 'changelog-3.12'
INFO|3288/0|Service traccar|18-07-31 20:36:28|[main] INFO liquibase.executor.jvm.JdbcExecutor - UPDATE traccar.DATABASECHANGELOG SET MD5SUM = '8:a3bf7fabcde29e106fe2f89829a76a84' WHERE ID = 'changelog-3.12-notmssql' AND AUTHOR = 'author' AND FILENAME = 'changelog-3.12'
INFO|3288/0|Service traccar|18-07-31 20:36:28|[main] INFO liquibase.executor.jvm.JdbcExecutor - UPDATE traccar.DATABASECHANGELOG SET MD5SUM = '8:cfc881bd2dadb561aa9c1a467bc8cc1c' WHERE ID = 'changelog-3.12-pgsql' AND AUTHOR = 'author' AND FILENAME = 'changelog-3.12'
INFO|3288/0|Service traccar|18-07-31 20:36:28|[main] INFO liquibase.executor.jvm.JdbcExecutor - UPDATE traccar.DATABASECHANGELOG SET MD5SUM = '8:1be7e6c0520f8be53ef1b099d96afba5' WHERE ID = 'changelog-3.14' AND AUTHOR = 'author' AND FILENAME = 'changelog-3.14'
INFO|3288/0|Service traccar|18-07-31 20:36:28|[main] INFO liquibase.executor.jvm.JdbcExecutor - UPDATE traccar.DATABASECHANGELOG SET MD5SUM = '8:ac8ccec176027e98bbf45dc6c15d9b05' WHERE ID = 'changelog-3.15' AND AUTHOR = 'author' AND FILENAME = 'changelog-3.15'
INFO|3288/0|Service traccar|18-07-31 20:36:28|[main] INFO liquibase.executor.jvm.JdbcExecutor - UPDATE traccar.DATABASECHANGELOG SET MD5SUM = '8:b59407d70bfe9bf57bc9968adfbbdf1c' WHERE ID = 'changelog-3.16' AND AUTHOR = 'author' AND FILENAME = 'changelog-3.16'
INFO|3288/0|Service traccar|18-07-31 20:36:28|[main] INFO liquibase.executor.jvm.JdbcExecutor - UPDATE traccar.DATABASECHANGELOG SET MD5SUM = '8:3f14c3b08068eb7628d0d3e2941eb2d3' WHERE ID = 'changelog-3.3-admin' AND AUTHOR = 'author' AND FILENAME = 'changelog-3.17'
INFO|3288/0|Service traccar|18-07-31 20:36:28|[main] INFO liquibase.executor.jvm.JdbcExecutor - UPDATE traccar.DATABASECHANGELOG SET MD5SUM = '8:8aa3e56afe6ba86cd004fa801507bc28' WHERE ID = 'changelog-3.17' AND AUTHOR = 'author' AND FILENAME = 'changelog-3.17'
INFO|3288/0|Service traccar|18-07-31 20:36:28|[main] INFO liquibase.executor.jvm.JdbcExecutor - SELECT COUNT(*) FROM traccar.DATABASECHANGELOG
INFO|3288/0|Service traccar|18-07-31 20:36:28|[main] INFO liquibase.changelog.StandardChangeLogHistoryService - Reading from traccar.DATABASECHANGELOG
INFO|3288/0|Service traccar|18-07-31 20:36:28|[main] INFO liquibase.executor.jvm.JdbcExecutor - SELECT * FROM traccar.DATABASECHANGELOG ORDER BY DATEEXECUTED ASC, ORDEREXECUTED ASC
INFO|3288/0|Service traccar|18-07-31 20:36:28|[main] INFO liquibase.lockservice.StandardLockService - Successfully released change log lock
INFO|3288/0|Service traccar|18-07-31 20:36:29|[main] INFO org.eclipse.jetty.util.log - Logging initialized @17388ms
INFO|3288/0|Service traccar|18-07-31 20:36:32|[main] INFO org.eclipse.jetty.server.Server - jetty-9.2.24.v20180105
INFO|3288/0|Service traccar|18-07-31 20:36:33|[main] INFO org.eclipse.jetty.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@4b862408{/api,null,AVAILABLE}
INFO|3288/0|Service traccar|18-07-31 20:36:33|[main] INFO org.eclipse.jetty.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@25ffd826{/console,null,AVAILABLE}
INFO|3288/0|Service traccar|18-07-31 20:36:33|[main] INFO org.eclipse.jetty.server.handler.ContextHandler - Started o.t.w.@75aea2ba{/,null,AVAILABLE}
INFO|3288/0|Service traccar|18-07-31 20:36:33|[main] INFO org.eclipse.jetty.server.ServerConnector - Started ServerConnector@5ff6dd3c{HTTP/1.1}{0.0.0.0:80}
INFO|3288/0|Service traccar|18-07-31 20:36:33|[main] INFO org.eclipse.jetty.server.Server - Started @21874ms

Anny suggestion ?

Anton Tananaev6 years ago

Have you checked browser console?

Vladimir Dimitrow6 years ago

Thanks for the reply,

What I need to check in the console?

Thanks in advance.

Vladimir Dimitrow6 years ago

If im not mistake, you asked for this check in console:

GET - http://gps.asc-bg.com/api/socket
Host: gps.asc-bg.com
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:62.0) Gecko/20100101 Firefox/62.0
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Accept-Language: bg,en-US;q=0.7,en;q=0.3
Accept-Encoding: gzip, deflate
Sec-WebSocket-Version: 13
Origin: http://gps.asc-bg.com
Sec-WebSocket-Extensions: permessage-deflate
Sec-WebSocket-Key: xZvD95NVFcvJJHTLXU76HQ==
Cookie: JSESSIONID=e9bmqhe52c5hwbgt4xxn0da2; ext-devices-grid=o%3Acolumns%3Da%253Ao%25253Aid%25253Ds%2525253Ah1%255Eo%25253Aid%25253Ds%2525253Ah2%255Eo%25253Aid%25253Ds%2525253Ah3%255Eo%25253Aid%25253Ds%2525253Ah4%255Eo%25253Aid%25253Ds%2525253Ah5%255Eo%25253Aid%25253Ds%2525253Ah6%255Eo%25253Aid%25253Ds%2525253Ah7%255Eo%25253Aid%25253Ds%2525253Ah8%255Eo%25253Aid%25253Ds%2525253Ah9%255Eo%25253Aid%25253Ds%2525253Ah10%5Eweight%3Dn%253A0; ext-state-grid=o%3Acolumns%3Da%253Ao%25253Aid%25253Ds%2525253Ah1%255Eo%25253Aid%25253Ds%2525253Ah2%5EstoreState%3Do%253Asorters%253Da%25253Ao%2525253Aroot%2525253Ds%252525253Adata%2525255Eproperty%2525253Ds%252525253Apriority%2525255Edirection%2525253Ds%252525253AASC%2525255Eid%2525253Ds%252525253Apriority%5Eweight%3Dn%253A10; ext-devices-and-state-panel=o%3Aweight%3Dn%253A-10; ext-show-geofences-button=o%3Apressed%3Db%253A1; ext-show-live-routes-button=o%3Apressed%3Db%253A0; ext-device-follow-button=o%3Apressed%3Db%253A1; ext-events-scroll-to-last-button=o%3Apressed%3Db%253A1; ext-sound-button=o%3Apressed%3Db%253A0; ext-events-grid=o%3Acollapsed%3Do%253A%5Ecolumns%3Da%253Ao%25253Aid%25253Ds%2525253Ah1%255Eo%25253Aid%25253Ds%2525253Ah2%255Eo%25253Aid%25253Ds%2525253Ah3%5Eweight%3Dn%253A-20
Connection: keep-alive, Upgrade
Pragma: no-cache
Cache-Control: no-cache
Upgrade: websocket

websocket_inspect

Vladimir Dimitrow6 years ago

Here is console result from Chrome (WS Frames)

chrome_ws

Anton Tananaev6 years ago

It looks like everything is working correctly. Not sure why you get the error. Maybe your devices report less than once a minute?

Vladimir Dimitrow6 years ago

No, the device is send data every 10 sec. There is no problem, when I attach this device on other server, and no problem with my old server (the difference between the old and the new one is only in the hardware and in that the new one works with the mysql database while the old one with the H2)

This is screenshot from other server. Here is one socket connection and all data is on it, unlike in the present server with error - there socket connection is on every minute.

iv

Vladimir Dimitrow6 years ago

I find my problem.
I had set a parameter web.timeout of 10 in the configuration file. Аfter I removed this parameter, the problem disappeared.

I see in the log file the constant appearance of the following message. How can I handle it?

Geocoding failed - Empty address - GeocoderException (JsonGeocoder:69 < *:34 < *:96 < ...)
Anton Tananaev6 years ago

Disable reverse geocoding or configure it correctly.