Reports until 15:55, Friday 10 January 2020
H1 CDS (DAQ)
david.barker@LIGO.ORG - posted 15:55, Friday 10 January 2020 - last comment - 16:52, Friday 10 January 2020(54413)
another h1nds1 crash

h1nds1 restarted at 14:30 this afternoon following a restart this morning. We are investigating this instability and will post details here.

Comments related to this report
jonathan.hanks@LIGO.ORG - 16:11, Friday 10 January 2020 (54415)

Taking a look at system metrics it looks like the h1nds1 received went under a some short periods of load that exhausted the memory of the system.  See the ndscope plot.  The two time axis markers are at daqd/nds crashes.

Reading the system dmesg also points out an out of memory condition. Here is a sample from the dmesg output

[6742427.444553] Out of memory: kill process 1350 (nds) score 669513 or a child
[6742427.444555] Killed process 1350 (nds) vsz:8034156kB, anon-rss:7857068kB, file-rss:4kB
[6742427.458197] nds: page allocation failure. order:0, mode:0x201da
[6742427.458199] Pid: 1350, comm: nds Not tainted 2.6.35.3 #5
[6742427.458201] Call Trace:
[6742427.458207]  [] __alloc_pages_nodemask+0x58a/0x5e3
[6742427.458211]  [] alloc_pages_current+0xa2/0xc5
[6742427.458214]  [] __page_cache_alloc+0x75/0x7c
[6742427.458217]  [] __do_page_cache_readahead+0x90/0x1a4
[6742427.458219]  [] ondemand_readahead+0x122/0x19c
[6742427.458221]  [] page_cache_sync_readahead+0x38/0x3a
[6742427.458223]  [] generic_file_aio_read+0x24d/0x56a
[6742427.458226]  [] nfs_file_read+0xa9/0xd0
[6742427.458228]  [] do_sync_read+0xc6/0x103
[6742427.458230]  [] vfs_read+0xa2/0xdf
[6742427.458232]  [] sys_read+0x45/0x69
[6742427.458235]  [] system_call_fastpath+0x16/0x1b

If this is a continued issue then we should switch the control room to reference h1nds2 which is a newer system with more resources.

Images attached to this comment
david.barker@LIGO.ORG - 16:48, Friday 10 January 2020 (54419)

Attached images show memory available (percent) as reported by h1nds1 around the times of the morning and afternoon crashes. The vertical lines going to 90% denote the time daqd is restarted. These agree with the generation of a new daqd log file. The times are (local PST):

10:33
10:34
10:49
14:29
14:30

In both cases the available memory started trending to zero about 13 minutes before the eventual crash. As reported in alog 54406 the 10:49 crash showed no error in the daqd logfile, but dmesg shows a segfault. The afternoon crash gives a dmesg memory error.

The pair or restarts following the memory depletion have the same sequence:

First restart: Retransmissions then packet skip

Second restart: Invalid broadcast received

Images attached to this comment
david.barker@LIGO.ORG - 16:52, Friday 10 January 2020 (54420)

When the available memory is being depleted, it happens in steps. The width of the steps are roughly 30 seconds, suggesting data requests are being made with that periodicity.