masakari-api failed to launch due to setting of watch_log_file and log_file

Bug #1740111 reported by takahara.kengo
8
This bug affects 1 person
Affects Status Importance Assigned to Milestone
masakari
Invalid
Undecided
Unassigned
oslo.log
Confirmed
Medium
Unassigned

Bug Description

I added the following settings to /etc/masakari/masakari.conf.
--
log_file = /var/log/masakari/masakari.log
watch_log_file = true
--

And then I failed to launch masakari-api with above settings.
Masakari-api output error logs as follows:

$ masakari-api
Config option database.idle_timeout is deprecated. Use option database.connection_recycle_time instead.
Traceback (most recent call last):
  File "/usr/local/bin/masakari-api", line 10, in <module>
    sys.exit(main())
  File "/usr/local/lib/python2.7/dist-packages/masakari/cmd/api.py", line 37, in main
    logging.setup(CONF, "masakari")
  File "/usr/local/lib/python2.7/dist-packages/oslo_log/log.py", line 264, in setup
    _setup_logging_from_conf(conf, product_name, version)
  File "/usr/local/lib/python2.7/dist-packages/oslo_log/log.py", line 353, in _setup_logging_from_conf
    filelog = file_handler(logpath)
  File "/usr/local/lib/python2.7/dist-packages/oslo_log/watchers.py", line 75, in __init__
    self._watch_file()
  File "/usr/local/lib/python2.7/dist-packages/oslo_log/watchers.py", line 86, in _watch_file
    timeout=FastWatchedFileHandler.TIMEOUT)
  File "/usr/local/lib/python2.7/dist-packages/pyinotify.py", line 1461, in __init__
    threshold, timeout)
  File "/usr/local/lib/python2.7/dist-packages/pyinotify.py", line 1138, in __init__
    self._pollobj = select.poll()
AttributeError: 'module' object has no attribute 'poll'
$

[Impact on other projects]
watch_log_file and log_file are configuration options of oslo.log.
So I tried to set same options for nova-compute.
As a result, same issue occurred in the nova-compute process.

There is a possibility that this issue affects all openstack projects using oslo.log.

[Caus of bug]
I think the root cause of this isse is the following bug of pyinotify.
pyinotify is used by oslo.log.
But this pull requests is not merged yet.
https://github.com/seb-m/pyinotify/pull/117

Revision history for this message
Rikimaru Honjo (honjo-rikimaru-c6) wrote :

"watch_log_file" is a configuration value of oslo.log.
So I added oslo.log to affects project.

description: updated
Revision history for this message
takahara.kengo (takahara.kengo) wrote :

Additional Infomation:
I could launch masakari-api and nova-compute after applying the patch[1] to my environment.
[1]: https://github.com/seb-m/pyinotify/pull/117/files

description: updated
Revision history for this message
Rikimaru Honjo (honjo-rikimaru-c6) wrote :

I sent a mail about this issue to openstack-dev ML.
As a result, Doug Hellmann replied to me and presented the policy to fix.
(Thanks!)

http://lists.openstack.org/pipermail/openstack-dev/2018-January/125966.html

Changed in oslo.log:
status: New → Triaged
importance: Undecided → Medium
Revision history for this message
Rikimaru Honjo (honjo-rikimaru-c6) wrote :

I tried to replace pyinotfy to inotify according to the discussion with Doug.
But, the same error was occurred.

I confirmed issues of inotify.
As a result, I found the report about same error.
https://github.com/dsoprea/PyInotify/issues/36 [1]

The above issue page said that epol is Linux only.
But, I was using Linux...
I'm asking about it on the above issue page.

[1]
The repository name is "PyInotify", but inotify's repository is this.
Please show the below page.
https://pypi.python.org/pypi/inotify/0.2.9

Revision history for this message
Takashi Kajinami (kajinamit) wrote :

I can still reproduce the problem with the latest version.

