derbynet
derbynet copied to clipboard
jeffpiazza
Sporadically fails to pull in results from Champ timer
We ran a derby this weekend with a brand new fresh install of DerbyNet (because, long story short, the SD card in our Raspberry Pi went read only - probably end of life - and we quickly needed to build a system for race day) - downloaded and installed latest version 7.0-1515-20220403 on Windows 10.
We had an odd quirk I've never seen before. Everything set up fine - database, timer test, communicating with timer, kiosks, everything.
We started racing, but about a half dozen heats in, the results stopped pulling in from the timer (a SmartLine timer with serial connection and PL2303 USB to serial dongle). Timer tests were successful, the timer was green OK, timer connection to server was green OK, and races down the track displayed places and times on the timer LED display. The data just wasn't updating DerbyNet.
This seemed to happen after we did a re-run of a heat.
So we continued, manually entering times, and although slower and more tedious, everything worked.
Until... about 20 heats later, it started magically pulling in results again (again, I think, after we'd re-run a heat).
This continued, on and off, for the entire race day.
I could see the logs on the timer display page, and clearly there was communication going on constantly with the timer.
The heat results were simply not automatically updating.
Not sure how to troubleshoot this (especially since the track and everything are torn down and put away now). Any thoughts?
Were you running with the in-browser timer interface, or derby-timer.jar? If the latter, there's a client-side log generated that'd be really useful here -- use the File menu in the derby-timer.jar GUI to locate it.
Also, could you collect and attach the server log (/var/log/nginx/access.log, I think)
Database attached. -----Original Message-----From: "Jeff Piazza" @.>Sent: Sunday, 1 May, 2022 16:08To: "jeffpiazza/derbynet" @.>Cc: "ScouterAndy" @.>, "Author" @.>Subject: Re: [jeffpiazza/derbynet] Timer fails to pull in results - sporadically (Issue #207)
Oh, and a database export, too, if you would. —Reply to this email directly, view it on GitHub, or unsubscribe.You are receiving this because you authored the thread.Message ID: @.***>
Apache logs attached. -----Original Message-----From: "Jeff Piazza" @.>Sent: Sunday, 1 May, 2022 16:05To: "jeffpiazza/derbynet" @.>Cc: "ScouterAndy" @.>, "Author" @.>Subject: Re: [jeffpiazza/derbynet] Timer fails to pull in results - sporadically (Issue #207)
Were you running with the in-browser timer interface, or derby-timer.jar? If the latter, there's a client-side log generated that'd be really useful here -- use the File menu in the derby-timer.jar GUI to locate it. Also, could you collect and attach the server log (/var/log/nginx/access.log, I think) —Reply to this email directly, view it on GitHub, or unsubscribe.You are receiving this because you authored the thread.Message ID: @.***>
derby-timer.jar - logs attached -----Original Message-----From: "Jeff Piazza" @.>Sent: Sunday, 1 May, 2022 16:05To: "jeffpiazza/derbynet" @.>Cc: "ScouterAndy" @.>, "Author" @.>Subject: Re: [jeffpiazza/derbynet] Timer fails to pull in results - sporadically (Issue #207)
Were you running with the in-browser timer interface, or derby-timer.jar? If the latter, there's a client-side log generated that'd be really useful here -- use the File menu in the derby-timer.jar GUI to locate it. Also, could you collect and attach the server log (/var/log/nginx/access.log, I think) —Reply to this email directly, view it on GitHub, or unsubscribe.You are receiving this because you authored the thread.Message ID: @.***>
I don't think the logs actually got attached, for whatever reason. If you don't mind, could you email them to me (jeff at jeffpiazza.org). Thanks!
Good evening, We’re you all able to get to the bottom of this? I ran a derby over this weekend, 2/4/2023 and had the exact same problem. When rerunning a heat, the results stopped coming in and we had to manually capture. I know why we had to rerun a head, but don’t know how to keep the timer results coming in when doing so.
Thanks for all you do by the way, I really appreciate the derby timer.
Pete Arlington, VA
Any logs you can share? Timer logs especially, but server logs may be helpful, too.
What’s your set-up look like? Are you using the timer jar or the in-browser timer interface?
timer-20230204-1018.log timer-20230204-1400.log timer-20230204-1436.log
Good morning Jeff, Looks like you were burning the midnight oil.
My set up is a windows 10 laptop hosting the derbynet timer server on a local network. I am running the Uniserver apache application and the derbytimer.jar.
I was using the race coordinator page through the browser. My best guess is that the scouts running the start gate, triggered the closed state, opened it again, and closed it before securing. I think this told the system that we had run another race, and to move to the next heat. In the race dashboard, it would show the next heat. I selected previous heat to see blank results or 10 sec times across all three lanes. When I selected to re-run that heat, the timer stopped sending results to the server.
My timer logs are attached. To resolve the issue mid derby I reset/purged and rebooted everything to get up and running. that worked until the same situation above occurred 2 rounds later. If it helps you find it, the first time occurred during the wolf round and then webelo round.
thanks again for your help, my goal here is to help you identify a bug or to learn how to make sure we don't mess up the starting gate.
Thanks for these logs!
In at least some instances (e.g., at +14:37:38 in the -1436 log), this looks to be a Champ-specific bug that was recently fixed in b0919cb49fa74a39921c0b537bee19f8f0735445. Briefly, if the start gate is already closed when a heat is queued, the command necessary to "arm" the timer doesn't get sent.
Updating to the latest derby-timer.jar should get you sorted.
In some other instances (e.g., at +14:04:41 in the -1400 log), the starting gate reports open (rs returns 0) and then closed (rs returns 1), but an "abort" message comes from the server before the gate actually opens (or reports as open) to start the race. These would be expected behavior if someone switched from "racing" to "not racing" and/or manually advanced to another heat (e.g., as the starter and crew confirm they're on the right heat). They might alternatively be a symptom of a gate switch that's perhaps slightly out of position so it doesn't always switch as it should.
I'm inclined to close this on the basis of the first part, unless you think the latter episodes aren't well explained.
Jeff, Thanks for the Reply. Your explanation does sound correct so this issue can be closed. Hopefully I'll find some time this summer to work on a better setup and help out with the Judging enhancement I submitted. Again I can't thank you enough for derbynet and the support you provide. You Rock!!!
Dave
On Tue, Feb 7, 2023 at 8:02 AM Jeff Piazza @.***> wrote:
Thanks for these logs!
In at least some instances (e.g., at +14:37:38 in the -1436 log), this looks to be a Champ-specific bug that was recently fixed in b0919cb https://github.com/jeffpiazza/derbynet/commit/b0919cb49fa74a39921c0b537bee19f8f0735445. Briefly, if the start gate is already closed when a heat is queued, the command necessary to "arm" the timer doesn't get sent.
Updating to the latest derby-timer.jar should get you sorted.
In some other instances (e.g., at +14:04:41 in the -1400 log), the starting gate reports open (rs returns 0) and then closed (rs returns 1), but an "abort" message comes from the server before the gate actually opens (or reports as open) to start the race. These would be expected behavior if someone switched from "racing" to "not racing" and/or manually advanced to another heat (e.g., as the starter and crew confirm they're on the right heat). They might alternatively be a symptom of a gate switch that's perhaps slightly out of position so it doesn't always switch as it should.
I'm inclined to close this on the basis of the first part, unless you think the latter episodes aren't well explained.
— Reply to this email directly, view it on GitHub https://github.com/jeffpiazza/derbynet/issues/207#issuecomment-1420735782, or unsubscribe https://github.com/notifications/unsubscribe-auth/AC7UH4XA7VY3QP6MGSHSNMTWWJBVNANCNFSM5U2KWWSQ . You are receiving this because you are subscribed to this thread.Message ID: @.***>
Thanks for the info. I'll download the latest version of .jar to get updated and run some more tests based on this scenario. Lets say we do have a faulty switch that triggers racing/not racing. is there a way to reinitialize things without purging all the data?
if selecting "re-run heat" doesn't allow timer results to get back on track (see what I did there) then I'm still in the same situation.
we can close it, thanks for looking into it and I'll let you know if I run into problems with testing.
thanks again!
Pete
I'm not sure what you're asking. The "faulty switch" theory was positing a slight mis-positioning of the physical switch on the track start gate (the travel on the switch is typically only 1/8" or so). The "Racing"/"Not Racing" control is on the race dashboard, and would be the reason for some "abort" messages being sent to the jar. Some of the episodes in the log show this sequence:
Gate open Gate closed Abort message received from server
The abort message implies a shift from "Racing" to "Not Racing", or manually advancing (on the dashboard) to a different heat. If the reason for that manual intervention was that a race occurred but the results weren't reported, then that's a concern. (The log wouldn't show this, because the results weren't reported.)
For manual testing, "Simulated Racing" (on the timer test page, accessible from the race dashboard) is your friend. Or you could just spin up a playground (https://hosting.derbynet.org/playground.php) and populate it with some fake racers.
I'll run some testing to confirm and see if we can log the activity, but what you describe here "If the reason for that manual intervention was that a race occurred but the results weren't reported, then that's a concern. "
is what was happening. I'll try my best to capture it here.
we are in heat 2 of 12 for a den round.
gate opens, race occurs and timer captures results and passes them to server.
the gate (I think this is how it went down) was closed, then re-opened, then closed again. Like someone let the springs slip.
now we are in heat 3 of 12.
gate opens, cars race, the timer displays the times on the timer read out, but fails to send the results to the server.
the server then advances to the next heat.
now we are in heat 4. no results for heat 3 in the server.
I click back to heat 3 and select "re-run heat".
when the cars race down the track, the timer displays results on the timer readout, but does not send results to the server.
this is where we had to capture the results and enter manually for the remaining heats.
This event is why I selected this issue thread as I believe this is the same issue as the Original Poster
I hope that helps. When I do testing, I can video or screen capture where appropriate.
Confirmed by the Original Poster that this basically describes the scenario we encountered.
The funny thing was, it eventually started working again (don't recall exactly what we did, because when you're not getting results in the middle of a derby, things get rather frantic).
Then later on, it stopped pulling results in again... also after a move back to re-run a previous heat.
In all cases, the timer pull in stopped working when we went back to re-run a heat.
We used newly-installed version 8 this past weekend at our district derby. It MOSTLY worked fine... but we did have 3 or 4 races where DerbyNet did not pull in results. What we observed when we started looking for it was that the timer status display remained at "Staging" although the race ran fine (ie. the CHAMP worked as expected, displaying places and times at the correct moment, etc.). We would then have to go back and re-run the previous heat; sometimes that fixed it in one go, other times two or three re-runs occurred.
One thing that seemed to fix it was if we went in to the timer debug dialogue and turned on debug output, observed some strings back and forth to/from the timer, then turned off debug and re-ran the heat.
However, unlike last year's issue, the majority of times, everything worked correctly, even if we decided to re-run a heat (for reasons other than lack of timing). There were just a few times when we didn't get race results pulled in to DerbyNet.
Andy, thanks for the feedback, and continued patience.
Timer logs and apache logs if you can? You're still using derby-timer.jar, right?
Timer and apache logs attached. We first ran into the issue around 11 or 12 heats into the first round.
Has there been any update on this. I am running it next week. Had the same issue when testing last night. It stopped collecting data.
So far I've been unable to reproduce in my experiments with a borrowed Champ timer. If you have a repro case, it'd certainly help. Second best would be the timer logs from your experience last night, if you have any.
timer-20230221-1620-43.log timer-20230221-1621-47.log timer-20230331-0014-49.log timer-20230331-0016-48.log timer-20230331-0024-06.log
@DionMSmith14, the logs you posted are from a FastTrack K2 timer, and probably one that doesn't support the RG (read gate state) command.
Try turning on the flag for fasttrack-automatic-gate-release. (You won't be able to release the gate by software, but it should stop the stream of LR (laser reset) commands that occasionally cause the reported times to fail to parse.)
I borrowed a Champ timer from a local pack, but wasn't able to reproduce this.
The proximate cause is that the Champ timer won't send captured results unless it receives an 'rg' command. Normally the interface jar sends the 'rg' command upon detecting the gate open, but the logs you sent never showed the gate opening. (That is, the polling for the gate state, 'rs', continually got a '1' response indicating a closed gate.)
I was hypothesizing that maybe the timer could get into a state where the gate opened and started timing but the timer would report the gate still closed, but as I said, I wasn't able to reproduce this.
When we experienced this issue. I'm pretty sure the scout resetting the starting gate was the culprit. Our gate is spring loaded. When they would swing the gate into place it triggers the starting mechanism for the timer. the little metal piece that sticks out of the timer trigger. Then something would slip (the scout dropped it, or let it fall or whatever) and the gate would release or drop back down.... sending a signal to the timer that the race had started when it actually hadn't. THEN they would put the gate back up and signal the timer that the gate is up. But the timer at the end of the track hadn't received any cars or signal the race was done. I hope that makes sense, ask me if you would like me to try again.
My logs from that day are attached, you've seen these once, but hopefully with my explanation provides context.
On Sun, Jun 4, 2023 at 6:12 PM Jeff Piazza @.***> wrote:
I borrowed a Champ timer from a local pack, but wasn't able to reproduce this.
The proximate cause is that the Champ timer won't send captured results unless it receives an 'rg' command. Normally the interface jar sends the 'rg' command upon detecting the gate open, but the logs you sent never showed the gate opening. (That is, the polling for the gate state, 'rs', continually got a '1' response indicating a closed gate.)
I was hypothesizing that maybe the timer could get into a state where the gate opened and started timing but the timer would report the gate still closed, but as I said, I wasn't able to reproduce this.
— Reply to this email directly, view it on GitHub https://github.com/jeffpiazza/derbynet/issues/207#issuecomment-1575753024, or unsubscribe https://github.com/notifications/unsubscribe-auth/AXLQH4TY2PXARYHFRZKLQ2TXJUB53ANCNFSM5U2KWWSQ . You are receiving this because you commented.Message ID: @.***>
My issue is similar, except the Timer Status never changes from staging no matter what I do. The timer itself seems to cycle as expected based on the manual. It resets and records time etc.
I plan on running a test in October. I will film our setup and try to replicate the problem. Then I’ll send logs.
On Wed, Sep 20, 2023 at 9:02 PM kummstep @.***> wrote:
My issue is similar, except the Timer Status never changes from staging no matter what I do. The timer itself seems to cycle as expected based on the manual. It resets and records time etc.
— Reply to this email directly, view it on GitHub https://github.com/jeffpiazza/derbynet/issues/207#issuecomment-1728613156, or unsubscribe https://github.com/notifications/unsubscribe-auth/AXLQH4UD5EOCJ5DF7PFQE5DX3OGZFANCNFSM5U2KWWSQ . You are receiving this because you commented.Message ID: @.***>
I still haven't been able to reproduce this. (And the neighboring pack is going to want their timer back soon.)
https://derbynet.org/download/v9pre/derby-timer.jar incorporates some code changes intended to address this issue. If you're doing any testing in the near term, I'd appreciate getting any results from using the newer jar file.
If you're able to reproduce the issue with the new jar file, then would you try turning on the -no-gate-watcher flag. That really should prevent recurrence, but loses the ability to distinguish between "staging" and "running".
kummstep, could you please open a new bug for your issue? It'd be useful if you could provide details on what kind of timer, whether you were using derby-timer.jar or the in-browser interface, and what version of DerbyNet. Big bonus points if you have logs!
@jeffpiazza thanks for the quick reply! I realized later last night, that since I was running on windows 7 that my Java may be out dated. I made a last ditch effort before bed last night and fired up a web instance on a windows 10 machine. It worked like a charm. Next chance I have to setup a local instance on the windows 10 machine, I will submit a new bug if I run into issues then.
Thanks again for your reply!