Persistent TCP Publisher Sync Issue
-
Good Evening Everyone,
I am having a bit of difficulty getting the Mango Persistent TCP Publisher and Datasource to sync properly.
The local data source has 288 entries for March 1, however the Persistent TCP Datasource only shows the following:
50 Mar 01 22:00 53 Mar 01 21:55 49 Mar 01 17:10 57 Mar 01 17:05 49 Mar 01 12:20 48 Mar 01 12:15 47 Mar 01 07:30 52 Mar 01 07:25 56 Mar 01 02:45 58 Mar 01 02:40
The cron statement for the Publisher is set like so:
* 0/5 * * * ?
I have tried several settings in the 'Synchronize history prior to' with no improvement.
Any ideas?
Thanks!
-
What is your Sync prior to set to? Try setting it to 5 minutes. You should also see a log in the log file when the sync completes, what does that say? Are you running the latest version?
-
It is currently set to 5 min.
I enabled the debug log and it shows a pattern similar to this:
.m2m2.persistent.pub.SyncHandler$PointSync.run:277) - Points completed: 420 INFO 2017-03-03 07:10:22,130 (com.serotonin.m2m2.persistent.pub.SyncHandler$PointSync.run:248) - Points left: 48 INFO 2017-03-03 07:10:22,130 (com.serotonin.m2m2.persistent.pub.SyncHandler$PointSync.checkPoint:306) - PointSync[4](OZ2_RM16_SETPOINT) starting from saved time at 1488553259001 DEBUG 2017-03-03 07:10:22,130 (com.serotonin.m2m2.persistent.pub.SyncHandler.sendRequest:178) - PointSync[4](OZ2_RM16_SETPOINT) Sending request with id: 42 DEBUG 2017-03-03 07:10:22,130 (com.serotonin.m2m2.persistent.pub.SyncHandler$PointSync.checkRangeImpl:406) - PointSync[4](OZ2_RM16_SETPOINT/0.0/42) locally counted 0 rows in 0ms, from=1488553259001, to=1488553500002 DEBUG 2017-03-03 07:10:22,130 (com.serotonin.m2m2.persistent.pub.SyncHandler$PointSync.checkRangeImpl:420) - PointSync[4](OZ2_RM16_SETPOINT/0.0/42) didn't recieve response in time. Forced to wait up to 1200000ms DEBUG 2017-03-03 07:10:22,687 (com.serotonin.m2m2.persistent.pub.SyncHandler$PointSync.responseReceived:532) - PointSync[6](OZ2_RM5_HIGHFLOW) Received response with id: 42 DEBUG 2017-03-03 07:10:22,687 (com.serotonin.m2m2.persistent.pub.PersistentSendThread.sendRealTime:452) - Sending datapoint with index: 102 DEBUG 2017-03-03 07:10:22,687 (com.serotonin.m2m2.persistent.pub.PersistentSendThread.sendRealTime:452) - Sending datapoint with index: 205 DEBUG 2017-03-03 07:10:22,687 (com.serotonin.m2m2.persistent.pub.PersistentSendThread.sendRealTime:452) - Sending datapoint with index: 232
A large number of Sending data point with index x, and on occasion the forced to wait.
This particular client is running 2.7.10. I cannot update this particular unit without a lot of pain.
-
Not sure, you might need to call in for some hands on assistance. You could try increasing the time out.
-
Also collect logs from the receiver
-
Here is a sample from the receiving side:
DEBUG 2017-03-07 14:58:11,107 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler.runImpl:546) - /<IP Address>:<port>: ensuring point LGCY_OZ2_PB2_PDM, index: 468 DEBUG 2017-03-07 14:58:11,107 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler.ensurePointV5:788) - /<IP Address>:<port>: ensuring point LGCY_OZ2_PB2_PDM DEBUG 2017-03-07 14:58:11,107 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler.ensurePointV5:796) - /<IP Address>:<port>: point LGCY_OZ2_PB2_PDM already exists in RT list DEBUG 2017-03-07 14:58:11,107 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler.updatePointV5:853) - /<IP Address>:<port>: saving point LGCY_OZ2_PB2_PDM updates DEBUG 2017-03-07 14:58:11,108 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler.runImpl:556) - /<IP Address>:<port>: confirmed LGCY_OZ2_PB2_PDM with client INFO 2017-03-07 14:58:11,108 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler.runImpl:565) - /<IP Address>:<port>: point init done DEBUG 2017-03-07 14:58:11,505 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler.updatePointHierarchy:927) - /<IP Address>:<port>: updatePointHierarchy DEBUG 2017-03-07 14:58:11,513 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler.updatePointHierarchy:934) - /<IP Address>:<port>: updatePointHierarchy: count=468 DEBUG 2017-03-07 14:58:11,523 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler.updatePointHierarchy:990) - /<IP Address>:<port>: updatePointHierarchy: done DEBUG 2017-03-07 14:58:42,618 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler.runImpl:670) - /<IP Address>:<port>: Received test packet DEBUG 2017-03-07 14:59:42,594 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler.runImpl:670) - /<IP Address>:<port>: Received test packet DEBUG 2017-03-07 15:00:22,831 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.runImpl:1060) - /<IP Address>:<port>: Processing range count request: id=0 from task: 0, pointId=1801, xid=LGCY_OZ1_RM12_OFF, from=1488916230001, to=1488916500000 DEBUG 2017-03-07 15:00:22,831 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.run:1030) - /<IP Address>:<port>: Finished range count request 0 from task: 0 DEBUG 2017-03-07 15:00:22,831 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.runImpl:1060) - /<IP Address>:<port>: Processing range count request: id=0 from task: 2, pointId=1893, xid=LGCY_OZ2_RM13_CONC, from=1488916230001, to=1488916500000 DEBUG 2017-03-07 15:00:22,831 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.runImpl:1060) - /<IP Address>:<port>: Processing range count request: id=0 from task: 1, pointId=1847, xid=LGCY_OZ3_PB_PDM, from=1488916230001, to=1488916500000 DEBUG 2017-03-07 15:00:22,832 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.run:1030) - /<IP Address>:<port>: Finished range count request 0 from task: 1 DEBUG 2017-03-07 15:00:22,835 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.run:1030) - /<IP Address>:<port>: Finished range count request 0 from task: 2 DEBUG 2017-03-07 15:00:22,835 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.runImpl:1060) - /<IP Address>:<port>: Processing range count request: id=0 from task: 5, pointId=2031, xid=LGCY_OZ1_RM5_DUTY, from=1488916230001, to=1488916500000 DEBUG 2017-03-07 15:00:22,835 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.run:1030) - /<IP Address>:<port>: Finished range count request 0 from task: 5 DEBUG 2017-03-07 15:00:22,836 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.runImpl:1060) - /<IP Address>:<port>: Processing range count request: id=0 from task: 7, pointId=2123, xid=LGCY_OZ3_RM8_INTR, from=1488916230001, to=1488916500000 DEBUG 2017-03-07 15:00:22,836 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.runImpl:1060) - /<IP Address>:<port>: Processing range count request: id=0 from task: 9, pointId=2575, xid=LGCY_OZ2_PB2_PDM, from=1488916230001, to=1488916500000 DEBUG 2017-03-07 15:00:22,836 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.run:1030) - /<IP Address>:<port>: Finished range count request 0 from task: 7 DEBUG 2017-03-07 15:00:22,836 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.run:1030) - /<IP Address>:<port>: Finished range count request 0 from task: 9 DEBUG 2017-03-07 15:00:22,836 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.runImpl:1060) - /<IP Address>:<port>: Processing range count request: id=0 from task: 4, pointId=1985, xid=LGCY_OZ3_RM3_INSTALLED, from=1488916230001, to=1488916500000 DEBUG 2017-03-07 15:00:22,836 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.run:1030) - /<IP Address>:<port>: Finished range count request 0 from task: 4 DEBUG 2017-03-07 15:00:22,837 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.runImpl:1060) - /<IP Address>:<port>: Processing range count request: id=0 from task: 6, pointId=2077, xid=LGCY_OZ2_RM6_SETPOINT, from=1488916230001, to=1488916500000 DEBUG 2017-03-07 15:00:22,837 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.runImpl:1060) - /<IP Address>:<port>: Processing range count request: id=0 from task: 8, pointId=2169, xid=LGCY_OZ1_TD2_REFLAMP, from=1488916230001, to=1488916500000 DEBUG 2017-03-07 15:00:22,837 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.run:1030) - /<IP Address>:<port>: Finished range count request 0 from task: 6 DEBUG 2017-03-07 15:00:22,837 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.runImpl:1060) - /<IP Address>:<port>: Processing range count request: id=0 from task: 3, pointId=1939, xid=LGCY_OZ2_RM16_OFF, from=1488916230001, to=1488916500000 DEBUG 2017-03-07 15:00:22,837 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.run:1030) - /<IP Address>:<port>: Finished range count request 0 from task: 8 DEBUG 2017-03-07 15:00:22,837 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.run:1030) - /<IP Address>:<port>: Finished range count request 0 from task: 3 DEBUG 2017-03-07 15:00:23,390 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.runImpl:1060) - /<IP Address>:<port>: Processing range count request: id=1 from task: 9, pointId=2574, xid=LGCY_OZ1_PB2_PDM, from=1488916230001, to=1488916500000 DEBUG 2017-03-07 15:00:23,390 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.runImpl:1060) - /<IP Address>:<port>: Processing range count request: id=1 from task: 5, pointId=2030, xid=LGCY_OZ3_RM5_CONC, from=1488916230001, to=1488916500000 DEBUG 2017-03-07 15:00:23,390 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.runImpl:1060) - /<IP Address>:<port>: Processing range count request: id=1 from task: 2, pointId=1892, xid=LGCY_OZ2_RM13_ABOVESP, from=1488916230001, to=1488916500000 DEBUG 2017-03-07 15:00:23,390 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.runImpl:1060) - /<IP Address>:<port>: Processing range count request: id=1 from task: 7, pointId=2122, xid=LGCY_OZ2_RM8_INTR, from=1488916230001, to=1488916500000 DEBUG 2017-03-07 15:00:23,390 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.run:1030) - /<IP Address>:<port>: Finished range count request 1 from task: 9 DEBUG 2017-03-07 15:00:23,390 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.run:1030) - /<IP Address>:<port>: Finished range count request 1 from task: 7 DEBUG 2017-03-07 15:00:23,390 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.runImpl:1060) - /<IP Address>:<port>: Processing range count request: id=1 from task: 1, pointId=1846, xid=LGCY_OZ2_PB_PDM, from=1488916230001, to=1488916500000 DEBUG 2017-03-07 15:00:23,390 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.run:1030) - /<IP Address>:<port>: Finished range count request 1 from task: 2 DEBUG 2017-03-07 15:00:23,390 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.run:1030) - /<IP Address>:<port>: Finished range count request 1 from task: 5 DEBUG 2017-03-07 15:00:23,390 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.run:1030) - /<IP Address>:<port>: Finished range count request 1 from task: 1 DEBUG 2017-03-07 15:00:23,390 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.runImpl:1060) - /<IP Address>:<port>: Processing range count request: id=1 from task: 0, pointId=1800, xid=LGCY_OZ1_RM12_INTR, from=1488916230001, to=1488916500000 DEBUG 2017-03-07 15:00:23,391 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.run:1030) - /<IP Address>:<port>: Finished range count request 1 from task: 0 DEBUG 2017-03-07 15:00:23,391 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.runImpl:1060) - /<IP Address>:<port>: Processing range count request: id=1 from task: 6, pointId=2076, xid=LGCY_OZ1_RM6_SETPOINT, from=1488916230001, to=1488916500000 DEBUG 2017-03-07 15:00:23,391 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.runImpl:1060) - /<IP Address>:<port>: Processing range count request: id=1 from task: 3, pointId=1938, xid=LGCY_OZ1_RM16_OFF, from=1488916230001, to=1488916500000 DEBUG 2017-03-07 15:00:23,391 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.runImpl:1060) - /<IP Address>:<port>: Processing range count request: id=1 from task: 8, pointId=2168, xid=LGCY_OZ3_TD2_COMOK, from=1488916230001, to=1488916500000 DEBUG 2017-03-07 15:00:23,391 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.run:1030) - /<IP Address>:<port>: Finished range count request 1 from task: 6 DEBUG 2017-03-07 15:00:23,391 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.run:1030) - /<IP Address>:<port>: Finished range count request 1 from task: 8 DEBUG 2017-03-07 15:00:23,391 (com.serotonin.m2m2.persistent.ds.PersistentDataSourceRT$TcpConnectionHandler$RangeCountHandler.run:1030) - /<IP Address>:<port>: Finished range count request 1 from task: 3
No failures to note as of yet. I'll stretch the timeouts and see if that helps.
-
So I bit the bullet and updated the install to 2.8.6.
As of now, the system is syncing every 5 minutes without issue.
-
If you export your publisher, do you see "dataPointId":null in the output?
-
The updated system exports with no errors. I'll try a different system on 2.7.1 and see what it does.
-
It would export without errors, but one of the items in the list of points would be the text: "dataPointId":null
I was just curious if that was related to the issue. Glad you got it working!