Opened 9 years ago

Closed 7 years ago

Last modified 6 years ago

#12498 closed Bug Report - General (Fixed)

slave BE not trying all resolved IP addresses when connecting to master BE

Reported by: brian@… Owned by: Peter Bennett
Priority: critical Milestone: 29.0
Component: MythTV - General Version: 0.27.4
Severity: medium Keywords:
Cc: Ticket locked: no

Description

My master back end is available on multiple IP addresses:

# netstat -apn | grep :6543
tcp        0      0 10.75.22.2:6543         0.0.0.0:*               LISTEN      29001/mythbackend
tcp        0      0 127.0.0.1:6543          0.0.0.0:*               LISTEN      29001/mythbackend
tcp6       0      0 fe80::111:2222:333:6543 :::*                    LISTEN      29001/mythbackend
tcp6       0      0 fd31:aeb1:48df:0:1:6543 :::*                    LISTEN      29001/mythbackend
tcp6       0      0 ::1:6543                :::*                    LISTEN      29001/mythbackend

But not all of the addresses available on the machine (for some unknown reason). The addresses for the master BE are:

pvr.example.com has IPv6 address 2002:43c1:d5d3:0:111:2222:333:444
pvr.example.com has IPv6 address 2001:470:1d:6f8:111:2222:333:444
pvr.example.com has IPv6 address fd31:aeb1:48df:0:111:2222:333:444

But not listening on all addresses is perfectly fine, or at least it should be. But in practice, due to a defect in the MythTV socket code, it's not:

