[LTCTest][OPAL][OP920] OPAL PRD generated logs is not available in /var/log/opal-prd.log file

Bug #1785026 reported by bugproxy on 2018-08-02
10
This bug affects 1 person
Affects Status Importance Assigned to Milestone
The Ubuntu-power-systems project
High
Canonical Foundations Team
skiboot (Ubuntu)
High
Canonical Foundations Team
Bionic
Undecided
Unassigned

Bug Description

[Impact]
Without this fix we end up creating /var/log/opal-prd.log file with root user. Hence rsyslogd will not be able to write data to this file. Hence we will not have enough opal-prd logs for debugging.

[Test Case]
- install fixed version of opal-prd package
- stop opal-prd daemon : sudo systemctl stop opal-prd
- force log rotation : sudo /usr/sbin/logrotate -f /etc/logrotate.conf
- check whether opal-prd logs /var/log/opal-prd.log file has 644 mode and non root owner.
- start opal-prd daemon : sudo systemctl start opal-prd : at that point opal-prd should just re-use the log with the proper mode.

[Regression Potential]
This is just changing owner for /var/log/opal-prd.log file.
Without this fix, file won't be created and prd logs gets dropped.
I do not see any possible regression with this fix.

----------------

Original description follows:

== Comment: #0 - PAVAMAN SUBRAMANIYAM - 2018-06-27 05:00:15 ==

Install a P9 Open Power Hardware with the latest OP920 Firmware images provided in the following link:
http://pfd.austin.ibm.com/releasenotes/openpower9/OP920/OP920_1824A/OP920_1824A_RelNote_Main.html

root@witherspoon:~# cat /etc/os-release
ID="openbmc-phosphor"
NAME="Phosphor OpenBMC (Phosphor OpenBMC Project Reference Distro)"
VERSION="ibm-v2.1"
VERSION_ID="ibm-v2.1-438-g0030304-r15-0-g19832d3"
PRETTY_NAME="Phosphor OpenBMC (Phosphor OpenBMC Project Reference Distro) ibm-v2.1"
BUILD_ID="ibm-v2.1-438-g0030304-r15"
root@witherspoon:~# cat /var/lib/phosphor-software-manager/pnor/ro/VERSION
IBM-witherspoon-ibm-OP9-v2.0.3-2.17
        op-build-v2.0.3-2-g6279a04-dirty
        buildroot-2018.02.1-6-ga8d1126
        skiboot-v6.0.4
        hostboot-9df0950-p378630b
        occ-90208bb
        linux-4.16.13-openpower1-pc10362e
        petitboot-v1.7.1-pcc0e2c7
        machine-xml-7cd20a6
        hostboot-binaries-8097b96
        capp-ucode-p9-dd2-v4
        sbe-0b006e7
        hcode-fbe2c7c

Then check if the OPAL prd generated logs are captured in /var/log/opal-prd.log file.

root@ltc-wspoon11:/var/log# cat opal-prd.log
root@ltc-wspoon11:/var/log# echo $?
0

