Family tree occasionally can't find ancestors

[BlueDiamondAvatar]

The Willow family lost the last name about 24 generations before my life. No connection between the first ancestor without the family name and the previous generations, means that numbering of generations is unavailble for the remainder of the lineage.

Here's the ancestor who seems to be the first without the last name. She has no easily found ancestor of record.
http://lineage.onehouronelife.com/server.php?action=character_page&id=3392473&rel_id=3399997

Here's my life many hours later:
http://lineage.onehouronelife.com/server.php?action=character_page&id=3399997

[jasonrohrer]

How often is this happening?

This will happen if someone in the tree has their life go unreported to the lineage server for some reason. I temporary network outage between the game server and the lineage server could cause this, for instance.

[BlueDiamondAvatar]

Hmm, it only happened to me once. Unless there are additional reports, it seems like this isn't happening often.

[BlueDiamondAvatar]

Spoke to soon, just found another example.
http://lineage.onehouronelife.com/server.php?action=character_page&id=3602928

In game, the client informed me that Snowy Knittle was my sixth cousin.

I was Bart Knittle. http://lineage.onehouronelife.com/server.php?action=character_page&id=3602767

[jasonrohrer]

Yes, looking at the lineage server logs, there is a 5-minute gap where no lives were logged at all:

The gap is between these times UTC:

2019-02-25 20:13:40:

2019-02-25 20:08:35

And it turns out that Lotta Knittle (and lots of other people) died during that time, and none of them were recorded.

Now, I gotta figure out why there'd be a 5-minute gap like this...

[jasonrohrer]

Okay, this seems to be the case of a standard "504 Gateway" type error, where all the available PHP processes get hung up somehow and stop responding. I'm not sure exactly what is happening here... But in the nginx log, I'm seeing this starting at around that time:
2019/02/25 20:09:37 [error] 25145#25145: *23962458 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 45.33.78.109, server: lineage.onehouronelife.com, request: "GET /server.php?action=log_life&server=server12.onehouronelife.com&email=REDACTED%40steamgames.com&age=0.180267&player_id=25106&parent_id=25076&display_id=347&killer_id=25106&name=NAMELESS&last_words=&male=1&sequence_number=1335&hash_value=REDACTED 9 HTTP/1.0", upstream: "fastcgi://unix:/run/php/php5.6-fpm.sock", host: "lineage.onehouronelife.com"

Those error messages continue for about 5 minutes.

At the end, the lineage server log shows that this call FINALLY gets through.

So I'm not sure if this particular call resulted in a really slow operation, or what.

In fact, the previous log_life request was received by nginx and logged by the lineage server almost instantaneously. So, not sure why this next request too five minutes to complete

104.237.138.91 - - [25/Feb/2019:20:08:35 +0000] "GET /server.php?action=log_life&server=bigserver2.onehouronelife.com&email=REDACTED%40steamgames.com&age=0.064717&player_id=422336&parent_id=422040&display_id=1007&killer_id=422336&name=NAMELESS&last_words=&male=0&sequence_number=64&hash_value=REDACTED HTTP/1.0" 200 2 "-" "-"
45.33.78.109 - - [25/Feb/2019:20:08:36 +0000] "GET /server.php?action=get_sequence_number&email=REDACTED%40steamgames.com HTTP/1.0" 200 7 "-" "-"
207.164.177.178 - - [25/Feb/2019:20:08:36 +0000] "POST /server.php HTTP/1.1" 499 0 "http://lineage.onehouronelife.com/server.php?action=front_page" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.119 Safari/537.36"
207.164.177.178 - - [25/Feb/2019:20:08:41 +0000] "POST /server.php HTTP/1.1" 499 0 "http://lineage.onehouronelife.com/server.php?action=front_page" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.119 Safari/537.36"
46.229.168.134 - - [25/Feb/2019:20:08:58 +0000] "GET /server.php?action=character_page&id=526106&rel_id=526089 HTTP/1.1" 499 0 "-" "Mozilla/5.0 (compatible; SemrushBot/3~bl; +http://www.semrush.com/bot.html)"
46.229.168.134 - - [25/Feb/2019:20:09:13 +0000] "GET /server.php?action=character_page&id=526106&rel_id=526089 HTTP/1.1" 499 0 "-" "Mozilla/5.0 (compatible; SemrushBot/3~bl; +http://www.semrush.com/bot.html)"
45.33.78.109 - - [25/Feb/2019:20:09:37 +0000] "GET /server.php?action=log_life&server=server12.onehouronelife.com&email=REDACTED%40steamgames.com&age=0.180267&player_id=25106&parent_id=25076&display_id=347&killer_id=25106&name=NAMELESS&last_words=&male=1&sequence_number=1335&hash_value=REDACTED HTTP/1.0" 504 192 "-" "-"

[jasonrohrer]

I'm stumped on this for now... if anyone feels like looking at this PHP code, it's here:

https://github.com/jasonrohrer/OneLife/blob/master/lineageServer/server.php

[chardbury]

Is the bot traffic common? Could be worth putting a robots.txt or meta robots or both on lineage.onehouronelife.com. Not sure if that’ll fix it but those were the last requests to complete, maybe they were long running. You missed an email redaction.

…

On 26 Feb 2019, at 00:23, Jason Rohrer ***@***.***> wrote: I'm stumped on this for now... if anyone feels like looking at this PHP code, it's here: https://github.com/jasonrohrer/OneLife/blob/master/lineageServer/server.php — You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub, or mute the thread.

[BlueDiamondAvatar]

Ok, so we know that this pause in lineage server functioning has happened at least twice. Is there a way to detect other times it has occurred? Any patterns in when this comes up might help determine why it is happening, and how common it is.

[jasonrohrer]

Yeah, lemme look at the logs and see other times when timeouts have happened.

[jasonrohrer]

So, about a five-minute block of timeouts ending at:
2019/02/25 20:13:44

Then a single timeout today at:
2019/02/26 02:22:03

Before that, single timeouts:
2019/02/25 01:06:09
2019/02/24 07:30:23
2019/02/23 09:56:03

Block timeout from:
2019/02/23 10:58:28
to
2019/02/23 11:06:07

That's 8 minutes, yikes!

In the lineage server log, I'm seeing a gap between:
2019-02-23 10:57:24
and
2019-02-23 11:00:36

[BlueDiamondAvatar]

There's a forum thread where some other folks are talking about this issue.
http://onehouronelife.com/forums/viewtopic.php?id=5428

My take from the other gaps you've found... It varies from single timeouts (seconds?) to a timeout of eight minutes. Seems like it was worse on the 23rd than in the last few days. Is it somehow correlated to server traffic? Was Saturday (23rd) busier than Sunday (24th) for some reason? No clear patterns standing out.

[JkHowling]

This is happening a LOT more often now. Please figure out a fix for this. It's becoming increasingly common and it's annoying as shit when you revisit the lineage- the ONLY way I can know what happened after my lifetime!!!- to find it's all fucked up because of a single life that went unregistered.

[BlueDiamondAvatar]

Latest evidence that links are getting lost is that occasionally non-eve mothers pop into the "today's longest line" listing. When investigated there is no obvious tie to previous family. This could become an issue with property gates, war swords, etc.

Today's example: http://lineage.onehouronelife.com/server.php?action=character_page&id=5267803
Other recent example: http://lineage.onehouronelife.com/server.php?action=character_page&id=5267263&rel_id=5267439

[jasonrohrer]

Closing. I think this has mostly been dealt with.