Bug #835
Wrong timing when replaying
| Status: | Rejected | Start date: | 02/01/2012 | |
|---|---|---|---|---|
| Priority: | High | Due date: | ||
| Assignee: | J. Moringen | % Done: | 0% | |
| Category: | - | |||
| Target version: | - |
Description
I recorded RSB communication on 9 different channels with 200Hz events each.
Replaying seems to replay the same data, but with timing completely off. RSB Scope Monitor showed 200Hz on each channel during recording, Monitor during replaying shows changing between 0Hz and ~400-500Hz.
Don`t know if recording or replaying went wrong. Tested with bag-record and bag-play trunk, as downloaded from toolkit. (file attaching doesn`t seem to work)
History
#1 Updated by J. Moringen about 12 years ago
- Status changed from New to In Progress
- Assignee set to J. Moringen
I cannot properly reproduce the problem with trunk versions of bag-cat and logger using either the Spread transport or the TCP-based transport. Both transports show some jitter but not to the extend you describe (see logger output below). I could not observe extreme scope-specific jitter in C++ logger's monitor mode either.
- I used the C++ and CL loggers simultaneously - this may have increased load and thus potentially jitter (especially for the TCP-based transport)
- Spread seems to be worse in this regard
- Is it possible, that some informers start at ~ 10 seconds into the recording? The rate seems to go up from 1400 Hz to 1800 Hz at that point
TCP example
Now |Rate |Throughput |Latency 2012-02-01T12:54:48.257888+01:00| N/A| 0.000| N/A ± N/A 2012-02-01T12:54:49.257648+01:00| 892.187| 5352.830|…387.760 ± 0.017 2012-02-01T12:54:50.257624+01:00| 1400.025| 8399.866|…387.749 ± 0.004 2012-02-01T12:54:51.258099+01:00| 1400.347| 8401.766|…387.759 ± 0.013 2012-02-01T12:54:52.265621+01:00| 1382.645| 8295.650|…387.752 ± 0.012 2012-02-01T12:54:53.257849+01:00| 1418.099| 8508.545|…387.748 ± 0.002 2012-02-01T12:54:54.258371+01:00| 1400.304| 8401.656|…387.749 ± 0.002 2012-02-01T12:54:55.257696+01:00| 1399.977| 8399.880|…387.748 ± 0.001 2012-02-01T12:54:56.258130+01:00| 1399.423| 8396.398|…387.751 ± 0.008 2012-02-01T12:54:57.257569+01:00| 1667.946| 10007.224|…387.748 ± 0.002 2012-02-01T12:54:58.258134+01:00| 1801.047| 10806.186|…387.749 ± 0.003 2012-02-01T12:54:59.257713+01:00| 1800.805| 10804.278|…387.754 ± 0.011 2012-02-01T12:55:00.257373+01:00| 1798.646| 10791.907|…387.749 ± 0.001 2012-02-01T12:55:01.258382+01:00| 1798.266| 10789.394|…387.750 ± 0.004 2012-02-01T12:55:02.258033+01:00| 1804.657| 10827.562|…387.749 ± 0.003 2012-02-01T12:55:03.257689+01:00| 1800.677| 10804.073|…387.752 ± 0.008 2012-02-01T12:55:04.258246+01:00| 1799.011| 10793.761|…387.752 ± 0.008 2012-02-01T12:55:05.258027+01:00| 1801.467| 10808.681|…387.750 ± 0.005 2012-02-01T12:55:06.257804+01:00| 1794.513| 10766.939|…387.751 ± 0.007 2012-02-01T12:55:07.258175+01:00| 1646.434| 9878.552|…387.798 ± 0.031 2012-02-01T12:55:08.257743+01:00| 1696.706| 10180.082|…387.867 ± 0.024 2012-02-01T12:55:09.258362+01:00| 1766.942| 10601.183|…387.885 ± 0.018 2012-02-01T12:55:10.257982+01:00| 2066.880| 12401.233|…387.845 ± 0.083 2012-02-01T12:55:11.257744+01:00| 1729.500| 10376.781|…387.780 ± 0.021 2012-02-01T12:55:12.258217+01:00| 1834.176| 11004.927|…387.770 ± 0.023 2012-02-01T12:55:13.257616+01:00| 1391.924| 8351.763|…387.923 ± 0.082 2012-02-01T12:55:14.258074+01:00| 2120.952| 12724.785|…387.955 ± 0.090 2012-02-01T12:55:15.257902+01:00| 1903.375| 11420.078|…387.784 ± 0.038 2012-02-01T12:55:16.257751+01:00| 1131.287| 6787.894|…387.970 ± 0.119 2012-02-01T12:55:17.257907+01:00| 1269.853| 7619.101|…388.348 ± 0.095 2012-02-01T12:55:18.258259+01:00| 2088.167| 12528.062|…388.420 ± 0.085 2012-02-01T12:55:19.261707+01:00| 1912.461| 11474.653|…388.244 ± 0.072 2012-02-01T12:55:20.268329+01:00| 2483.576| 14900.554|…388.103 ± 0.126 2012-02-01T12:55:21.258349+01:00| 1886.945| 11321.795|…387.805 ± 0.022 2012-02-01T12:55:22.258086+01:00| 1856.579| 11139.620|…387.861 ± 0.076 2012-02-01T12:55:23.257702+01:00| 1592.690| 9556.042|…387.824 ± 0.032 2012-02-01T12:55:24.258157+01:00| 1620.282| 9721.616|…387.932 ± 0.024 2012-02-01T12:55:25.274505+01:00| 1916.638| 11499.398|…387.986 ± 0.051 2012-02-01T12:55:26.258032+01:00| 1718.426| 10310.662|…387.949 ± 0.023 2012-02-01T12:55:27.257782+01:00| 1559.479| 9356.620|…388.042 ± 0.035 2012-02-01T12:55:28.258984+01:00| 2413.054| 14477.368|…388.021 ± 0.109 2012-02-01T12:55:29.257890+01:00| 1809.042| 10854.733|…387.749 ± 0.003 2012-02-01T12:55:30.257742+01:00| 1797.318| 10783.294|…387.750 ± 0.004 2012-02-01T12:55:31.258338+01:00| 1804.951| 10829.719|…387.749 ± 0.003 2012-02-01T12:55:32.257854+01:00| 1800.906| 10804.992|…387.752 ± 0.007 2012-02-01T12:55:33.258317+01:00| 1694.361| 10166.381|…387.749 ± 0.002 2012-02-01T12:55:34.257950+01:00| 739.333| 4436.218|…387.749 ± 0.003 2012-02-01T12:55:35.258008+01:00| N/A| 0.000| N/A ± N/A
Spread example
Now |Rate |Throughput |Latency 2012-02-01T12:56:53.268604+01:00| n/a| n/a|…508.905 ± 0.111 2012-02-01T12:56:54.267153+01:00| 1429.366| 8576.133|…508.759 ± 0.006 2012-02-01T12:56:55.267338+01:00| 1401.240| 8408.110|…508.759 ± 0.004 2012-02-01T12:56:56.267046+01:00| 1392.834| 8356.897|…508.758 ± 0.003 2012-02-01T12:56:57.266485+01:00| 1407.821| 8446.739|…508.760 ± 0.008 2012-02-01T12:56:58.267131+01:00| 1666.688| 9999.740|…508.767 ± 0.011 2012-02-01T12:56:59.267099+01:00| 1801.355| 10807.762|…508.760 ± 0.005 2012-02-01T12:57:00.266556+01:00| 1420.844| 8525.465|…508.818 ± 0.086 2012-02-01T12:57:01.266953+01:00| 1913.286| 11479.190|…508.924 ± 0.022 2012-02-01T12:57:02.266744+01:00| 2066.411| 12396.099|…508.806 ± 0.052 2012-02-01T12:57:03.266629+01:00| 1523.468| 9141.465|…508.799 ± 0.053 2012-02-01T12:57:04.267126+01:00| 1170.462| 7022.685|…509.067 ± 0.104 2012-02-01T12:57:05.266372+01:00| 1146.891| 6881.319|…509.409 ± 0.101 2012-02-01T12:57:06.266441+01:00| 1179.968| 7079.724|…509.788 ± 0.102 2012-02-01T12:57:07.266768+01:00| 1332.598| 7995.274|…510.090 ± 0.070 2012-02-01T12:57:08.267021+01:00| 1197.752| 7186.613|…510.379 ± 0.095 2012-02-01T12:57:09.267339+01:00| 1194.633| 7167.585|…510.723 ± 0.089 2012-02-01T12:57:10.266680+01:00| 1175.794| 7054.600|…511.045 ± 0.107 2012-02-01T12:57:11.266856+01:00| 1166.846| 7001.139|…511.413 ± 0.103 2012-02-01T12:57:12.267300+01:00| 1174.515| 7046.998|…511.757 ± 0.103 2012-02-01T12:57:13.266632+01:00| 1105.777| 6634.511|…512.138 ± 0.116 2012-02-01T12:57:14.266752+01:00| 1260.875| 7565.145|…512.469 ± 0.085 2012-02-01T12:57:15.267385+01:00| 1449.106| 8694.462|…512.715 ± 0.037 2012-02-01T12:57:16.266733+01:00| 1187.827| 7126.811|…513.005 ± 0.092 2012-02-01T12:57:17.266837+01:00| 1476.863| 8860.822|…513.262 ± 0.044 2012-02-01T12:57:18.267313+01:00| 1720.210| 10321.221|…513.363 ± 0.025 2012-02-01T12:57:19.266958+01:00| 1909.645| 11457.311|…513.369 ± 0.029 2012-02-01T12:57:20.266681+01:00| 2263.643| 13581.219|…513.203 ± 0.083 2012-02-01T12:57:21.266623+01:00| 1849.270| 11095.564|…513.063 ± 0.011 2012-02-01T12:57:22.267354+01:00| 1972.615| 11835.904|…512.987 ± 0.035 2012-02-01T12:57:23.267023+01:00| 2062.730| 12249.299|…512.885 ± 0.053 2012-02-01T12:57:24.266965+01:00| 2014.123| 12211.068|…512.798 ± 0.058 2012-02-01T12:57:25.266487+01:00| 2045.068| 12270.221|…512.601 ± 0.034 2012-02-01T12:57:26.267165+01:00| 1960.686| 11763.953|…512.541 ± 0.032 2012-02-01T12:57:27.267036+01:00| 2001.916| 12008.998|…512.415 ± 0.028 2012-02-01T12:57:28.266727+01:00| 2130.525| 12782.692|…512.245 ± 0.060 2012-02-01T12:57:29.266427+01:00| 1969.693| 11818.219|…512.131 ± 0.045 2012-02-01T12:57:30.267032+01:00| 1975.903| 11855.432|…512.006 ± 0.039 2012-02-01T12:57:31.267007+01:00| 1986.793| 11920.283|…511.940 ± 0.036 2012-02-01T12:57:32.267392+01:00| 2252.991| 13470.871|…511.749 ± 0.066 2012-02-01T12:57:33.267174+01:00| 2101.123| 12606.193|…511.546 ± 0.037 2012-02-01T12:57:34.267313+01:00| 2098.786| 12593.887|…511.397 ± 0.055 2012-02-01T12:57:35.267136+01:00| 1917.451| 11505.106|…511.276 ± 0.020 2012-02-01T12:57:36.266764+01:00| 2043.768| 12261.862|…511.167 ± 0.047 2012-02-01T12:57:37.266804+01:00| 1247.059| 7482.771|…510.965 ± 0.075 2012-02-01T12:57:38.267152+01:00| N/A| 0.000| N/A ± N/A
#2 Updated by Anonymous about 12 years ago
- Status changed from In Progress to Rejected
Turned out to be not a rsbag problem, but caused due to the spread setup, using two spread daemons (even when replay and logger started on the same machine). Spread conf was:
Spread_Segment 225.0.1.1:4814 {
sylvin 129.70.143.43
mellit 129.70.143.46
}
Setup with one spread daemon had no significant delays, even when sending events between both machines.
#3 Updated by Anonymous about 12 years ago
We should think about where to document this kind of issues (regarding spread transport / other transports).
#4 Updated by S. Wrede about 12 years ago
How did the network setup loook like? All Spread daemons and nodes physically within a local network? I am asking that because the configuration was (from a Spread perspective) correct, wasn't it? So, this should work and it is still a bug.
Wrt to collecting these issues, I wonder if we can add a category in RSB that is targeted towards the different transports.
#5 Updated by S. Wrede about 12 years ago
Johannes: Is this related to the Spread problem we had with the dataset?
#6 Updated by S. Wrede about 12 years ago
@Arne, all: Probably we could move this ticket over to project:"RSBSpread" even if the transport is not fully externalized yet.