Project

General

Profile

Bug #28095

Monitor mdnsd and restart if necessary

Added by Caleb St. John over 1 year ago. Updated about 1 year ago.

Status:
Done
Priority:
Important
Assignee:
John Hixson
Category:
Middleware
Target version:
Seen in:
TrueNAS - TrueNAS 11.1-U2
Severity:
Low
Reason for Closing:
Reason for Blocked:
Needs QA:
No
Needs Doc:
No
Needs Merging:
No
Needs Automation:
No
Support Suite Ticket:
n/a
Hardware Configuration:
ChangeLog Required:
No

Related projects 1 project

Description

Seems like mdns is spamming /var/log/middlewared.log to the point a python traceback is occuring. This pollutes the middlewared.log file.

Below is the verbiage of the message:

[2018/01/31 19:05:19] (DEBUG) middlewared.debug():161 - ResolveThread: name=x20qa2._sftp._tcp.local. flags=0x00000000 error=0
[2018/01/31 19:05:19] (DEBUG) middlewared.debug():161 - ResolveThread: name=freejohn._sftp._tcp.local. flags=0x00000000 error=0
[2018/01/31 19:05:19] (DEBUG) middlewared.debug():161 - ResolveThread: name=x20qa1._sftp._tcp.local. flags=0x00000000 error=0
[2018/01/31 19:05:19] (DEBUG) middlewared.debug():161 - ResolveThread: name=fncertified._sftp._tcp.local. flags=0x00000000 error=0
[2018/01/31 19:05:19] (DEBUG) middlewared.debug():161 - ResolveThread: name=tn02-b._sftp._tcp.local. flags=0x00000000 error=0
[2018/01/31 19:05:19] (DEBUG) middlewared.debug():161 - ResolveThread: name=warp-b._sftp._tcp.local. flags=0x00000000 error=0
[2018/01/31 19:05:19] (DEBUG) middlewared.debug():161 - ResolveThread: name=mp18._middleware._tcp.local. flags=0x00000000 error=0
[2018/01/31 19:05:19] (DEBUG) middlewared.debug():161 - ResolveThread: name=truenas-b._middleware._tcp.local. flags=0x00000000 error=0
Exception in thread Thread-93:
Traceback (most recent call last):
File "/usr/local/lib/python3.6/threading.py", line 916, in _bootstrap_inner
self.run()
File "/usr/local/lib/python3.6/site-packages/middlewared/plugins/mdns.py", line 288, in run
pybonjour.DNSServiceProcessResult(ref)
File "/usr/local/lib/python3.6/site-packages/pybonjour.py", line 895, in DNSServiceProcessResult
_DNSServiceProcessResult(sdRef)
File "/usr/local/lib/python3.6/site-packages/pybonjour.py", line 286, in _errcheck
raise cls(result)
pybonjour.BonjourError: (-65541, 'bad reference')


Related issues

Copied to FreeNAS - Bug #40640: Monitor mdnsd and restart if necessaryDone

Associated revisions

Revision 2de2be95 (diff)
Added by John Hixson about 1 year ago

Monitor mdnsd and restart if necessary. Avoid tracebacks.

Ticket: #28095

Revision af841b71 (diff)
Added by John Hixson about 1 year ago

Monitor mdnsd and restart if necessary. Avoid tracebacks.

Ticket: #28095
(cherry picked from commit 2de2be9509681c64cf0710db8bf1261d3e98a58e)

Revision b07819c5 (diff)
Added by John Hixson 11 months ago

Monitor mdnsd and restart if necessary. Avoid tracebacks.

Ticket: #28095
(cherry picked from commit 2de2be9509681c64cf0710db8bf1261d3e98a58e)
(cherry picked from commit af841b7107d3de83da1f3c09ddd8826f5eff6694)

(11.1-stable)
Ticket: #40640

History

#1 Updated by Dru Lavigne over 1 year ago

  • Project changed from TrueNAS to FreeNAS
  • Category changed from Middleware to Middleware
  • Assignee changed from Ash Gokhale to Vladimir Vinogradenko
  • Target version set to 11.2-BETA1
  • Migration Needed deleted (No)
  • Hide from ChangeLog deleted (No)
  • Support Department Priority deleted (0)

#2 Updated by William Grzybowski over 1 year ago

  • Assignee changed from Vladimir Vinogradenko to John Hixson

John is all about MDNS, he wrote it ;)

#3 Updated by John Hixson over 1 year ago

Caleb St. John wrote:

Seems like mdns is spamming /var/log/middlewared.log to the point a python traceback is occuring. This pollutes the middlewared.log file.

