Re: Upgrade from 7.0.2 to 8.0_BETA: some trouble with sockets (I think)

[BERTRAND Joël <joel.bertrand%systella.fr@localhost>]

Manuel Bouyer a écrit :
> On Mon, Jul 03, 2017 at 11:25:38AM +0200, BERTRAND Joël wrote:
> > Manuel Bouyer a écrit :
> > > On Sun, Jul 02, 2017 at 03:55:39PM +0200, BERTRAND Joël wrote:
> > > > > Can you ktrace the mysql daemon while doint this ?
> > > > > Eventually match the tcpdump timestamps with the kdump one, to see
> > > > > exaclty
> > > > > what cause the socket to be closed, and what is happening before.
> > > >
> > > > I have ktrace'd mysqld process before posting here (only when I try to open
> > > > a new connection from client). I paste an extraction of this file :
> > >
> > > Are you sure you got all the related informations ?
> > > this is where mayching timestamps from tcpdump with timestamps from
> > > kdump -T would help
> >
> > 	Very strange :
> >
> > On client side (linux box, amd64):
> > $  mysql -uzmuser -p -hlegendre
> > Enter password:
> > ERROR 2013 (HY000): Lost connection to MySQL server at 'reading initial
> > communication packet', system error: 104 "Connection reset by peer"
> >
> > On server side:
> > legendre# tcpdump -tt -i agr0 port 3306
> > tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
> > listening on agr0, link-type EN10MB (Ethernet), capture size 262144 bytes
> > 1499073569.026306 IP 192.168.10.103.59532 > 192.168.10.128.mysql: Flags [S],
> > seq 688000445, win 29200, options [mss 1460,sackOK,TS val 44791111 ecr
> > 0,nop,wscale 7], length 0
> > 1499073569.026337 IP 192.168.10.128.mysql > 192.168.10.103.59532: Flags
> > [S.], seq 2439021135, ack 688000446, win 32768, options [mss 1460,nop,wscale
> > 3,sackOK,TS val 1 ecr 44791111], length 0
> > 1499073569.026440 IP 192.168.10.103.59532 > 192.168.10.128.mysql: Flags [.],
> > ack 1, win 229, options [nop,nop,TS val 44791111 ecr 1], length 0
> > 1499073569.026473 IP 192.168.10.128.mysql > 192.168.10.103.59532: Flags [R],
> > seq 2439021136, win 0, length 0
> >
> > But kdump -T doesn't show any similar timestamp :
> >
> >  14288     13 mysqld   1499073568.381466253 RET   ___lwp_park60 -1 errno 60
> > Connection timed out
> >  14288     13 mysqld   1499073568.381469810 CALL
> > __gettimeofday50(0x79f65fdffe60,0)
> >  14288     13 mysqld   1499073568.381470435 RET   __gettimeofday50 0
> >  14288     13 mysqld   1499073568.381472191 CALL
> > ___lwp_park60(0,1,0x79f65fdffed0,0,0x79f663df2198,0x79f663df2198)
> >  14288     14 mysqld   1499073568.413143778 RET   ___lwp_park60 -1 errno 60
> > Connection timed out
> >  14288     14 mysqld   1499073568.413149847 CALL
> > __gettimeofday50(0x79f65f9feef0,0)
> >  14288     14 mysqld   1499073568.413150487 RET   __gettimeofday50 0
> >  14288     14 mysqld   1499073568.413175021 CALL
> > __gettimeofday50(0x79f65f9fee20,0)
> >  14288     14 mysqld   1499073568.413175827 RET   __gettimeofday50 0
> >  14288     14 mysqld   1499073568.413178033 CALL
> > ___lwp_park60(0,1,0x79f65f9fee90,0,0x79f688d17b98,0x79f688d17b98)
> >  14288     16 mysqld   1499073568.821865058 RET   __select50 0
> >  14288     16 mysqld   1499073568.821867715 CALL
> > __gettimeofday50(0x79f65f1fcf70,0)
> >  14288     16 mysqld   1499073568.821868385 RET   __gettimeofday50 0
> >  14288     16 mysqld   1499073568.821869736 CALL
> > __gettimeofday50(0x79f65f1fcf70,0)
> >  14288     16 mysqld   1499073568.821870302 RET   __gettimeofday50 0
> >  14288     16 mysqld   1499073568.821872158 CALL
> > __gettimeofday50(0x79f65f1fcf60,0)
> >  14288     16 mysqld   1499073568.821872793 RET   __gettimeofday50 0
> >  14288     16 mysqld   1499073568.821875340 CALL
> > __select50(0,0,0,0,0x79f65f1fcf70)
> >  14288     18 mysqld   1499073568.829767482 RET   __select50 0
> >  14288     18 mysqld   1499073568.829771034 CALL
> > __gettimeofday50(0x79f6607f5f10,0)
> >  14288     18 mysqld   1499073568.829771674 RET   __gettimeofday50 0
> >  14288     18 mysqld   1499073568.829774426 CALL
> > __gettimeofday50(0x79f6607f5f10,0)
> >
> > 	I don't understand... I suppose ktrace has to show socket activity.
>
> Assuming the socket queue isn't full (netstat -f inet would show this),
> does the mysqld listen on the address you're connecting to ?
> netstat -a -f inet will show this (or fstat).
>
> Another possibility is a packet filter which is sending the RST

legendre# netstat -a -f inet | grep mysql
legendre# netstat -a -f inet6 | grep mysql
tcp6       0      0  *.mysql                *.*                    LISTEN
legendre#

I don't understand why mysql doesn't listen on ipv4 anymore. 
Configuration was not modified between running configuration (NetBSD 
7.0.2) and faulty one.

I have check squid and I obtain :
legendre# fstat | grep squid | grep intern
squid    pinger     28605    0* internet6 dgram udp localhost:64928 <-> 
localhost:64929
squid    pinger     28605    1* internet6 dgram udp localhost:64928 <-> 
localhost:64929
squid    pinger     28605    3* internet raw icmp fffffe841b1dd1f8
squid    pinger     28605    4* internet6 raw icmp6 fffffe8411ba4000
squid    squid       6805    6* internet6 dgram udp *:64930
squid    squid       6805    8* internet dgram udp *:62672
squid    squid       6805   17* internet6 stream tcp *:ndl-aas
squid    squid       6805   19* internet6 dgram udp localhost:64929 <-> 
localhost:64928
legendre#

It listens on tcp6 and not on tcp !

	Of course, I've only upgrade NetBSD from a running configuration.

	Best regards,

	JKB