== Comment: #4 - VASANT HEGDE - 2018-06-27 09:12:48 ==
root@ltc-wspoon11:~# grep prd /var/log/syslog
Jun 27 08:00:44 ltc-wspoon11 rsyslogd: file '/var/log/opal-prd.log': open error: Permission denied [v8.32.0 try http://www.rsyslog.com/e/2433 ]

root@ltc-wspoon11:~# ls -l /var/log
total 83332
-rw-r--r-- 1 root root 11833 Jun 15 03:15 alternatives.log
....
-rw-r--r-- 1 root root 0 May 1 06:25 opal-prd.log
-rw-r----- 1 syslog adm 5084615 May 1 02:12 opal-prd.log.1

Notice that opal-prd.log file is owned by root user while opal-prd.log.1 is owned by syslog.
That means someone has manually created that log file?

I deleted opal-prd.log file and restart opal-prd daemon.

rm /var/log/opal-prd.log

systemctl restart opal-prd

head /var/log/opal-prd.log
Jun 27 08:02:41 ltc-wspoon11 opal-prd: CTRL: Starting PRD daemon
Jun 27 08:02:41 ltc-wspoon11 opal-prd: I2C: Found Chip: 00000000 engine 3 port 0
Jun 27 08:02:41 ltc-wspoon11 opal-prd: I2C: Found Chip: 00000000 engine 1 port 2
Jun 27 08:02:41 ltc-wspoon11 opal-prd: I2C: Found Chip: 00000008 engine 3 port 1
Jun 27 08:02:41 ltc-wspoon11 opal-prd: I2C: Found Chip: 00000008 engine 1 port 2
Jun 27 08:02:41 ltc-wspoon11 opal-prd: I2C: Found Chip: 00000000 engine 3 port 1
Jun 27 08:02:41 ltc-wspoon11 opal-prd: I2C: Found Chip: 00000000 engine 2 port 0
Jun 27 08:02:41 ltc-wspoon11 opal-prd: I2C: Found Chip: 00000000 engine 1 port 0
Jun 27 08:02:41 ltc-wspoon11 opal-prd: I2C: Found Chip: 00000008 engine 3 port 0
Jun 27 08:02:41 ltc-wspoon11 opal-prd: I2C: Found Chip: 00000008 engine 1 port 0

root@ltc-wspoon11:~# ls -l /var/log
...
-rw-r----- 1 syslog syslog 80804 Jun 27 08:02 opal-prd.log
...

So looks like its user error.

-Vasant

== Comment: #6 - VASANT HEGDE - 2018-07-30 23:16:39 ==
Looks like logrorate stuff is creating new file with root user. Below change should fix this.

:/etc/logrotate.d# diff -Naurp opal-prd.org opal-prd
--- opal-prd.org 2018-07-30 13:04:08.814168026 -0400
+++ opal-prd 2018-07-31 00:09:04.145154122 -0400
@@ -5,5 +5,5 @@
  delaycompress
  missingok
  notifempty
- create 644 root root
+ create 644 syslog adm
 }

-Vasant

== Comment: #7 - VASANT HEGDE - 2018-07-30 23:17:38 ==
Fred,

Can you look into the proposed change?

-Vasant

== Comment: #8 - Frederic Bonnard <email address hidden> - 2018-07-31 01:18:28 ==
Hi all,
thanks Vasant for the investigation. The fix looks good,
I'm just going to check that on Debian as well.
I'll let you know asap,

F.

bugproxy (bugproxy) on 2018-08-02
tags: added: architecture-ppc64le bugnameltc-169279 severity-high targetmilestone-inin1804
Changed in ubuntu:
assignee: nobody → Ubuntu on IBM Power Systems Bug Triage (ubuntu-power-triage)
affects: ubuntu → opal (Ubuntu)
Changed in ubuntu-power-systems:
importance: Undecided → High
tags: added: triage-g
Changed in ubuntu-power-systems:
assignee: nobody → Canonical Foundations Team (canonical-foundations)
Frédéric Bonnard (frediz) wrote :

Fixed in skiboot-6.1-2 (Debian/Unstable).
You may use the same fix for 18.04 there :
https://salsa.debian.org/debian/skiboot/commit/0e6ac150e51a0e7b3701acf78c311709b6336d58

F.

tags: added: id-5b63304d24c8d673190c285b
Manoj Iyer (manjo) on 2018-08-06
Changed in opal (Ubuntu):
importance: Undecided → High
assignee: Ubuntu on IBM Power Systems Bug Triage (ubuntu-power-triage) → Canonical Foundations Team (canonical-foundations)
Manoj Iyer (manjo) on 2018-08-06
Changed in ubuntu-power-systems:
status: New → Triaged
tags: added: p9
tags: added: triage-a
removed: triage-g
Michael Hudson-Doyle (mwhudson) wrote :

Would it be possible for one of the subscribers to this bug to update it with the impact/test case/regression potential per https://wiki.ubuntu.com/StableReleaseUpdates#SRU_Bug_Template ?

Changed in opal (Ubuntu):
status: New → Fix Released