Below is the verbiage of the message:

[2018/01/31 19:05:19] (DEBUG) middlewared.debug():161 - ResolveThread: name=x20qa2._sftp._tcp.local. flags=0x00000000 error=0
[2018/01/31 19:05:19] (DEBUG) middlewared.debug():161 - ResolveThread: name=freejohn._sftp._tcp.local. flags=0x00000000 error=0
[2018/01/31 19:05:19] (DEBUG) middlewared.debug():161 - ResolveThread: name=x20qa1._sftp._tcp.local. flags=0x00000000 error=0
[2018/01/31 19:05:19] (DEBUG) middlewared.debug():161 - ResolveThread: name=fncertified._sftp._tcp.local. flags=0x00000000 error=0
[2018/01/31 19:05:19] (DEBUG) middlewared.debug():161 - ResolveThread: name=tn02-b._sftp._tcp.local. flags=0x00000000 error=0
[2018/01/31 19:05:19] (DEBUG) middlewared.debug():161 - ResolveThread: name=warp-b._sftp._tcp.local. flags=0x00000000 error=0
[2018/01/31 19:05:19] (DEBUG) middlewared.debug():161 - ResolveThread: name=mp18._middleware._tcp.local. flags=0x00000000 error=0
[2018/01/31 19:05:19] (DEBUG) middlewared.debug():161 - ResolveThread: name=truenas-b._middleware._tcp.local. flags=0x00000000 error=0
Exception in thread Thread-93:
Traceback (most recent call last):
File "/usr/local/lib/python3.6/threading.py", line 916, in _bootstrap_inner
self.run()
File "/usr/local/lib/python3.6/site-packages/middlewared/plugins/mdns.py", line 288, in run
pybonjour.DNSServiceProcessResult(ref)
File "/usr/local/lib/python3.6/site-packages/pybonjour.py", line 895, in DNSServiceProcessResult
_DNSServiceProcessResult(sdRef)
File "/usr/local/lib/python3.6/site-packages/pybonjour.py", line 286, in _errcheck
raise cls(result)
pybonjour.BonjourError: (-65541, 'bad reference')

Normally the log is only "spammed" on start, and periodically as new devices arrive on the network. This traceback needs to be fixed, however I think there is another problem here. The "bad reference" error makes me think that mDNSResponder is not running. Are you able to reproduce this error at will? If you have a system in this state, I would like to see it.

#4 Avatar?id=13649&size=24x24 Updated by Ben Gadd over 1 year ago

  • Target version changed from 11.2-BETA1 to 11.2-RC2

#6 Updated by William Grzybowski over 1 year ago

  • Subject changed from (DEBUG) middlewared.debug():161 - ServiceThread spamming /var/log/middlewared.log to Middleware MDNS threads tracebacking

DEBUG spamming has been handled, update subject to reflect reality.

#7 Updated by John Hixson over 1 year ago

So we need to mdnsadvertise.restart whenever we restart mdnsd. I'm looking into this.

#9 Updated by Caleb St. John over 1 year ago

I only restarted mdnsd to show the tracebacks that are generated.

As we discussed in person, these tracebacks are happening on boot.

Steps that I did to reproduce are:

1. create afp share
2. set afp share service to start on boot
3. reboot and look at middlewared.log

#10 Updated by John Hixson about 1 year ago

  • Severity set to Low

#11 Updated by John Hixson about 1 year ago

I'm working on a fix for this.

#13 Updated by John Hixson about 1 year ago

  • Status changed from Not Started to Ready for Testing

#14 Updated by Dru Lavigne about 1 year ago

  • Subject changed from Middleware MDNS threads tracebacking to Monitor mdnsd and restart if necessary
  • Status changed from Ready for Testing to In Progress
  • Target version changed from 11.2-RC2 to 11.2-BETA1

#15 Updated by John Hixson about 1 year ago

  • Status changed from In Progress to Done

#16 Updated by Dru Lavigne about 1 year ago

  • Status changed from Done to Ready for Testing
  • Needs Merging changed from Yes to No

#17 Updated by Bonnie Follweiler about 1 year ago

I'm testing this

#18 Updated by Bonnie Follweiler about 1 year ago

  • Status changed from Ready for Testing to Passed Testing
  • Needs QA changed from Yes to No

Passed Test in FreeNAS-11.2-INTERNAL2

#19 Updated by Dru Lavigne about 1 year ago

  • Status changed from Passed Testing to Done

#20 Updated by John Hixson 11 months ago

  • Copied to Bug #40640: Monitor mdnsd and restart if necessary added

Also available in: Atom PDF