Project

General

Profile

Actions
Copy link

Bug #54086

closed

Permission denied when trying to unlink and open /var/log/ntpstats/...

Added by Laura Flores about 2 years ago. Updated almost 2 years ago.

Status:
Duplicate
Priority:
Normal
Assignee:
Aishwarya Mathuria
Category:
-
% Done:

0%

Source:
Tags:
Backport:
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Crash signature (v1):
Crash signature (v2):

Description

We haven't experienced this issue on past runs because ntp.service never loaded in the first place:

Sample good runs:
/a/yuriw-2022-01-28_16:09:05-rados-wip-master-1.27.22-distro-default-smithi/6646655
/a/yuriw-2022-01-21_19:17:29-rados-wip-yuri2-testing-2022-01-21-0949-pacific-distro-default-smithi/6632651/

2022-01-28T21:37:36.568 DEBUG:teuthology.orchestra.run.smithi185:> sudo systemctl stop ntp.service || sudo systemctl stop ntpd.service || sudo systemctl stop chronyd.service ; sudo ntpd -gq || sudo chronyc makestep ; sudo systemctl start ntp.service || sudo systemctl start ntpd.service || sudo systemctl start chronyd.service ; PATH=/usr/bin:/usr/sbin ntpq -p || PATH=/usr/bin:/usr/sbin chronyc sources || true
2022-01-28T21:37:36.595 INFO:teuthology.orchestra.run.smithi084.stderr:Failed to stop ntp.service: Unit ntp.service not loaded.

Now, we are loading ntp.service, but this leads to permission problems:

Sample bad run:
/a/yuriw-2022-01-27_14:57:16-rados-wip-yuri-testing-2022-01-26-1810-pacific-distro-default-smithi/6643389

022-01-27T15:30:35.980 DEBUG:teuthology.orchestra.run.smithi164:> sudo systemctl stop ntp.service || sudo systemctl stop ntpd.service || sudo systemctl stop chronyd.service ; sudo ntpd -gq || sudo chronyc makestep ; sudo systemctl start ntp.service || sudo systemctl start ntpd.service || sudo systemctl start chronyd.service ; PATH=/usr/bin:/usr/sbin ntpq -p || PATH=/usr/bin:/usr/sbin chronyc sources || true
2022-01-27T15:30:35.983 INFO:teuthology.orchestra.run:Running command with timeout 360
2022-01-27T15:30:35.984 DEBUG:teuthology.orchestra.run.smithi189:> sudo systemctl stop ntp.service || sudo systemctl stop ntpd.service || sudo systemctl stop chronyd.service ; sudo ntpd -gq || sudo chronyc makestep ; sudo systemctl start ntp.service || sudo systemctl start ntpd.service || sudo systemctl start chronyd.service ; PATH=/usr/bin:/usr/sbin ntpq -p || PATH=/usr/bin:/usr/sbin chronyc sources || true
2022-01-27T15:30:36.013 INFO:teuthology.orchestra.run.smithi164.stdout:27 Jan 15:30:36 ntpd[9926]: ntpd 4.2.8p12@1.3728-o (1): Starting
2022-01-27T15:30:36.014 INFO:teuthology.orchestra.run.smithi164.stdout:27 Jan 15:30:36 ntpd[9926]: Command line: ntpd -gq

2022-01-27T15:30:36.026 INFO:teuthology.orchestra.run.smithi189.stdout:27 Jan 15:30:36 ntpd[9833]: Listen normally on 5 enp3s0f1 [fe80::ec4:7aff:fe88:6df1%5]:123
2022-01-27T15:30:36.026 INFO:teuthology.orchestra.run.smithi189.stdout:27 Jan 15:30:36 ntpd[9833]: Listening on routing socket on fd #22 for interface updates
2022-01-27T15:30:37.016 INFO:teuthology.orchestra.run.smithi164.stderr:27 Jan 15:30:37 ntpd[9926]: couldn't unlink /var/log/ntpstats/rawstats: Permission denied
2022-01-27T15:30:37.017 INFO:teuthology.orchestra.run.smithi164.stderr:27 Jan 15:30:37 ntpd[9926]: can't open /var/log/ntpstats/rawstats.20220127: Permission denied
2022-01-27T15:30:37.017 INFO:teuthology.orchestra.run.smithi164.stderr:27 Jan 15:30:37 ntpd[9926]: couldn't unlink /var/log/ntpstats/rawstats: Permission denied

"Permission denied" errors continue on various directories...

2022-01-27T15:30:43.024 INFO:teuthology.orchestra.run.smithi189.stderr:27 Jan 15:30:43 ntpd[9833]: couldn't unlink /var/log/ntpstats/peerstats: Permission denied
2022-01-27T15:30:43.024 INFO:teuthology.orchestra.run.smithi189.stderr:27 Jan 15:30:43 ntpd[9833]: can't open /var/log/ntpstats/peerstats.20220127: Permission denied
2022-01-27T15:30:43.024 INFO:teuthology.orchestra.run.smithi189.stdout:27 Jan 15:30:43 ntpd[9833]: ntpd: time slew +0.008085 s
2022-01-27T15:30:43.025 INFO:teuthology.orchestra.run.smithi189.stdout:ntpd: time slew +0.008085s
2022-01-27T15:30:43.025 INFO:teuthology.orchestra.run.smithi189.stderr:27 Jan 15:30:43 ntpd[9833]: couldn't unlink /var/log/ntpstats/loopstats: Permission denied
2022-01-27T15:30:43.026 INFO:teuthology.orchestra.run.smithi189.stderr:27 Jan 15:30:43 ntpd[9833]: can't open /var/log/ntpstats/loopstats.20220127: Permission denied
2022-01-27T15:30:43.089 INFO:teuthology.orchestra.run.smithi189.stdout:     remote           refid      st t when poll reach   delay   offset  jitter
2022-01-27T15:30:43.089 INFO:teuthology.orchestra.run.smithi189.stdout:==============================================================================
2022-01-27T15:30:43.089 INFO:teuthology.orchestra.run.smithi189.stdout: hv01.front.sepi .INIT.          16 u    -   64    0    0.000    0.000   0.000
2022-01-27T15:30:43.090 INFO:teuthology.orchestra.run.smithi189.stdout: hv02.front.sepi .INIT.          16 u    -   64    0    0.000    0.000   0.000
2022-01-27T15:30:43.090 INFO:teuthology.orchestra.run.smithi189.stdout: hv03.front.sepi .INIT.          16 u    -   64    0    0.000    0.000   0.000
2022-01-27T15:30:43.090 INFO:teuthology.orchestra.run.smithi189.stdout: hv04.front.sepi .INIT.          16 u    -   64    0    0.000    0.000   0.000
2022-01-27T15:30:43.104 INFO:teuthology.orchestra.run.smithi164.stdout:     remote           refid      st t when poll reach   delay   offset  jitter
2022-01-27T15:30:43.104 INFO:teuthology.orchestra.run.smithi164.stdout:==============================================================================
2022-01-27T15:30:43.105 INFO:teuthology.orchestra.run.smithi164.stdout: hv01.front.sepi .INIT.          16 u    -   64    0    0.000    0.000   0.000
2022-01-27T15:30:43.105 INFO:teuthology.orchestra.run.smithi164.stdout: hv02.front.sepi .INIT.          16 u    -   64    0    0.000    0.000   0.000
2022-01-27T15:30:43.105 INFO:teuthology.orchestra.run.smithi164.stdout: hv03.front.sepi .INIT.          16 u    -   64    0    0.000    0.000   0.000
2022-01-27T15:30:43.105 INFO:teuthology.orchestra.run.smithi164.stdout: hv04.front.sepi .INIT.          16 u    -   64    0    0.000    0.000   0.000

Related issues 1 (0 open — 1 closed)

Is duplicate of Dashboard - Bug #54992: pacific: rados/dashboard: tasks/dashboard: cannot stat '/etc/containers/registries.conf': No such file or directoryResolvedLaura Flores

Actions
Actions
Copy link
 #1

Updated by Laura Flores about 2 years ago

/a/yuriw-2022-01-31_16:18:27-rados-wip-yuri-testing-2022-01-26-1810-pacific-distro-default-smithi/6651077

Actions
Copy link
 #3

Updated by Laura Flores about 2 years ago

Seems like it could be an Ubuntu thing: https://serverfault.com/questions/1055736/ntpd-permission-denied-writing-to-var-log-ntpstats-statsdir-directory

The above "good run" examples are CentOS, while the "bad runs" are Ubuntu.

Actions
Copy link
 #4

Updated by Laura Flores about 2 years ago

Ubuntu does not support SELinux:

/a/yuriw-2022-01-27_14:57:16-rados-wip-yuri-testing-2022-01-26-1810-pacific-distro-default-smithi/6643389 -- bad run, Ubuntu

2022-01-27T15:27:09.664 DEBUG:teuthology.task:Applying overrides for task selinux: {'whitelist': ['scontext=system_u:system_r:logrotate_t:s0']}
2022-01-27T15:27:09.664 DEBUG:teuthology.task.selinux:Excluding smithi164: OS 'ubuntu' does not support SELinux
2022-01-27T15:27:09.664 DEBUG:teuthology.task.selinux:Excluding smithi189: OS 'ubuntu' does not support SELinux
2022-01-27T15:27:09.665 DEBUG:teuthology.task.selinux:Getting current SELinux state
2022-01-27T15:27:09.665 DEBUG:teuthology.task.selinux:Existing SELinux modes: {}
2022-01-27T15:27:09.665 INFO:teuthology.task.selinux:Putting SELinux into permissive mode

/a/yuriw-2022-01-28_16:09:05-rados-wip-master-1.27.22-distro-default-smithi/6646655 -- good run, CentOS

2022-01-28T21:32:47.500 DEBUG:teuthology.task:Applying overrides for task selinux: {'whitelist': ['scontext=system_u:system_r:logrotate_t:s0']}
2022-01-28T21:32:47.501 DEBUG:teuthology.orchestra.run.smithi084:> sudo service auditd rotate
2022-01-28T21:32:47.567 INFO:teuthology.orchestra.run.smithi084.stdout:Rotating logs: [  OK  ]
2022-01-28T21:32:47.569 DEBUG:teuthology.orchestra.run.smithi185:> sudo service auditd rotate
2022-01-28T21:32:47.641 INFO:teuthology.orchestra.run.smithi185.stdout:Rotating logs: [  OK  ]
2022-01-28T21:32:47.642 DEBUG:teuthology.task.selinux:Getting current SELinux state
2022-01-28T21:32:47.643 DEBUG:teuthology.orchestra.run.smithi084:> /usr/sbin/getenforce
2022-01-28T21:32:47.667 INFO:teuthology.orchestra.run.smithi084.stdout:Permissive
2022-01-28T21:32:47.667 DEBUG:teuthology.orchestra.run.smithi185:> /usr/sbin/getenforce
2022-01-28T21:32:47.704 INFO:teuthology.orchestra.run.smithi185.stdout:Permissive

SELinux is handled in the Teuthology repo, so I am changing this to a Teuthology issue.

Actions
Copy link
 #5

Updated by Laura Flores about 2 years ago

  • Project changed from Dashboard to teuthology
Actions
Copy link
 #6

Updated by Laura Flores about 2 years ago

Here, we exclude any non-RPM-based hosts: https://github.com/ceph/teuthology/blob/0f634dc1c0a64a93646e6d007882c69b3e1663e0/teuthology/task/selinux.py#L46-L66
This is why hosts running Ubuntu get excluded -- Ubuntu uses deb packages, while CentOS uses RPM.

Actions
Copy link
 #7

Updated by Laura Flores about 2 years ago

/a/yuriw-2022-02-06_16:04:09-rados-wip-yuri2-testing-2022-02-04-1646-pacific-distro-default-smithi/6665053

Actions
Copy link
 #8

Updated by Laura Flores about 2 years ago

Happening on master too.

/a/yuriw-2022-02-17_22:49:55-rados-wip-yuri3-testing-2022-02-17-1256-distro-default-smithi/6692100

2022-02-18T08:41:36.871 INFO:teuthology.run_tasks:Running task selinux...
2022-02-18T08:41:36.891 DEBUG:teuthology.task.selinux:Excluding smithi187: OS 'ubuntu' does not support SELinux
2022-02-18T08:41:36.892 DEBUG:teuthology.task.selinux:Getting current SELinux state
2022-02-18T08:41:36.892 DEBUG:teuthology.task.selinux:Existing SELinux modes: {}

Actions
Copy link
 #9

Updated by Laura Flores about 2 years ago

  • Subject changed from pacific: tasks/dashboard: Permission denied when trying to unlink and open /var/log/ntpstats/... to tasks/dashboard: Permission denied when trying to unlink and open /var/log/ntpstats/...
  • Backport set to quincy, pacific
Actions
Copy link
 #10

Updated by Laura Flores about 2 years ago

  • Subject changed from tasks/dashboard: Permission denied when trying to unlink and open /var/log/ntpstats/... to Permission denied when trying to unlink and open /var/log/ntpstats/...
Actions
Copy link
 #11

Updated by Laura Flores about 2 years ago

/a/yuriw-2022-02-17_22:49:55-rados-wip-yuri3-testing-2022-02-17-1256-distro-default-smithi/6691968

Actions
Copy link
 #12

Updated by Aishwarya Mathuria about 2 years ago

  • Assignee set to Aishwarya Mathuria
Actions
Copy link
 #13

Updated by Laura Flores about 2 years ago

This ended in an AnsibleFailedError, but the leadup to the Traceback is similar to what's documented in this Tracker:

/a/yuriw-2022-02-23_18:18:42-rados-wip-yuri-testing-2022-02-23-0827-distro-default-smithi/6703247

2022-02-23T22:49:17.241 INFO:teuthology.run_tasks:Running task selinux...
2022-02-23T22:49:17.316 DEBUG:teuthology.task.selinux:Excluding smithi018: OS 'ubuntu' does not support SELinux
2022-02-23T22:49:17.317 DEBUG:teuthology.task.selinux:Getting current SELinux state
2022-02-23T22:49:17.317 DEBUG:teuthology.task.selinux:Existing SELinux modes: {}
2022-02-23T22:49:17.318 INFO:teuthology.task.selinux:Putting SELinux into permissive mode
2022-02-23T22:49:17.318 INFO:teuthology.run_tasks:Running task ansible.cephlab...
2022-02-23T22:49:17.357 INFO:teuthology.repo_utils:/home/teuthworker/src/git.ceph.com_git_ceph-cm-ansible_master was just updated or references a specific commit; assuming it is current
2022-02-23T22:49:17.358 INFO:teuthology.repo_utils:Resetting repo at /home/teuthworker/src/git.ceph.com_git_ceph-cm-ansible_master to origin/master
2022-02-23T22:49:17.380 INFO:teuthology.task.ansible:Playbook: [{'import_playbook': 'ansible_managed.yml'}, {'import_playbook': 'teuthology.yml'}, {'hosts': 'testnodes', 'tasks': [{'set_fact': {'ran_from_cephlab_playbook': True}}]}, {'import_playbook': 'testnodes.yml'}, {'import_playbook': 'container-host.yml'}, {'import_playbook': 'cobbler.yml'}, {'import_playbook': 'paddles.yml'}, {'import_playbook': 'pulpito.yml'}, {'hosts': 'testnodes', 'become': True, 'tasks': [{'name': 'Touch /ceph-qa-ready', 'file': {'path': '/ceph-qa-ready', 'state': 'touch'}, 'when': 'ran_from_cephlab_playbook|bool'}]}]
2022-02-23T22:49:17.382 DEBUG:teuthology.task.ansible:Running ansible-playbook -v --extra-vars '{"ansible_ssh_user": "ubuntu"}' -i /etc/ansible/hosts --limit smithi018.front.sepia.ceph.com /home/teuthworker/src/git.ceph.com_git_ceph-cm-ansible_master/cephlab.yml
2022-02-23T22:52:48.456 INFO:teuthology.task.ansible:Archiving ansible failure log at: /home/teuthworker/archive/yuriw-2022-02-23_18:18:42-rados-wip-yuri-testing-2022-02-23-0827-distro-default-smithi/6703247/ansible_failures.yaml
2022-02-23T22:52:48.459 ERROR:teuthology.run_tasks:Saw exception from tasks.
Traceback (most recent call last):
  File "/home/teuthworker/src/git.ceph.com_git_teuthology_6b607b46862a6b148fb1608e09b31d367f094555/teuthology/run_tasks.py", line 94, in run_tasks
    manager.__enter__()
  File "/home/teuthworker/src/git.ceph.com_git_teuthology_6b607b46862a6b148fb1608e09b31d367f094555/teuthology/task/__init__.py", line 123, in __enter__
    self.begin()
  File "/home/teuthworker/src/git.ceph.com_git_teuthology_6b607b46862a6b148fb1608e09b31d367f094555/teuthology/task/ansible.py", line 421, in begin
    super(CephLab, self).begin()
  File "/home/teuthworker/src/git.ceph.com_git_teuthology_6b607b46862a6b148fb1608e09b31d367f094555/teuthology/task/ansible.py", line 264, in begin
    self.execute_playbook()
  File "/home/teuthworker/src/git.ceph.com_git_teuthology_6b607b46862a6b148fb1608e09b31d367f094555/teuthology/task/ansible.py", line 290, in execute_playbook
    self._handle_failure(command, status)
  File "/home/teuthworker/src/git.ceph.com_git_teuthology_6b607b46862a6b148fb1608e09b31d367f094555/teuthology/task/ansible.py", line 315, in _handle_failure
    raise AnsibleFailedError(failures)
teuthology.exceptions.AnsibleFailedError: {'smithi018.front.sepia.ceph.com': {'_ansible_no_log': False, 'attempts': 24, 'changed': False, 'invocation': {'module_args': {'allow_unauthenticated': False, 'autoclean': False, 'autoremove': False, 'cache_valid_time': 0, 'deb': None, 'default_release': None, 'dpkg_options': 'force-confdef,force-confold', 'force': False, 'force_apt_get': False, 'install_recommends': None, 'only_upgrade': False, 'package': None, 'policy_rc_d': None, 'purge': False, 'state': 'present', 'update_cache': True, 'upgrade': None}}, 'msg': 'Failed to update apt cache: '}}

Actions
Copy link
 #14

Updated by Laura Flores about 2 years ago

/a/sseshasa-2022-02-24_11:27:07-rados-wip-45118-45121-quincy-testing-distro-default-smithi/6704249
/a/sseshasa-2022-02-24_11:27:07-rados-wip-45118-45121-quincy-testing-distro-default-smithi/6704258

Actions
Copy link
 #15

Updated by Laura Flores about 2 years ago

  • Backport deleted (quincy, pacific)

Removed backports since this is a Teuthology bug-- my mistake for adding in the first place.

Actions
Copy link
 #16

Updated by Laura Flores about 2 years ago

/a/yuriw-2022-04-01_01:23:52-rados-wip-yuri2-testing-2022-03-31-1523-pacific-distro-default-smithi/6771061

Actions
Copy link
 #17

Updated by Laura Flores about 2 years ago

/a/yuriw-2022-04-06_14:02:46-rados-wip-yuri4-testing-2022-04-05-1720-pacific-distro-default-smithi/6779532

Actions
Copy link
 #18

Updated by Laura Flores about 2 years ago

/a/yuriw-2022-04-23_16:12:08-rados-wip-55324-pacific-backport-distro-default-smithi/6803119

Actions
Copy link
 #19

Updated by Laura Flores almost 2 years ago

  • Is duplicate of Bug #54992: pacific: rados/dashboard: tasks/dashboard: cannot stat '/etc/containers/registries.conf': No such file or directory added
Actions
Copy link
 #20

Updated by Laura Flores almost 2 years ago

  • Status changed from New to Duplicate
Actions
Copy link

Also available in: Atom PDF