Not indexing updates after upgrading gem

[JasonBarnabe]

I upgraded to 2.0.2 and since then, it looks like updates stop getting indexed after a while (maybe after a deploy?).

[Mon Mar 26 00:20:23.625 2018] [19628] caught SIGHUP (seamless=1, in queue=1)
[Mon Mar 26 00:20:23.639 2018] [19628] rotating index 'script_delta': started
[Mon Mar 26 00:20:23.646 2018] [19628] rotating index 'script_delta': success
[Mon Mar 26 00:20:23.646 2018] [19628] rotating index 'script_core': started
[Mon Mar 26 00:20:23.656 2018] [19628] rotating index 'script_core': success
[Mon Mar 26 00:20:23.658 2018] [19628] rotating index: all indexes done

And nothing in production.searchd.log since then.

I was previously on 0aef2195f3acc1da048f18bc0191c90538565705, so there shouldn't be any changes when going to 2.0.2, but maybe the update of riddle from 2.2.0 to 2.3.0 is causing the issue?

[pat]

Hrm. Are there any temp files in the indices directory?

[JasonBarnabe]

$ ls -l shared/db/sphinx/ts-script_delta.tmp 
-rw-rw-r-- 1 www www 0 Mar 25 19:11 shared/db/sphinx/ts-script_delta.tmp

I have deleted this once already on March 24 and the issue reoccurred. Nothing special in the log at the same time this was created.

[Sun Mar 25 19:11:20.124 2018] [19628] caught SIGHUP (seamless=1, in queue=1)
[Sun Mar 25 19:11:20.129 2018] [19628] rotating index 'script_delta': started
[Sun Mar 25 19:11:20.136 2018] [19628] rotating index 'script_delta': success
[Sun Mar 25 19:11:20.137 2018] [19628] rotating index: all indexes done

[pat]

Does deleting that file get the index processing working again?

[JasonBarnabe]

Last time, I deleted it then kicked ts a bunch of times and it started working. This time I will just delete it and report back.

Deleted at: Mar 28 02:34:10 UTC 2018

[JasonBarnabe]

Running again for now.

[Wed Mar 28 02:38:54.158 2018] [19628] caught SIGHUP (seamless=1, in queue=1)
[Wed Mar 28 02:38:54.203 2018] [19628] rotating index 'script_delta': started
[Wed Mar 28 02:38:54.210 2018] [19628] rotating index 'script_delta': success
[Wed Mar 28 02:38:54.210 2018] [19628] rotating index: all indexes done
[Wed Mar 28 02:40:09.253 2018] [19628] caught SIGHUP (seamless=1, in queue=1)
[Wed Mar 28 02:40:09.300 2018] [19628] rotating index 'script_delta': started
[Wed Mar 28 02:40:09.308 2018] [19628] rotating index 'script_delta': success
[Wed Mar 28 02:40:09.308 2018] [19628] rotating index: all indexes done
[Wed Mar 28 02:40:44.332 2018] [19628] caught SIGHUP (seamless=1, in queue=1)
[Wed Mar 28 02:40:44.372 2018] [19628] rotating index 'script_delta': started
[Wed Mar 28 02:40:44.379 2018] [19628] rotating index 'script_delta': success
[Wed Mar 28 02:40:44.379 2018] [19628] rotating index: all indexes done

[pat]

Good to know that's the source of the issue… though the fact that it's cropping up at all is frustrating. There are some changes in develop to make the lock file experience a bit better (see the last two points in the Changes to Behaviour section of the forthcoming release notes - all of this is in the develop branch), but neither of those are going to address what you're seeing.

I don't suppose you have any failed delta jobs in your database?

[JasonBarnabe]

I see no failed jobs.

I will update if/when it starts happening again. Judging from the past week, should be a couple of days.

[JasonBarnabe]

This has not happened since.

[JasonBarnabe]

It has happened again. I see a ts-script_delta.tmp file with a date that matches some errors in my production.searchd.log:

[Sun May  6 04:52:13.492 2018] [19628] caught SIGHUP (seamless=1, in queue=1)
[Sun May  6 04:52:13.523 2018] [19628] rotating index 'script_delta': started
[Sun May  6 04:52:13.531 2018] [19628] WARNING: rotating index 'script_delta': prealloc: mmap() failed: Cannot allocate memory (length=14669761); using old index
[Sun May  6 04:52:13.531 2018] [19628] rotating index: all indexes done

[pat]

Appreciate the extra data. Can you confirm which version of TS you're using?