From owner-freebsd-current@FreeBSD.ORG Wed May 25 18:24:39 2011 Return-Path: Delivered-To: current@FreeBSD.ORG Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id E7EF11065679; Wed, 25 May 2011 18:24:38 +0000 (UTC) (envelope-from sobomax@sippysoft.com) Received: from mail.sippysoft.com (mail.sippysoft.com [4.59.13.245]) by mx1.freebsd.org (Postfix) with ESMTP id 5C9F88FC1D; Wed, 25 May 2011 18:24:38 +0000 (UTC) Received: from [4.59.13.245] (helo=[192.168.1.79]) by mail.sippysoft.com with esmtpsa (TLSv1:CAMELLIA256-SHA:256) (Exim 4.72 (FreeBSD)) (envelope-from ) id 1QPIl3-0008p5-H3; Wed, 25 May 2011 11:24:37 -0700 Message-ID: <4DDD4964.7060008@sippysoft.com> Date: Wed, 25 May 2011 11:24:36 -0700 From: Maxim Sobolev Organization: Sippy Software, Inc. User-Agent: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9.2.17) Gecko/20110414 Lightning/1.0b2 Thunderbird/3.1.10 MIME-Version: 1.0 To: Pawel Jakub Dawidek References: <4DDD4890.70604@FreeBSD.org> In-Reply-To: <4DDD4890.70604@FreeBSD.org> Content-Type: multipart/mixed; boundary="------------070703080106020807050502" X-ssp-trusted: yes X-Mailman-Approved-At: Wed, 25 May 2011 18:29:30 +0000 Cc: "current@freebsd.org" Subject: Re: Weird issue with hastd(8) X-BeenThere: freebsd-current@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Discussions about the use of FreeBSD-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 25 May 2011 18:24:39 -0000 This is a multi-part message in MIME format. --------------070703080106020807050502 Content-Type: text/plain; charset=KOI8-U; format=flowed Content-Transfer-Encoding: 7bit On 5/25/2011 11:21 AM, Maxim Sobolev wrote: > Hi Pawel, > > I am observing strange errors while synchronizing the data between > primary and secondary. I keep getting the following error messages: > > May 25 11:09:19 eights hastd[10113]: [test] (secondary) Unable to > receive request header: Socket is not connected. > May 25 11:09:24 eights hastd[37571]: [test] (secondary) Worker process > exited ungracefully (pid=10113, exitcode=75). > May 25 11:10:17 eights hastd[12109]: [test] (secondary) Unable to > receive request header: Socket is not connected. > May 25 11:10:18 eights hastd[37571]: [test] (secondary) Worker process > exited ungracefully (pid=12109, exitcode=75). > May 25 11:10:39 eights hastd[14685]: [test] (secondary) Unable to > receive request header: Socket is not connected. > May 25 11:10:44 eights hastd[37571]: [test] (secondary) Worker process > exited ungracefully (pid=14685, exitcode=75). > > The synchronization steel proceeds, but it's slow due to the need to > re-negotiate and re-spawn the secondary worker. I have tried to ktrace > both server and client at the same time. For some reason the primary > keeps sending data, while client gets 0-read from the recvfrom at some > point, while the primary keeps sending more data. This is 8-STABLE code > on both ends. > > Any ideas of what could be wrong here are appreciated. Sorry, forgot the traces. Regards, -- Maksym Sobolyev Sippy Software, Inc. Internet Telephony (VoIP) Experts Tel: +1-646-651-1110 Fax: +1-866-857-6942 Web: http://www.sippysoft.com MSN: sales@sippysoft.com Skype: SippySoft --------------070703080106020807050502 Content-Type: text/plain; name="ktrace_secondary.txt" Content-Transfer-Encoding: 7bit Content-Disposition: attachment; filename="ktrace_secondary.txt" 83257 hastd 1306344078.593820 CALL recvfrom(0x7,0x80360d400,0x8c,MSG_WAITALL,0,0) 83257 hastd 1306344078.593825 GIO fd 7 read 140 bytes 0x0000 0204 0100 0000 636d 6400 0068 0000 0200 0000 0000 0000 0804 0800 0000 7365 7100 0068 |......cmd..h................seq..h| 0x0022 0000 0100 0000 0000 0000 0807 0800 0000 6f66 6673 6574 0000 0000 2040 0000 0000 0807 |................offset.... @......| 0x0044 0800 0000 6c65 6e67 7468 0000 0000 0200 0000 0000 110c 0400 0000 636f 6d70 7265 7373 |....length................compress| 0x0066 696f 6e00 0000 0000 6c7a 6600 0000 0000 0605 0400 0000 7369 7a65 0068 0000 80e8 0100 |ion.....lzf...........size.h......| 0x0088 0000 0000 |....| 83257 hastd 1306344078.593830 RET recvfrom 140/0x8c 83257 hastd 1306344078.593851 CALL recvfrom(0x7,0x8030c4000,0x1e880,MSG_WAITALL,0,0) 83257 hastd 1306344098.677645 GIO fd 7 read 4096 bytes 0x0000 0000 0200 1f10 031a 0003 2403 2e03 3803 4200 034c 0356 0360 036a 0003 7403 7e03 8803 |..........$...8.B..L.V.`.j..t.~...| 0x0022 9200 031f 9c03 a603 b003 ba00 03c4 03ce 03d8 03e2 0003 ec03 f603 f518 1600 65bb 124e |..............................e..N| 0x0044 378d 1f11 8f00 b402 0700 0103 0402 0000 0200 96a4 939a ba28 ac5b 6400 1401 0814 0a03 |7......................(.[d.......| [...] 0x0ff0 7c26 017d 2601 7e20 0c09 7f26 0180 2601 ||&.}&.~ ...&..&.| 83257 hastd 1306344098.677664 RET recvfrom 125056/0x1e880 83257 hastd 1306344098.678035 CALL _umtx_op(0x801223120,0x9,0,0,0) 83257 hastd 1306344098.678046 RET _umtx_op 0 83257 hastd 1306344098.678048 RET _umtx_op 0 83257 hastd 1306344098.678050 CALL recvfrom(0x7,0x7fffff9fdf70,0x5,MSG_WAITALL,0,0) 83257 hastd 1306344098.678057 GIO fd 7 read 0 bytes "" 83257 hastd 1306344098.678060 RET recvfrom 0 83257 hastd 1306344098.678064 CALL pwrite(0x4,0x8030c4000,0x20000,0x40208a00) 83257 hastd 1306344098.678097 CALL stat(0x7fffff9fd590,0x7fffff9fd510) 83257 hastd 1306344098.678102 NAMI "/usr/share/nls/C/libc.cat" 83257 hastd 1306344098.678108 RET stat -1 errno 2 No such file or directory 83257 hastd 1306344098.678111 CALL stat(0x7fffff9fd590,0x7fffff9fd510) 83257 hastd 1306344098.678115 NAMI "/usr/share/nls/libc/C" 83257 hastd 1306344098.678121 RET stat -1 errno 2 No such file or directory 83257 hastd 1306344098.678123 GIO fd 4 wrote 4096 bytes 0x0000 1003 1a00 0324 032e 0338 0342 0003 4c03 5603 6003 6a00 0374 037e 0388 0392 0003 9c03 |.....$...8.B..L.V.`.j..t.~........| 0x0022 a603 b003 ba00 03c4 03ce 03d8 03e2 0003 ec03 f603 f518 1600 65bb 124e 378d 118f 00b4 |........................e..N7.....| 0x0044 0207 0001 0304 0200 0002 0096 a493 9aba 28ac 5b64 0014 0108 140a 0300 0403 ea39 239c |................(.[d...........9#.| [...] 0x0f8a 0a60 014a 011c 0000 011c 0126 0130 013a 0001 4401 4e01 5801 6200 016c 0176 0180 018a |.`.J.......&.0.:..D.N.X.b..l.v....| 0x0fac 0001 9401 9e01 a801 b200 01bc 01c6 01d0 01da 0001 e401 ee01 f802 0200 020c 0216 0220 |................................. | 0x0fce 022a 0002 3402 3e02 4802 5200 025c 0266 0270 027a 0002 8402 8e02 9802 a200 02ac 02b6 |.*..4.>.H.R..\.f.p.z..............| 0x0ff0 02c0 02ca 0002 d402 de02 e802 f200 02fc |................| 83257 hastd 1306344098.678125 CALL stat(0x7fffff9fd590,0x7fffff9fd510) 83257 hastd 1306344098.678137 RET pwrite 131072/0x20000 83257 hastd 1306344098.678138 NAMI "/usr/local/share/nls/C/libc.cat" 83257 hastd 1306344098.678141 CALL _umtx_op(0x801223160,0x9,0,0,0) 83257 hastd 1306344098.678142 RET stat -1 errno 2 No such file or directory 83257 hastd 1306344098.678153 CALL stat(0x7fffff9fd590,0x7fffff9fd510) 83257 hastd 1306344098.678156 NAMI "/usr/local/share/nls/libc/C" 83257 hastd 1306344098.678159 RET _umtx_op 0 83257 hastd 1306344098.678160 RET stat -1 errno 2 No such file or directory 83257 hastd 1306344098.678163 CALL _umtx_op(0x801223120,0x8,0x1,0x801223100,0) 83257 hastd 1306344098.678163 RET _umtx_op 0 83257 hastd 1306344098.678192 CALL clock_gettime(0xd,0x7fffff9fcc40) 83257 hastd 1306344098.678197 RET clock_gettime 0 83257 hastd 1306344098.678203 CALL sendto(0x8,0x8013f93fb,0x1b,MSG_NOSIGNAL,0,0) 83257 hastd 1306344098.678218 GIO fd 8 wrote 27 bytes 0x0000 0116 0000 0008 0408 0000 0073 6571 0060 0308 0001 0000 0000 0000 00 |...........seq.`...........| 83257 hastd 1306344098.678221 RET sendto 27/0x1b 83257 hastd 1306344098.678228 CALL _umtx_op(0x801223160,0x8,0x1,0x801223140,0) 83257 hastd 1306344098.678229 CALL getpid 83257 hastd 1306344098.678234 RET getpid 83257/0x14539 83257 hastd 1306344098.678239 CALL sendto(0x3,0x7fffff9fccd0,0x6f,0,0,0) 83257 hastd 1306344098.678248 GIO fd 3 wrote 111 bytes "<27>May 25 10:21:38 hastd[83257]: [test] (secondary) Unable to receive request header: Socket is not connected." --------------070703080106020807050502 Content-Type: text/plain; name="ktrace_primary.txt" Content-Transfer-Encoding: 7bit Content-Disposition: attachment; filename="ktrace_primary.txt" 8173 hastd 1306344078.549041 RET sendto 145/0x91 8173 hastd 1306344078.549043 CALL sendto(0x6,0x80385c000,0x8000,MSG_NOSIGNAL,0,0) 8173 hastd 1306344078.549109 GIO fd 6 wrote 4096 bytes 0x0000 0000 0200 1f10 031a 0003 2403 2e03 3803 4200 034c 0356 0360 036a 0003 7403 7e03 8803 |..........$...8.B..L.V.`.j..t.~...| 0x0022 9200 031f 9c03 a603 b003 ba00 03c4 03ce 03d8 03e2 0003 ec03 f603 f518 1600 65bb 124e |..............................e..N| 0x0044 378d 1f11 8f00 b402 0700 0103 0402 0000 0200 96a4 939a ba28 ac5b 6400 1401 0814 0a03 |7......................(.[d.......| 0x0066 001f 0403 ea39 239c 0681 52ff 060a 8200 070a 8007 0a81 0507 0af4 0705 f501 5900 4280 |.....9#...R...................Y.B.| 0x0088 1fea 3927 5807 60e1 0005 0037 ea09 0303 0300 a450 4209 1ab2 8604 b386 04b4 5586 0409 |..9'X.`....7.......PB.........U...| 0x00aa b586 04b6 8604 b786 04b8 200c 09b9 8604 ba86 04bb 8604 bc20 0c09 bd86 04be 8604 bf86 |.......... ............ ..........| 0x0f8a 015e 2601 5f23 0135 a809 1960 2601 6126 0162 26ec 0963 2601 6426 0165 2601 6620 0c09 |.^&._#.5...`&.a&.b&..c&.d&.e&.f ..| 0x0fac 6726 0168 2601 6926 016a 200c 096b 2601 6c26 016d 2601 6e20 0c09 6f26 0170 2601 7126 |g&.h&.i&.j ..k&.l&.m&.n ..o&.p&.q&| 0x0fce 0172 200c 0973 2601 7426 0175 2601 7620 0c09 7726 0178 2601 7926 017a 200c 097b 2601 |.r ..s&.t&.u&.v ..w&.x&.y&.z ..{&.| 0x0ff0 7c26 017d 2601 7e20 0c09 7f26 0180 2601 ||&.}&.~ ...&..&.| [...] 8173 hastd 1306344078.549113 RET sendto 32768/0x8000 8173 hastd 1306344078.549116 CALL sendto(0x6,0x803864000,0x8000,MSG_NOSIGNAL,0,0) 8173 hastd 1306344078.549180 GIO fd 6 wrote 4096 bytes 0x0000 4a47 6b76 0559 7730 6234 4923 a715 7976 7462 6348 5844 4b78 6b5a 6371 4d65 7958 746a |JGkv.Yw0b4I#..yvtbcHXDKxkZcqMeyXtj| 0x0022 4731 33a2 1874 746b 4546 6b77 5973 4741 4c4f 6b72 3556 5166 7542 6a6c 6e44 2710 004b |G13..ttkEFkwYsGALOkr5VQfuBjlnD'..K| 0x0044 24f1 0765 486e 6e45 4f4a 702d 8306 386f 7775 4e78 452a 0d1c 746c 5868 5739 6a47 626a |$..eHnnEOJp-..8owuNxE*..tlXhW9jGbj| [...] 0x0f68 6945 6864 6d38 3929 9f07 335a 6742 4b57 5945 2607 1f47 6669 6762 4c57 316a 2f5a 702f |iEhdm89)..3ZgBKWYE&..GfigbLW1j/Zp/| 0x0f8a 5a36 3066 514c 3238 7362 7251 7266 5564 5430 7a05 5576 6970 7273 3079 0433 4353 3345 |Z60fQL28sbrQrfUdT0z.Uviprs0y.3CS3E| 0x0fac 29bf 0c72 7248 6964 626a 534c 4b36 6b68 3a31 1f57 3074 7264 4162 4553 5345 7367 794f |)..rrHidbjSLK6kh:1.W0trdAbESSEsgyO| 0x0fce 4a38 5433 7678 4975 2f69 5838 4c37 7634 7032 a60a 6165 7558 3274 574e 7861 5220 9d04 |J8T3vxIu/iX8L7v4p2..aeuX2tWNxaR ..| 0x0ff0 4266 5847 6b23 9800 7158 fb0d 754c 4b34 |BfXGk#..qX..uLK4| 8173 hastd 1306344078.549184 RET sendto 32768/0x8000 8173 hastd 1306344078.549186 CALL sendto(0x6,0x80386c000,0x8000,MSG_NOSIGNAL,0,0) 8173 hastd 1306344078.645696 GIO fd 6 wrote 4096 bytes 0x0000 4362 6247 306b 6246 676b 2895 1f4a 7655 6a63 4649 474f 4258 5179 334e 734e 6175 6b56 |CbbG0kbFgk(..JvUjcFIGOBXQy3NsNaukV| 0x0022 516a 7241 7269 5159 6a55 6c0d 564b 4249 386b 447a 4163 6b78 444a 2b45 0e56 6477 7751 |QjrAriQYjUl.VKBI8kDzAckxDJ+E.VdwwQ| 0x0044 4255 7668 697a 744c 4b4b 2766 046c 5957 374a 2725 1f6b 4979 5933 5553 4441 4277 4645 |BUvhiztLKK'f.lYW7J'%.kIyY3USDABwFE| 0x0fac 7131 5a30 3432 7670 4658 6c1f 4a4e 4e4a 4b50 5461 3656 3372 6532 312b 6837 566f 6b61 |q1Z042vpFXl.JNNJKPTa6V3re21+h7Voka| 0x0fce 7168 6a59 414d 3752 7946 0243 6d35 2e1c 032f 6474 7621 371f 7970 546e 4f46 504b 6a49 |qhjYAM7RyF.Cm5.../dtv!7.ypTnOFPKjI| 0x0ff0 7a78 3071 3263 4839 6e36 6863 2b62 4757 |zx0q2cH9n6hc+bGW| [...] 8173 hastd 1306344078.645762 RET sendto 32768/0x8000 8173 hastd 1306344078.645769 CALL sendto(0x6,0x803874000,0x6880,MSG_NOSIGNAL,0,0) 8173 hastd 1306344078.732828 GIO fd 6 wrote 4096 bytes 0x0000 1f73 0f6c e01e 2190 e31e 9473 0021 0f41 e060 6200 2181 afff 3f7f b263 b229 1e47 201f |.s.l..!....s.!.A.`b.!...?..c.).G .| 0x0022 2d6e a02a fa65 ea1d 5420 0e3f b3ff 1cf1 1c63 8e7f 6b1c 612b 658e ff1c ff1c ef1c 1fa1 |-n.*.e..T .?.....c..k.a+e.........| 0x0044 6c6d ffe0 d3a1 7ce1 4da3 2ba7 02bf 0ebf 0eaf 0e5a 4ce0 7d6f a00e a91d 44a2 9b03 67bf |lm....|.M.+........ZL.}o....D...g.| 0x0f46 6047 be6d a222 7f22 ed8a 6f22 a186 6ca0 201f d761 5521 213f 3469 e055 53a0 4861 575d |`G.m."."..o"..l. ..aU!!?4i.US.HaW]| 0x0f68 215b 69bf 23ee 9b75 3376 601b 692d 621d 0762 a000 3f46 65e2 7d26 761f e96a 6123 7920 |![i.#..u3v`.i-b..b..?Fe.}&v..ja#y | 0x0f8a 5172 ff12 ff12 0096 4520 41e1 b279 6066 4700 a764 15a1 1465 a07d 1965 20bd 2000 4805 |Qr......E A..y`fG..d...e.}.e . .H.| 0x0fac e021 e7e0 22d6 001f 0165 c5e0 0059 e00f 6b00 2e45 411f b520 1078 20c3 6c22 1ae1 6867 |.!.."....e...Y..k..EA.. .x .l"..hg| 0x0fce 2011 e84c 00fc 2056 66e0 3621 9d21 8f8a 6be2 2579 01e0 1058 ee04 10ba 5420 2925 f41f | ..L.. Vf.6!.!..k.%y...X....T )%..| 0x0ff0 a19b a321 2ee0 11b7 3f12 6fd1 6f35 53e0 |...!....?.o.o5S.| [...] 8173 hastd 1306344078.732850 RET sendto 26752/0x6880 8173 hastd 1306344078.732864 CALL _umtx_op(0x801223220,0x9,0,0,0) 8173 hastd 1306344078.732870 RET _umtx_op 0 8173 hastd 1306344078.732875 CALL clock_gettime(0x4,0x7fffff3faf10) 8173 hastd 1306344078.732878 RET clock_gettime 0 8173 hastd 1306344078.732882 CALL clock_gettime(0x4,0x7fffff3faea0) 8173 hastd 1306344078.732885 RET clock_gettime 0 8173 hastd 1306344078.732887 CALL _umtx_op(0x8012231e0,0x8,0x1,0x8012231c0,0x7fffff3fae90) 8173 hastd 1306344078.732893 RET _umtx_op 0 8173 hastd 1306344078.732899 CALL recvfrom(0x7,0x7fffff1f9f30,0x5,MSG_WAITALL,0,0) 8173 hastd 1306344079.641192 RET ioctl 0 8173 hastd 1306344079.641354 CALL pwrite(0x4,0x8012b8000,0x7800,0x1000) 8173 hastd 1306344079.641376 GIO fd 4 wrote 4096 bytes 0x0000 feff efff f36f eb66 c585 1b00 b038 0119 2d62 8006 d418 dcfa d73c fd73 2630 4dd2 d699 |.....o.f.....8..-b.......<.s&0M...| 0x0022 f751 f69e e1af d97c fd00 2010 0856 0200 0d00 0002 2000 0820 8252 7002 4400 42c8 0259 |.Q.....|.. ..V...... .. .Rp.D.B..Y| 0x0044 0040 2610 c940 601b 7043 1000 0402 240c 8060 00d0 0900 802f 2512 0000 23ad 410c 003a |.@&..@`.pC....$..`...../%...#.A..:| 0x0066 a002 0000 1801 0001 008a 3150 8000 0000 1008 0002 4062 8000 0401 1000 8030 caa8 2801 |..........1P........@b.......0..(.| --------------070703080106020807050502--