------- Comment From <email address hidden> 2018-09-27 02:17 EDT-------
(In reply to comment #19)
> Would it be possible for one of the subscribers to this bug to update it
> with the impact/test case/regression potential per
> https://wiki.ubuntu.com/StableReleaseUpdates#SRU_Bug_Template ?

[Impact]
Without this fix we end up creating /var/log/opal-prd.log file with root user. Hence rsyslogd will not be able to write data to this file. Hence we will not have enough opal-prd logs for debugging.

[Test Case]
- Installed fixed version of opal-prd package
- restart opal-prd daemon (systemctl restart opal-prd)
- check whether opal-prd logs are stored in /var/log/opal-prd.log file.

[Regression Potential]
Nothing.

-Vasant

description: updated
affects: opal (Ubuntu) → skiboot (Ubuntu)
Changed in skiboot (Ubuntu Bionic):
status: New → In Progress
Robie Basak (racb) wrote :

The skiboot SRU needs a proper Regression Potential section please.

bugproxy (bugproxy) wrote :

------- Comment From <email address hidden> 2018-10-05 02:06 EDT-------
(In reply to comment #21)
> The skiboot SRU needs a proper Regression Potential section please.

[Regression Potential]
This is just changing owner for /var/log/opal-prd.log file.
Without this fix, file won't be created and prd logs gets dropped.
I do not see any possible regression with this fix.

-Vasant

Andrew Cloke (andrew-cloke) wrote :

Updated "[Regression Potential]" section in bug description with text from comment #5.

description: updated

Hello bugproxy, or anyone else affected,

Accepted skiboot into bionic-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/skiboot/5.10~rc4-1ubuntu1.1 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation on how to enable and use -proposed. Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested and change the tag from verification-needed-bionic to verification-done-bionic. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed-bionic. In either case, without details of your testing we will not be able to proceed.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance for helping!

N.B. The updated package will be released to -updates after the bug(s) fixed by this package have been verified and the package has been in -proposed for a minimum of 7 days.

Changed in skiboot (Ubuntu Bionic):
status: In Progress → Fix Committed
tags: added: verification-needed verification-needed-bionic
Changed in ubuntu-power-systems:
status: Triaged → Fix Committed
Frédéric Bonnard (frediz) wrote :

Hi,
the log file mode is dealt with by logrotate. So restarting opal-prd won't make logrotate start and change anything (logrotate is called from crontab). The test case would rather be :

[Test Case]
- install fixed version of opal-prd package
- stop opal-prd daemon : sudo systemctl stop opal-prd
- force log rotation : sudo /usr/sbin/logrotate -f /etc/logrotate.conf
- check whether opal-prd logs /var/log/opal-prd.log file has 644 mode and non root owner.
- start opal-prd daemon : sudo systemctl start opal-prd : at that point opal-prd should just re-use the log with the proper mode.

That worked well for me with opal-prd 5.10~rc4-1ubuntu1.1 from bionic-proposed.

F.

description: updated
Michael Hudson-Doyle (mwhudson) wrote :
Download full text (5.1 KiB)

Ah, thanks for the improved test case. I've been through the steps (boring transcript below) and also verified the fix.

ubuntu@dradis:~$ systemctl status opal-prd
● opal-prd.service - OPAL PRD daemon
   Loaded: loaded (/lib/systemd/system/opal-prd.service; enabled; vendor preset: enabled)
   Active: active (running) since Mon 2018-10-15 02:06:02 UTC; 17s ago
     Docs: man:opal-prd(8)
 Main PID: 4545 (opal-prd)
    Tasks: 1 (limit: 24575)
   CGroup: /system.slice/opal-prd.service
           └─4545 /usr/sbin/opal-prd

Oct 15 02:06:03 dradis opal-prd[4545]: HBRT: PRDF:<<PRDF::initialize()
Oct 15 02:06:03 dradis opal-prd[4545]: HBRT: ATTN_SLOW:I>Service::enableAttns() enter
Oct 15 02:06:03 dradis opal-prd[4545]: HBRT: TARG:[TARG] I> getNextTarget: Using next node 1
Oct 15 02:06:03 dradis opal-prd[4545]: HBRT: TARG:[TARG] E> getNextTarget: Node 0 targets: first 0x7ba601bbfc1c, current 0x7ba601bc4b00, last 0x7ba601bc4
Oct 15 02:06:03 dradis opal-prd[4545]: HBRT: TARG:[TARG] E> getNextTarget: Target not found
Oct 15 02:06:03 dradis opal-prd[4545]: HBRT: ATTN_SLOW:I>Service::enableAttns() exit
Oct 15 02:06:03 dradis opal-prd[4545]: HBRT: ATTN_SLOW:I><<ATTN_RT::enableAttns rc: 0
Oct 15 02:06:03 dradis opal-prd[4545]: HBRT: calling get_ipoll_events
Oct 15 02:06:03 dradis opal-prd[4545]: HBRT: enabling IPOLL events 0x5b90000000000000
Oct 15 02:06:03 dradis opal-prd[4545]: FW: writing init message
ubuntu@dradis:~$ less /var/log/opal-prd.log
ubuntu@dradis:~$ -l /var/log/opal-prd.log
-l: command not found
ubuntu@dradis:~$ ls -l /var/log/opal-prd.log
-rw-r----- 1 syslog adm 34057 Oct 15 02:06 /var/log/opal-prd.log
ubuntu@dradis:~$ dplg -^C
ubuntu@dradis:~$ sudo systemctl stop opal-prd
ubuntu@dradis:~$ sudo /usr/sbin/logrotate -f /etc/logrotate.conf
ubuntu@dradis:~$ ls -l /var/log/opal-prd.log
-rw-r--r-- 1 root root 0 Oct 15 02:06 /var/log/opal-prd.log
ubuntu@dradis:~$ sudo systemctl start opal-prd
ubuntu@dradis:~$ less opal-prd
opal-prd: No such file or directory
ubuntu@dradis:~$ ls -l /var/log/opal-prd.log
-rw-r--r-- 1 root root 0 Oct 15 02:06 /var/log/opal-prd.log
ubuntu@dradis:~$ sudo systemctl stop opal-prd
ubuntu@dradis:~$ dpkg -l opal-prd
Desired=Unknown/Install/Remove/Purge/Hold
| Status=Not/Inst/Conf-files/Unpacked/halF-conf/Half-inst/trig-aWait/Trig-pend
|/ Err?=(none)/Reinst-required (Status,Err: uppercase=bad)
||/ Name Version Architecture Description
+++-================================-=====================-=====================-=====================================================================
ii opal-prd 5.10~rc4-1ubuntu1 ppc64el OPAL Processor Recovery Diagnostics daemon
ubuntu@dradis:~$ wget https://launchpad.net/ubuntu/+archive/primary/+files/opal-prd_5.10~rc4-1ubuntu1.1_ppc64el.deb
--2018-10-15 02:07:37-- https://launchpad.net/ubuntu/+archive/primary/+files/opal-prd_5.10~rc4-1ubuntu1.1_ppc64el.deb
Resolving launchpad.net (launchpad.net)... 91.189.89.222, 91.189.89.223
Connecting to launchpad.net (launchpad.net)|91.189.89.222|:443... connected.
HTTP request sent, awaiting response... 303 See Other
Location: https://launchpadlibrarian.net/39...

Read more...

tags: added: verification-done-bionic
removed: verification-needed verification-needed-bionic
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package skiboot - 5.10~rc4-1ubuntu1.1

---------------
skiboot (5.10~rc4-1ubuntu1.1) bionic; urgency=medium

  * d/opal-prd.logrotate: fix ownership of /var/log/opal-prd.log.
    (LP: #1785026)

 -- Michael Hudson-Doyle <email address hidden> Wed, 03 Oct 2018 12:27:12 +1300

Changed in skiboot (Ubuntu Bionic):
status: Fix Committed → Fix Released

The verification of the Stable Release Update for skiboot has completed successfully and the package has now been released to -updates. Subsequently, the Ubuntu Stable Release Updates Team is being unsubscribed and will not receive messages about this bug report. In the event that you encounter a regression using the package from -updates please report a new bug using ubuntu-bug and tag the bug report regression-update so we can easily find any regressions.

Changed in ubuntu-power-systems:
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers