Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Schrodinger's user logs diffs #323

Closed
2 tasks
yakra opened this issue May 14, 2020 · 6 comments · Fixed by #333
Closed
2 tasks

Schrodinger's user logs diffs #323

yakra opened this issue May 14, 2020 · 6 comments · Fixed by #333

Comments

@yakra
Copy link
Contributor

yakra commented May 14, 2020

Currently using 1a2932ad6db82301d5c3d061c7d7772aebc112cb on BiggaTomato but this has been showing up for a while now...

Sometimes, compare_all.sh shows differences in user logs, E.G.

mc49399.log:
0a1
> Note: deprecated route name I-285FutWin -> canonical name I-285 in line NC I-285FutWin I-85 107(52)

Running siteupdate again with no changes to HighwayData, UserData, the siteupdate executable or its parameters results in the diff disappearing.
Most perplexing. No idea what could be causing this.

I haven't noticed whether this happens for .log lines other than the "deprecated route name" variety. If it does, I'll log them here.

A new shell script can run siteupdate & compare_all.sh a set number of times or indefinitely, until diffs are found.

TBD: Does this happen...

  • with only one ReadListThread?
  • with threading disabled?

Part of me hopes this will just go away when I address the other TravelerList ctor issues...

@yakra
Copy link
Contributor Author

yakra commented May 14, 2020

Ugnaught2.log:
1d0
< Waypoint label(s) not found in line: AR US167 I-530(3) AR69/69Bus

1.log:
0a1
> Waypoint label(s) not found in line: GA GA120 GA316 ClaSt

Weird. This puts a stake through my theory about wacky try/catch behavior in a multi-threaded environment; I have no leads on what could be causing this. Changes in progress for #278 will involve a major rewrite of this part of the code, so hopefully this goes away in the process...

@yakra
Copy link
Contributor Author

yakra commented May 17, 2020

Pending changes are not enough to perturb this out of existence. This time, it's

1995hoo.log:
1d0
< Unknown region/highway combo in line: ENG A344 A303 A360
  • Test out the wazoo on lab1.5; see if stuff breaks there...
  • Maybe if I upgrade GCC...?
  • Though maybe for giggles, try getting an iterator via unordered_map::find, branching based on validity, and dereferencing?

@yakra
Copy link
Contributor Author

yakra commented May 19, 2020

sbeaver44.log:
1d0
< Waypoint label NLABREAAVE not found in line: CA US66HisHol NLaBreaAve HigAve
neroute2.log:
1,2c1
< Waypoint label(s) not found in line: CA CA91 I-405 VerAve
< Waypoint label(s) not found in line: CA CA238 AppAve 14
---
> Waypoint labels APPAVE and 14 not found in line: CA CA238 AppAve 14

@yakra
Copy link
Contributor Author

yakra commented May 30, 2020

This may or may not be the bug I'm looking for, but it's in the TravelerList ctor, and I'm writing to areas of memory I shouldn't be. So maybe it's possible it could be producing these effects.
I'll have to keep an eye out & test the versions before & after the commit that eventually fixes this.

char * endchar = lines[l+1]-2; // -2 skips over the 0 inserted while separating listdata into lines
while (*endchar == 0) endchar--; // skip back more for CRLF cases, and lines followed by blank lines
while (*endchar == ' ' || *endchar == '\t')
{ *endchar = 0;
endchar--;
}

If a file begins with a blank line, this causes endchar to point to a location in memory before the beginning of the .list file copy. If that location contains a space or tab, we start overwriting stuff, and wacky antics ensue.
Under just the right conditions, this can crash siteupdate entirely.
With all the thousands of times I've run siteupdate with no crashes, I'm surprised I didn't notice the problem earlier.

@yakra
Copy link
Contributor Author

yakra commented May 31, 2020

All of these errors affect the first line of the .log file. The lines shown in the diffs above aren't missing -- the timestamp string (which includes a newline) after Log file created at: is. The underlying diffs are thus something like:

1,2c1
< Log file created at: Sun May 31 12:16:29 2020
< Waypoint label I-65 not found in line: AL AL14 I-65 US31
---
> Log file created at: Waypoint label I-65 not found in line: AL AL14 I-65 US31

Since the timestamp will always be changing, compare_all.sh ignores the first line of the file, thus turning the diff into:

1d0
< Waypoint label I-65 not found in line: AL AL14 I-65 US31

from http://www.cplusplus.com/reference/ctime/ctime/:

Return Value

A C-string containing the date and time information in a human-readable format.

The returned value points to an internal array whose validity or value may be altered by any subsequent call to asctime or ctime.

Appears that ctime is not thread safe.
Reading on...

Data races

The function accesses the object pointed by timer.
The function also accesses and modifies a shared internal buffer, which may cause data races on concurrent calls to asctime or ctime.

Yup.

The simplest thing to do may be to just slap a mutex around calling ctime & inserting it into the ofstream.

@yakra
Copy link
Contributor Author

yakra commented May 31, 2020

We already have

static std::mutex alltrav_mtx; // for locking the traveler_lists list when reading .lists from disk

This is already used rarely and briefly; reusing it to lock ctime should not create a noticeable performance hit.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

1 participant