# su - mythtv -c "mythjobqueue -v all"
2015-08-27 06:34:57.051084 C  mythjobqueue version: fixes/0.27 [v0.27.4-64-g8fd277b] www.mythtv.org
2015-08-27 06:34:57.051090 C  Qt version: compile: 4.8.6, runtime: 4.8.6
2015-08-27 06:34:57.051092 N  Enabled verbose msgs: all
2015-08-27 06:34:57.051097 N  Setting Log Level to LOG_INFO
2015-08-27 06:34:57.061488 I  Added logging to the console
2015-08-27 06:34:57.061756 I  Setup Interrupt handler
2015-08-27 06:34:57.061762 I  Setup Terminated handler
2015-08-27 06:34:57.061765 I  Setup Segmentation fault handler
2015-08-27 06:34:57.061770 I  Setup Aborted handler
2015-08-27 06:34:57.061772 I  Setup Bus error handler
2015-08-27 06:34:57.061776 I  Setup Floating point exception handler
2015-08-27 06:34:57.061781 I  Setup Illegal instruction handler
2015-08-27 06:34:57.061785 I  Setup Real-time signal 0 handler
2015-08-27 06:34:57.061811 N  Using runtime prefix = /usr
2015-08-27 06:34:57.061819 N  Using configuration directory = /home/mythtv/.mythtv
2015-08-27 06:34:57.061859 I  Assumed character encoding: en_US.UTF-8
2015-08-27 06:34:57.062000 N  Empty LocalHostName.
2015-08-27 06:34:57.062002 I  Using localhost value of pc.example.com
2015-08-27 06:34:57.062007 I  Clearing Settings Cache.
2015-08-27 06:34:57.062016 I  DefaultUPnP() - No default UPnP backend
2015-08-27 06:34:57.062020 I  Testing network connectivity to 'pvr'
2015-08-27 06:34:57.062353 I  Starting process signal handler
2015-08-27 06:34:57.063224 I  Managed child (PID: 12661) has started! * command=ping -t 3 -c 1  pvr  >/dev/null 2>&1, timeout=0
2015-08-27 06:34:57.063288 I  Starting IO manager (read)
2015-08-27 06:34:57.063335 I  Starting process manager
2015-08-27 06:34:57.063392 I  Starting IO manager (write)
2015-08-27 06:34:57.063251 I  (0x1c37380)::IncrRef() -> 2
2015-08-27 06:34:57.161936 I  New Client:  (#1)
2015-08-27 06:34:57.163416 I  Managed child (PID: 12661) has exited! command=ping -t 3 -c 1  pvr  >/dev/null 2>&1, status=0, result=0
2015-08-27 06:34:57.212592 I  (0x1c37380)::DecrRef() -> 1
2015-08-27 06:34:57.212611 I  (0x1c37380)::DecrRef() -> 0
2015-08-27 06:34:57.212640 I  Clearing Settings Cache.
2015-08-27 06:34:57.216674 I  Database connection created: DBManager0
2015-08-27 06:34:57.216684 I  New DB connection, total: 1
2015-08-27 06:34:57.220538 I  Connected to database 'mythconverg' at host: pvr
2015-08-27 06:34:57.225263 I  Closing DB connection named 'DBManager0'
2015-08-27 06:34:57.225329 I  Clearing Settings Cache.
2015-08-27 06:34:57.225366 I  Database connection created: DBManager1
2015-08-27 06:34:57.225370 I  New DB connection, total: 1
2015-08-27 06:34:57.227330 I  Connected to database 'mythconverg' at host: pvr
2015-08-27 06:34:57.230324 N  Setting QT default locale to en_CA
2015-08-27 06:34:57.230415 I  Current locale en_CA
2015-08-27 06:34:57.230441 N  Reading locale defaults from /usr/share/mythtv//locales/en_ca.xml
2015-08-27 06:34:57.257371 I  Enabling Settings Cache.
2015-08-27 06:34:57.257377 I  Clearing Settings Cache.
2015-08-27 06:34:57.274465 I  MythCoreContext: Connecting to backend server: 2001:470:1D:6F8:111:2222:333:444:6543 (try 1 of 5)
2015-08-27 06:34:57.274503 I  MythSocket(1c6c260:-1): MythSocket(-1, 0x0) ctor
2015-08-27 06:34:57.275155 I  MythSocket(1c6c260:-1): attempting connect() to (2001:470:1D:6F8:111:2222:333:444:6543)
2015-08-27 06:34:57.275678 E  MythSocket(1c6c260:-1): Failed to connect to (2001:470:1D:6F8:111:2222:333:444:6543) Connection refused
2015-08-27 06:34:57.276563 I  Managed child (PID: 12664) has started! * command=/usr/bin/wakeonlan -i 10.75.22.255 00:11:22:33:44:55, timeout=0
2015-08-27 06:34:57.276590 I  (0x1c86d90)::IncrRef() -> 2
2015-08-27 06:34:57.363604 I  Managed child (PID: 12664) has exited! command=/usr/bin/wakeonlan -i 10.75.22.255 00:11:22:33:44:55, status=32512, result=127
2015-08-27 06:34:57.413024 I  (0x1c86d90)::DecrRef() -> 1
2015-08-27 06:34:57.413039 I  (0x1c86d90)::DecrRef() -> 0
2015-08-27 06:34:57.413051 I  (0x1c6c270)::DecrRef() -> 0
2015-08-27 06:34:57.413058 I  MythSocket(1c6c260:-1): MythSocket dtor : cb 0x0
2015-08-27 06:35:07.414213 I  MythCoreContext: Connecting to backend server: 2001:470:1D:6F8:111:2222:333:444:6543 (try 2 of 5)
2015-08-27 06:35:07.414230 I  MythSocket(1c1c870:-1): MythSocket(-1, 0x0) ctor
2015-08-27 06:35:07.414925 I  MythSocket(1c1c870:-1): attempting connect() to (2001:470:1D:6F8:111:2222:333:444:6543)
2015-08-27 06:35:07.415288 E  MythSocket(1c1c870:-1): Failed to connect to (2001:470:1D:6F8:111:2222:333:444:6543) Connection refused
2015-08-27 06:35:07.417275 I  Managed child (PID: 12694) has started! * command=/usr/bin/wakeonlan -i 10.75.22.255 00:11:22:33:44:55, timeout=0
2015-08-27 06:35:07.417301 I  (0x1c97d70)::IncrRef() -> 2
2015-08-27 06:35:07.472028 I  Managed child (PID: 12694) has exited! command=/usr/bin/wakeonlan -i 10.75.22.255 00:11:22:33:44:55, status=32512, result=127
2015-08-27 06:35:07.484230 I  (0x1c97d70)::DecrRef() -> 1
2015-08-27 06:35:07.484252 I  (0x1c97d70)::DecrRef() -> 0
2015-08-27 06:35:07.484266 I  (0x1c1c880)::DecrRef() -> 0
2015-08-27 06:35:07.484272 I  MythSocket(1c1c870:-1): MythSocket dtor : cb 0x0
2015-08-27 06:35:17.484503 I  MythCoreContext: Connecting to backend server: 2001:470:1D:6F8:111:2222:333:444:6543 (try 3 of 5)
2015-08-27 06:35:17.484519 I  MythSocket(1c86d00:-1): MythSocket(-1, 0x0) ctor
2015-08-27 06:35:17.485169 I  MythSocket(1c86d00:-1): attempting connect() to (2001:470:1D:6F8:111:2222:333:444:6543)
2015-08-27 06:35:17.485675 E  MythSocket(1c86d00:-1): Failed to connect to (2001:470:1D:6F8:111:2222:333:444:6543) Connection refused
2015-08-27 06:35:17.486613 I  Managed child (PID: 12702) has started! * command=/usr/bin/wakeonlan -i 10.75.22.255 00:11:22:33:44:55, timeout=0
2015-08-27 06:35:17.486655 I  (0x1c6c3b0)::IncrRef() -> 2
2015-08-27 06:35:17.580508 I  Managed child (PID: 12702) has exited! command=/usr/bin/wakeonlan -i 10.75.22.255 00:11:22:33:44:55, status=32512, result=127
2015-08-27 06:35:17.602071 I  (0x1c6c3b0)::DecrRef() -> 1
2015-08-27 06:35:17.602085 I  (0x1c6c3b0)::DecrRef() -> 0
2015-08-27 06:35:17.602098 I  (0x1c86d10)::DecrRef() -> 0
2015-08-27 06:35:17.602104 I  MythSocket(1c86d00:-1): MythSocket dtor : cb 0x0
2015-08-27 06:35:27.602324 I  MythCoreContext: Connecting to backend server: 2001:470:1D:6F8:111:2222:333:444:6543 (try 4 of 5)
2015-08-27 06:35:27.602339 I  MythSocket(1c6c370:-1): MythSocket(-1, 0x0) ctor
2015-08-27 06:35:27.602928 I  MythSocket(1c6c370:-1): attempting connect() to (2001:470:1D:6F8:111:2222:333:444:6543)
2015-08-27 06:35:27.603422 E  MythSocket(1c6c370:-1): Failed to connect to (2001:470:1D:6F8:111:2222:333:444:6543) Connection refused
2015-08-27 06:35:27.604313 I  Managed child (PID: 12708) has started! * command=/usr/bin/wakeonlan -i 10.75.22.255 00:11:22:33:44:55, timeout=0
2015-08-27 06:35:27.604335 I  (0x1c94960)::IncrRef() -> 2
2015-08-27 06:35:27.688905 I  Managed child (PID: 12708) has exited! command=/usr/bin/wakeonlan -i 10.75.22.255 00:11:22:33:44:55, status=32512, result=127
2015-08-27 06:35:27.718875 I  (0x1c94960)::DecrRef() -> 1
2015-08-27 06:35:27.718894 I  (0x1c94960)::DecrRef() -> 0
2015-08-27 06:35:27.718907 I  (0x1c6c380)::DecrRef() -> 0
2015-08-27 06:35:27.718914 I  MythSocket(1c6c370:-1): MythSocket dtor : cb 0x0
2015-08-27 06:35:37.719196 I  MythCoreContext: Connecting to backend server: 2001:470:1D:6F8:111:2222:333:444:6543 (try 5 of 5)
2015-08-27 06:35:37.719212 I  MythSocket(1c961b0:-1): MythSocket(-1, 0x0) ctor
2015-08-27 06:35:37.719798 I  MythSocket(1c961b0:-1): attempting connect() to (2001:470:1D:6F8:111:2222:333:444:6543)
2015-08-27 06:35:37.720206 E  MythSocket(1c961b0:-1): Failed to connect to (2001:470:1D:6F8:111:2222:333:444:6543) Connection refused
2015-08-27 06:35:37.720244 I  (0x1c961c0)::DecrRef() -> 0
2015-08-27 06:35:37.720250 I  MythSocket(1c961b0:-1): MythSocket dtor : cb 0x0
2015-08-27 06:35:37.720360 E  Connection to master server timed out.
			Either the server is down or the master server settings
			in mythtv-settings does not contain the proper IP address

2015-08-27 06:35:37.720365 E  MythJobQueue: Failed to connect to master server

As you can see, the socket creation code is not cycling through the available IP addresses that a name resolves to like it is supposed to.

Any code which resolves an IP address from a name should try to use all IP addresses the name resolves to when attempting to make a socket connection.

Change History (6)

comment:1 Changed 7 years ago by Peter Bennett

Owner: set to Peter Bennett
Status: newassigned

comment:2 Changed 7 years ago by Peter Bennett

Status: assignedinfoneeded

Sorry for the long delay in looking at this. Can you tell me how the backends are set up in mythtv-setup, first screen

  • Master backend setup page
    • local backend
      • ipv6 address xxxx
    • master backend
      • ip address yyyy
  • Slave backend setup page
    • local backend
      • ipv6 address zzzz
    • master backend
      • ip address yyyy

In this scenario, xxxx yyyy and zzzz must be IPV6 addresses. ALso xxxx must be exactly equal to yyyy.

Master backend should be listening on ipv6 address xxxx (=yyyy). Slave backend should be trying to connect to ipv6 address xxxx (=yyyy).

Please let me know what values you have for the various IPV6 addresses xxxx, yyyy and zzzz.

comment:3 Changed 7 years ago by brian@…

I'm afraid I don't actually have any slave backends any more.

comment:4 Changed 7 years ago by Peter Bennett

Milestone: unknown29.0
Status: infoneededassigned

In will look into adding a setup option for "listen on all IP addresses". That should solve this problem as well as the problem of backend starting up before all interfaces are active.

comment:5 Changed 7 years ago by Peter Bennett

Resolution: Fixed
Status: assignedclosed

This is fixed as part of fixes for ticket #13024

comment:6 Changed 6 years ago by Peter Bennett

Owner: changed from Peter Bennett to Peter Bennett
Note: See TracTickets for help on using tickets.