```
Traceback (most recent call last):
 File "/usr/bin/nova-scheduler", line 8, in <module>
   sys.exit(main())
 File "/usr/lib/python3.9/site-packages/nova/cmd/scheduler.py", line 40, in main
   logging.setup(CONF, "nova")
 File "/usr/lib/python3.9/site-packages/oslo_log/log.py", line 291, in setup
   _setup_logging_from_conf(conf, product_name, version)
 File "/usr/lib/python3.9/site-packages/oslo_log/log.py", line 378, in _setup_logging_from_conf
   filelog = file_handler(logpath)
 File "/usr/lib/python3.9/site-packages/oslo_log/watchers.py", line 75, in __init__
   self._watch_file()
 File "/usr/lib/python3.9/site-packages/oslo_log/watchers.py", line 82, in _watch_file
   notifier = _EventletThreadedNotifier(
 File "/usr/lib/python3.9/site-packages/pyinotify.py", line 1446, in __init__
   Notifier.__init__(self, watch_manager, default_proc_fun, read_freq,
 File "/usr/lib/python3.9/site-packages/pyinotify.py", line 1124, in __init__
   self._pollobj = select.poll()
AttributeError: module 'select' has no attribute 'poll'
```

Revision history for this message
Takashi Kajinami (kajinamit) wrote :

pyinotify hasn't been updated for 9 years https://github.com/seb-m/pyinotify
inotify hasn't been updated for 4 years https://github.com/dsoprea/PyInotify

So I doublt replacing pyinotify by inotify can be benefitial here, because we just pull another debt.

Probably it makes better sense to deprecate the feature, because no one has argued the broken feature for very long time.

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Related fix proposed to oslo.log (master)

Related fix proposed to branch: master
Review: https://review.opendev.org/c/openstack/oslo.log/+/914788

Changed in oslo.log:
status: Triaged → Confirmed
Changed in masakari:
status: New → Invalid
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Related fix merged to oslo.log (master)

Reviewed: https://review.opendev.org/c/openstack/oslo.log/+/914788
Committed: https://opendev.org/openstack/oslo.log/commit/31603ac6dacd0b47ec9f02d99bfdd0a7b683119c
Submitter: "Zuul (22348)"
Branch: master

commit 31603ac6dacd0b47ec9f02d99bfdd0a7b683119c
Author: Takashi Kajinami <email address hidden>
Date: Sun Mar 31 00:54:59 2024 +0900

    Deprecate watch_log_file

    This feature has been broken for some time without any actual update
    to fix it. Also the pyinotify package used hasn't been updated for 9
    years and looks badly unmaintained.

    Related-Bug: #1740111
    Related-Bug: #2059855
    Change-Id: If776fee0072d95737e1c19ad673a3c881a89de06

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Related fix proposed to oslo.log (stable/2024.1)

Related fix proposed to branch: stable/2024.1
Review: https://review.opendev.org/c/openstack/oslo.log/+/914880

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Change abandoned on oslo.log (stable/2024.1)

Change abandoned by "Takashi Kajinami <email address hidden>" on branch: stable/2024.1
Review: https://review.opendev.org/c/openstack/oslo.log/+/914880
Reason: https://review.opendev.org/c/openstack/oslo.log/+/915068 would be a better way forward.

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Related fix merged to oslo.log (master)

Reviewed: https://review.opendev.org/c/openstack/oslo.log/+/915068
Committed: https://opendev.org/openstack/oslo.log/commit/b977cb9becbeaaa67bb663bd8db5aa6846e495b9
Submitter: "Zuul (22348)"
Branch: master

commit b977cb9becbeaaa67bb663bd8db5aa6846e495b9
Author: Takashi Kajinami <email address hidden>
Date: Thu Apr 4 23:08:05 2024 +0900

    Remove implementation for watch_log_file

    ... and raise an exception when the feature is explicitly requested.

    The feature has been broken for some time, and depends on pyinotify
    library which has been unmaintained for long time and is not compatible
    with python 3.12 (because it uses asyncore).

    Related-Bug: #1740111
    Closes-Bug: #2059855
    Change-Id: I209b1260ed4de64cbfc561a1da81a66f7a5ea397

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.