[Varnish] #1054: Child not responding to CLI, killing it

[Varnish]

#1054: Child not responding to CLI, killing it
-----------------------+----------------------------------------------------
  Reporter:  scorillo  |        Type:  defect  
    Status:  reopened  |    Priority:  normal  
 Milestone:            |   Component:  varnishd
   Version:  3.0.2     |    Severity:  normal  
Resolution:            |    Keywords:          
-----------------------+----------------------------------------------------

Comment(by bstillwell):

 I'm also seeing this problem with varnish 3.0.2 on CentOS 6.2.  There
 isn't any panic output from varnishadm:

 {{{
 [root at den2tpv16 ~]# varnishadm panic.show
 Child has not panicked or panic has been cleared
 Command failed with error code 300
 }}}

 However /var/log/messages has some details:
 {{{
 May 16 19:18:45 den2tpv16 varnishd[32205]: Child (32206) not responding to
 CLI, killing it.
 May 16 19:18:55 den2tpv16 varnishd[32205]: Child (32206) not responding to
 CLI, killing it.
 May 16 19:19:05 den2tpv16 varnishd[32205]: Child (32206) not responding to
 CLI, killing it.
 May 16 19:19:15 den2tpv16 varnishd[32205]: Child (32206) not responding to
 CLI, killing it.
 May 16 19:19:25 den2tpv16 varnishd[32205]: Child (32206) not responding to
 CLI, killing it.
 May 16 19:19:35 den2tpv16 varnishd[32205]: Child (32206) not responding to
 CLI, killing it.
 May 16 19:19:37 den2tpv16 varnishd[32205]: Child (32206) not responding to
 CLI, killing it.
 May 16 19:19:38 den2tpv16 varnishd[32205]: Child (32206) died signal=3
 (core dumped)
 May 16 19:19:38 den2tpv16 varnishd[32205]: child (4447) Started
 May 16 19:19:38 den2tpv16 varnishd[32205]: Child (4447) said Child starts
 May 16 19:19:38 den2tpv16 varnishd[32205]: Child (4447) said SMF.s0
 mmap'ed 85899345920 bytes of 85899345920
 }}}

 The machine has 32GiB of memory with an SSD for storage (120GB OCZ
 Vertex2).  The storage option I'm using is: -s
 file,/data/varnish_storage.bin,80G,32K

 Using -s malloc,23G on this same box is quite stable, but I'm hoping to
 start using SSDs to improve our hitrates (we have a very large set size).

 'dstat -tlcmgndr 60' output:


 {{{

 ----system---- ---load-avg--- ----total-cpu-usage---- ------memory-
 usage----- ---paging-- -net/total- -dsk/total- --io/total-
   date/time   | 1m   5m  15m |usr sys idl wai hiq siq| used  buff  cach
 free|  in   out | recv  send| read  writ| read  writ
 16-05 19:08:13|0.10 11.6 15.1|  3   2  93   2   0   1|2719M 52.7M 28.0G
 328M|   0     0 |3675k   13M|1878k  136k| 469  11.3
 16-05 19:09:13|0.12 9.52 14.2|  3   2  93   2   0   1|2721M 52.9M 28.0G
 320M|   0     0 |3425k   13M|1753k  133k| 438  11.1
 16-05 19:10:13|0.16 7.82 13.3|  3   2  93   2   0   1|2719M 53.1M 28.0G
 298M|   0     0 |3069k   13M|1529k  139k| 382  12.1
 16-05 19:11:13|0.47 6.50 12.5|  3   2  93   2   0   1|2721M 53.3M 28.0G
 308M|   0     0 |3763k   13M|1925k  135k| 481  12.3
 16-05 19:12:13|0.35 5.36 11.7|  3   2  93   2   0   1|2724M 53.5M 28.0G
 310M|   0     0 |3652k   12M|1852k  140k| 463  12.5
 16-05 19:13:13|0.17 4.40 11.0|  3   2  92   2   0   1|2725M 53.6M 28.0G
 304M|   0     0 |4319k   14M|2498k  140k| 625  12.6
 16-05 19:14:13|0.31 3.68 10.3|  3   2  93   2   0   1|2723M 51.2M 28.0G
 316M|   0     0 |3437k   12M|2006k  135k| 501  12.0
 16-05 19:15:13|0.26 3.05 9.71|  3   2  93   2   0   1|2722M 51.4M 28.0G
 316M|   0     0 |4249k   14M|2313k  135k| 578  12.2
 16-05 19:16:13|0.14 2.51 9.10|  3   2  93   2   0   1|2723M 51.6M 28.0G
 308M|   0     0 |3741k   12M|1774k  132k| 443  11.6
 16-05 19:17:13|17.6 6.52 10.0|  3   3  53  41   0   1|2725M 51.7M 28.0G
 297M|   0     0 |3780k   12M|1755k   18M| 439   193
 16-05 19:18:13| 302 78.2 33.7|  2   2  26  68   0   1|2778M 51.8M 27.9G
 321M|   0     0 |2401k 9803k| 681k   18M| 170   463
 16-05 19:19:13| 561  194 76.3|  1   1  35  63   0   1|2765M 51.8M 27.9G
 350M|   0     0 | 438k 1137k| 148k   14M|37.1   840
 16-05 19:20:13| 373  222 94.2|  4   5  27  62   0   2|2011M 52.1M 28.0G
 1015M|   0     0 |  15M   13M|1474k   15M| 366   577
 16-05 19:21:13| 142  183 88.9|  3   3  52  41   0   1|2012M 52.2M 28.1G
 930M|   0     0 |  10M   13M|1371k   15M| 343   360
 16-05 19:22:13|52.7  150 83.4|  3   3  73  20   0   1|2012M 52.4M 28.2G
 781M|   0     0 |8901k   12M|2472k 8992k| 618   266
 16-05 19:23:13|20.4  123 78.3|  3   2  73  21   0   1|2012M 52.6M 28.3G
 630M|   0     0 |7799k   12M|2502k 8782k| 626   270
 16-05 19:24:13|8.86  101 73.5|  3   3  76  18   0   1|2022M 52.8M 28.5G
 453M|   0     0 |7689k   18M|2791k 7731k| 698   245
 16-05 19:25:13|3.74 82.7 69.0|  3   3  74  20   0   1|2027M 52.9M 28.6G
 315M|   0     0 |7754k   14M|2786k 8175k| 697   255
 16-05 19:26:13|2.70 68.0 64.8|  3   2  80  15   0   1|2029M 53.1M 28.6G
 315M|   0     0 |6680k   13M|2162k 6918k| 540   240

 }}}

-- 
Ticket URL: <https://www.varnish-cache.org/trac/ticket/1054#comment:8>
Varnish <https://varnish-cache.org/>
The Varnish HTTP Accelerator