Chris's AIX Blog

Before I describe the sudo problem I hit, I will tell you that the root cause of the problem is evident in the following output:

 

# mount

  node       mounted        mounted over    vfs       date        options

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

         /dev/hd4         /                jfs2   Aug 14 12:00 rw,log=/dev/hd8

         /dev/hd2         /usr             jfs2   Aug 14 12:00 rw,log=/dev/hd8

         /dev/hd9var      /var             jfs2   Aug 14 12:00 rw,log=/dev/hd8

         /dev/hd3         /tmp             jfs2   Aug 14 12:00 rw,log=/dev/hd8

         /dev/hd11admin   /admin           jfs2   Aug 14 12:00 rw,log=/dev/hd8

         /dev/mksysblv    /export/mksysb   jfs2   Aug 14 12:00 rw,log=/dev/loglv00

         /dev/fslv00      /export/nim      jfs2   Aug 14 12:00 rw,log=/dev/loglv00

         /dev/hd1         /home            jfs2   Aug 14 12:00 rw,log=/dev/hd8

         /dev/hd10opt     /opt             jfs2   Aug 14 12:00 rw,log=/dev/hd8

         /dev/swlv        /software        jfs2   Aug 14 12:00 rw,log=INLINE

         /dev/fslv01      /tftpboot        jfs2   Aug 14 12:00 rw,log=/dev/loglv00

         /dev/livedump    /var/adm/ras/livedump jfs2   Aug 14 12:00 rw,log=/dev/hd8

         /dev/fixelv      /fixes           jfs2   Aug 14 12:00 rw,log=INLINE

         /dev/lpmautolv   /lpmauto         jfs2   Aug 14 12:00 rw,log=INLINE

         /dev/promonlv    /promon          jfs2   Aug 14 12:00 rw,log=INLINE

         /aha             /aha             ahafs  Aug 14 12:00 rw

 

The output above is from the mount command on an AIX host.

 

Can you see any problems that might impact sudo's ability to run?

 

No?

 

Problem Description:

 

A customer was attempting to use sudo to run some commands on an AIX host. Each time, sudo would fail with the following error message:

 

$ sudo -l

sudo: no tty present and no askpass program specified

 

The only information we had was that the host had been rebooted at some point in the last day or so.

 

We spent some time checking and verifying a bunch of things (specifically making sure that the /etc/sudoers file was intact and did not contain any bad entries) but none of them provided any real clues as to the root cause of the problem.

 

Problem Debugging and Investigation

 

We enabled debug for sudo. This involved creating an /etc/sudo.conf file with the following entries:

 

# vi sudo.conf

Debug sudo /var/log/sudo_debug.log all@debug

Debug sudoers.so /var/log/sudo_debug.log all@debug

 

Then, as the non-root user, we attempted to run sudo again. This generated some useful data in the /var/log/sudo_debug.log file. You'll notice we grep'ed for the string tty specifically, given that this was part of the sudo error message provided to us.

 

 

$ sudo -l

sudo: no tty present and no askpass program specified

 

# grep tty /var/log/sudo_debug.log

Aug 10 16:20:26 sudo[14352830] -> get_process_ttyname @ ./ttyname.c:417

Aug 10 16:20:26 sudo[14352830] unable to resolve tty via /proc/14352830/psinfo: A file or directory in the path name does not exist. @ get_process_ttyname() ./ttyname.c:442

Aug 10 16:20:26 sudo[14352830] <- get_process_ttyname @ ./ttyname.c:444 := (null)

Aug 10 16:20:26 sudo[14352830] -> sudo_get_ttysize_v1 @ ./ttysize.c:59

Aug 10 16:20:26 sudo[14352830] -> get_ttysize_ioctl @ ./ttysize.c:38

Aug 10 16:20:26 sudo[14352830] <- get_ttysize_ioctl @ ./ttysize.c:44 := 0

Aug 10 16:20:26 sudo[14352830] <- sudo_get_ttysize_v1 @ ./ttysize.c:75

Aug 10 16:20:26 sudo[14352830] searching for tty time stamp record @ timestamp_lock() ./timestamp.c:603

Aug 10 16:20:26 sudo[14352830] appending new tty time stamp record @ timestamp_lock() ./timestamp.c:611

Aug 10 16:20:26 sudo[14352830] tty time stamp position is 112 @ timestamp_lock() ./timestamp.c:617

Aug 10 16:20:26 sudo[14352830] -> tty_present @ ./tgetpass.c:360

Aug 10 16:20:26 sudo[14352830] <- tty_present @ ./tgetpass.c:361 := false

Aug 10 16:20:26 sudo[14352830] no tty present and no askpass program specified @ tgetpass() ./tgetpass.c:107

 

The following information was of great interest to us! It appeared to be that some information was "missing" from the /proc file system on the host?

 

# grep tty /var/log/sudo_debug.log | grep unable

Aug 10 16:20:26 sudo[14352830] unable to resolve tty via /proc/14352830/psinfo: A file or directory in the path name does not exist. @ get_process_ttyname() ./ttyname.c:442

Aug 18 11:19:59 sudo[21889328] unable to resolve tty via /proc/21889328/psinfo: A file or directory in the path name does not exist. @ get_process_ttyname() ./ttyname.c:442

 

Upon further investigation, we found that /proc did, in fact, appear to be completely empty!! This was not expected or normal on a modern AIX system.

 

# ls -ltr /proc

total 0

 

And, after running the mount command, we discovered that, yes, the /proc file system was NOT mounted!

 

# mount | grep proc

#

 

Resolution

 

Next, we attempted to mount /proc. But we couldn't, as it was not a known file system? Curious indeed.

 

# mount /proc

mount: 0506-334 /proc is not a known file system.

 

The /proc file system stanza was missing from /etc/filesystems. So, we added it back in and mounted the file system successfully.

 

 

# grep -p proc /etc/filesystems

#                                  << No /proc entry found in /etc/filesystems!

 

# grep -p proc /etc/filesystems

/proc:

        dev       = /proc

        vol       = "/proc"

        mount     = true

        check     = false

        free      = false

        vfs       = procfs

 

# mount /proc

# mount | grep proc

         /proc            /proc            procfs Aug 18 11:31 rw

             

# ls -ltr /proc | head -10

total 0

dr-xr-xr-x    8 root     system            0 Aug 10 16:21 sys

-r--r--r--    1 root     system           91 Aug 10 16:21 version

dr-xr-xr-x    1 root     system            0 Aug 10 16:21 0

dr-xr-xr-x    1 root     system            0 Aug 10 16:21 1

dr-xr-xr-x    1 root     system            0 Aug 10 16:21 260

dr-xr-xr-x    1 root     system            0 Aug 10 16:21 65798

dr-xr-xr-x    1 root     system            0 Aug 10 16:21 131336

dr-xr-xr-x    1 root     system            0 Aug 10 16:21 196874

dr-xr-xr-x    1 root     system            0 Aug 10 16:21 262412

 

As soon as /proc was mounted again, the non-root user could run sudo without any issues.

 

$ sudo -l

Password:

User cgibson may run the following commands on 750lpar4:

    (ALL) /usr/sbin/slibclean

$

 

The /proc file system is different from other file systems. It does not reside on disk. The /proc file system resides in AIX memory and is referred to as a virtual file system. The files maintained in /proc represent the running processes on the system.

http://www-01.ibm.com/support/docview.wss?uid=isg3T1012015

https://www.ibm.com/support/knowledgecenter/en/ssw_aix_72/com.ibm.aix.files/proc.htm

 

Using PowerSC RTC to monitor for the deletion of a specific file.

 

One of my customers was concerned that someone or something was randomly deleting the /etc/niminfo on several of his AIX hosts. We discussed several ways in which he could track down who or what was removing this file. Obviously, the AIX audit subsystem would be an ideal method of capturing this event. However, PowerSC Real Time Compliance (RTC) can also monitor and capture this type of event.

 

“The PowerSC™ Real Time Compliance feature continuously monitors enabled AIX® systems to ensure that they are configured consistently and securely.

 

The PowerSC Real Time Compliance feature works with the PowerSC Compliance Automation and AIX Security Expert policies to provide notification when compliance violations occur or when a monitored file is changed. When the security configuration policy of a system is violated, the PowerSC Real Time Compliance feature sends an email or a text message to alert the system administrator.”

 

Here’s a quick start guide on configuring PowerSC RTC on AIX.

 

1. PowerSC is included with the AIX Enterprise Edition offering. Download the PowerSC software from IBM Entitled Systems Support (ESS) website.

 

 

The package name is ESD_-_PowerSC_Standard_Edition_v1.1.5_122016.tar.gz.

 

2. Install the following filesets on the AIX host.

 

# lslpp -L powerscStd\*

  Fileset                      Level  State  Type  Description (Uninstaller)

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

  powerscStd.license         7.1.1.5    C     F    PowerSC Standard Edition

  powerscStd.rtc.rte         1.1.5.0    C     F    Real-Time Compliance

 

# oslevel -s

7100-04-04-1717

 

3. Configure RTC.

 

# smit RTC

>Configure Real-Time Compliance Subsystem

 

                  Configure Real-Time Compliance subsystem

 

Type or select values in entry fields.

Press Enter AFTER making all desired changes.

 

                                                        [Entry Fields]

* Email Address (comma separated)                    [root@lpar9]

  Alert Information Level                            [1]            +#

  Alert Style                                        [once]         +

  Alert Email Subject                                []

  Debug                                              [off]          +

 

Or you can use /usr/sbin/mkrtc.

 

# lssrc -s rtcd

Subsystem         Group            PID          Status

 rtcd                              11075602     active

 

4. Configure the /etc/security/rtc/rtcd.conf and rtcd_policy.conf files.

 

/etc/security/rtc/rtcd.conf:

 

infolevel: 3

alertStyle: event

locallogfile: /var/log/rtc.log

 

Add /etc/niminfo to rtcd_policy.conf file.

 

# tail -2 /etc/security/rtc/rtcd_policy.conf

 

/etc/niminfo:

        eventtype = modFile,modFileAttr

 

Restart RTC.

 

# stopsrc -s rtcd

 

# startsrc -s rtcd

 

5. Test RTC monitoring. e.g If someone deletes the niminfo file, a report is sent via email to root.

 

# rm /etc/niminfo

 

# mail

Mail [5.2 UCB] [AIX 5.X]  Type ? for help.

"/var/spool/mail/root": 2 messages 2 new

>N  1 RTC@lpar9.mel  Thu Aug  3 12:46  35/880  "PowerSC Real-Time Alert - 75"

?

Message  1:

From root Thu Aug  3 12:46:25 2017

Date: Thu, 3 Aug 2017 12:46:25 GMT

To: root@lpar9.meldemo.au.ibm.com

From: RTC@lpar9.meldemo.au.ibm.com

Subject: PowerSC Real-Time Alert - lpar9

 

The following event(s) has occurred:

BEGIN_EVENT_INFO

Hostname      : lpar9

Filename      : /etc/niminfo

Time          : Thu Aug  3 12:46:25 2017

Sequence Num  : 2

Process ID    : 15991252

User Info     : userName=root, loginName=root, groupName=system

Program Name  : rm

Event         : AHAFS_MODFILE_REMOVE

STACK_TRACE

[14D70]

ahafs_evprods+970

aha_process_vnop+194

vnop_remove+3A4

kunlinkat+530

.svc_instr

IPRA.$rm+800

IPRA.$rm_main+100

main+C4

__start+68

END_EVENT_INFO

 

The event information is also captured in the RTC log file (/var/log/rtc.log) on the host.

 

# grep -p REMOVE /var/log/rtc.log | head -50

The following event(s) has occurred:

BEGIN_EVENT_INFO

Hostname      : lpar9

Filename      : /etc/niminfo

Time          : Thu Aug  3 12:46:25 2017

Sequence Num  : 2

Process ID    : 15991252

User Info     : userName=root, loginName=root, groupName=system

Program Name  : rm

Event         : AHAFS_MODFILE_REMOVE

STACK_TRACE

[14D70]

ahafs_evprods+970

aha_process_vnop+194

vnop_remove+3A4

kunlinkat+530

.svc_instr

IPRA.$rm+800

IPRA.$rm_main+100

main+C4

__start+68

END_EVENT_INFO

 

 

IBM Knowledge Center PowerSC Real Time Compliance

https://www.ibm.com/support/knowledgecenter/en/SSTQK9_1.1.5/com.ibm.powersc.se/realtimecompliance.htm

 

 

The AIX minidump facility was introduced with AIX 5.3 TL3. A mini dump is a small compressed dump that is stored to NVRAM when a system crashes or a dump is initiated, and then written to the AIX error log on reboot. It can be used to see some of the system’s state and do some debugging when a full dump is not available. It can also be used to get a quick snapshot of a crash without having to transfer the entire dump from the crashed system to IBM support.

 

Please refer to the following, official guide, on "How to examine a minidump in AIX".

 

"Using this crash stack IBM support personnel can then search through the database to find what the fault may mean".

"The RAS effort mentioned..is part of an ongoing effort by AIX to increase stability and to make more information available for troubleshooting when a problem occurs. The ability to look at minidump data has helped solve many issues that would otherwise go unresolved".

 

http://www-01.ibm.com/support/docview.wss?uid=isg3T1010709

 

Of course, minidumps have their limitations and do not replace the need for a full system dump in many cases.

 

"Limitations of minidumps
A minidump is of limited or no use in situations where a server has hung. In this situation we can use mdmprpt to see what was running on each cpu. Practically speaking a full dump is usually needed to determine how and why a server has hung."

 

Here are some examples of how I've used minidump to assist me (and IBM support) in diagnosing the root cause of a system crash.

 

The first example is from a customer that found that one of their AIX partitions would crash when they ran optmem DPO (Dynamic Platform Optimiser) against one of their new POWER8 E880s. Immediately after optmem ran, one specific LPAR would crash. The LPAR reference LED code would show "888 102 300 C20". This LPAR was installed with AIX 7.1 TL3 SP4. When we tried to restart the partition, it would crash (and dump) several times before it would start successfully. Once the partition booted successfully, we noticed that there were several system dumps (SYSDUMP) and minidumps (COMPRESSED MINIMAL DUMP) shown in the AIX error report.

 

IDENTIFIER TIMESTAMP  T C RESOURCE_NAME  DESCRIPTION

A6DF45AA   0411163117 I O RMCdaemon      The daemon is started.

2BFA76F6   0411163117 T S SYSPROC        SYSTEM SHUTDOWN BY USER

9DBCFDEE   0411163117 T O errdemon       ERROR LOGGING TURNED ON

192AC071   0411162917 T O errdemon       ERROR LOGGING TURNED OFF

A6DF45AA   0411162517 I O RMCdaemon      The daemon is started.

2BFA76F6   0411162517 T S SYSPROC        SYSTEM SHUTDOWN BY USER

9DBCFDEE   0411162517 T O errdemon       ERROR LOGGING TURNED ON

192AC071   0411162217 T O errdemon       ERROR LOGGING TURNED OFF

A6DF45AA   0411161117 I O RMCdaemon      The daemon is started.

67145A39   0411161017 U S SYSDUMP        SYSTEM DUMP                                  << CRASH!

F48137AC   0411161017 U O minidump       COMPRESSED MINIMAL DUMP                      << Minidump information

9D035E4D   0411161017 P S SYSVMM         DATA STORAGE INTERRUPT, PROCESSOR

9DBCFDEE   0411161017 T O errdemon       ERROR LOGGING TURNED ON

A6DF45AA   0411155917 I O RMCdaemon      The daemon is started.

67145A39   0411155817 U S SYSDUMP        SYSTEM DUMP                                  << CRASH!

F48137AC   0411155817 U O minidump       COMPRESSED MINIMAL DUMP                      << Minidump information

9D035E4D   0411155817 P S SYSVMM         DATA STORAGE INTERRUPT, PROCESSOR

9DBCFDEE   0411155817 T O errdemon       ERROR LOGGING TURNED ON

A6DF45AA   0411155717 I O RMCdaemon      The daemon is started.

67145A39   0411155717 U S SYSDUMP        SYSTEM DUMP                                  << CRASH!

F48137AC   0411155717 U O minidump       COMPRESSED MINIMAL DUMP                      << Minidump information

9D035E4D   0411155717 P S SYSVMM         DATA STORAGE INTERRUPT, PROCESSOR            << CRASH!

9DBCFDEE   0411155717 T O errdemon       ERROR LOGGING TURNED ON

6AEB31F5   0410143317 I H sysplanar0     Platform Resource Reassignment.              << DPO

 

I used the minidump reporting tool (mdmprpt) to perform a quick analysis of the cause of the crash, by reviewing the "Stack Trace" information. The mdmprpt tool has a couple of options.

 

 

# mdmprpt -?

Usage:

mdmprpt [[-l seq_no] [-i filename]] | [ -b filename ] [ -F ] [-r]

 

Process error log entries from the supplied file(s).

-l seq_no Format the minidump at the specified sequence number in the error log.

-i filename  Uses the error log file specified by the filename param.

-b filename  Uses the binary file specified by the filename param.

-F prints only dump failure information.

-r print the raw minidump, without formatting.

 

If no parameters are specified, the most recently logged minidump is shown. You may not specify -b with -i or -l.

 

Typically, the most common usage is to simply run mdmprpt and redirect the output to a file for review.

 

# mdmprpt > /tmp/minidumpreport.out

 

The most relevant section of the report is the "Stack Trace" section(s).

 

# vi /tmp/minidumpreport.out

 

MINIDUMP VERSION 4D33

***************************************************

64-bit Kernel, 57 Entries

 

Last Error Log Entry:

         Error ID: 9D035E4D      Resource Name: SYSVMM

         Detail Data: 0000000000000000 00007FFFFFFFD080 00000007000000C7 0000000000000115

 

Symptom Information:

        Crash Location: [00000000000ADE98] trc_generate_ea+78

        Component: COMP  Exception Type: 277

 

Data From CPU #1 (Faulting CPU)

***************************************************

...

Stack Trace:

[00000000000ADE98] trc_generate_ea+78

        0000000000000002 F1000A002033C000 C0C0C0C0C0C0C0C1 8000002841900000

        00000000025BBC00 00000000000034C8 00000000009F3998 0000000003322000

[00000000000ACF64] trc_inmem_recor+144

        0000000000000000 F1000815B0052D00 0000000000007800 000000000000F000

 ...

 

In this case, the stack trace showed messages relating to trc_generate and trc_inmem_recor. Using this information, I was able to find several hits (both internally to IBM and using my preferred internet search tool) for the potential cause of the crash. The problem was a known issue and related to the following APAR.

 

IV69116: AIX CAN CRASH IBM POWER8 E880 (9119-MHE) WITH > THAN 128 CORES APPLIES TO AIX 7100-03

http://www-01.ibm.com/support/docview.wss?uid=isg1IV69116

 

 

We verified our findings with IBM support (who performed their own internal search) and we concluded that an update would be required. We chose to update the AIX system to AIX 7.1 TL4 SP3, and the problem went away.

 

In the next example, the customer had updated one of their AIX partitions to AIX 7.1 TL4 SP3 (previously on AIX 7.1 TL4 SP1). This LPAR also housed a single, AIX 5.3 versioned WPAR. The update was successful but whenever they ran the stopwpar command, the entire partition would crash (dump). So, once again, I employed the mdmprpt utiliy to check the stack traces.

 

MINIDUMP VERSION 4D33

***************************************************

64-bit Kernel, 48 Entries

 

Last Error Log Entry:

         Error ID: 9D035E4D      Resource Name: SYSVMM

         Detail Data: 000000000A000000 00000000C000C400 F1000000C01ED500 0000000000000086

 

Symptom Information:

        Crash Location: [F1000000C012B968] pcmUserGetDevIn+E8

        Component: COMP  Exception Type: 134

...

Stack Trace:

[F1000000C012B968] pcmUserGetDevIn+E8

       000000002FF44EAC 00000000DEADBEEF 00000000A28F47CB 0000000000000005

       F1000A000036A500 0000000000010000 F1000000C01D3000 000000002FEF56E0

[F1000000C01D1808] sddUserInterfac+588

       0000000000000002 00000000DEADBEEF 00000000A28F47CB 0000000000000088

...

 

The report showed us pcmUserGetDevIn and sddUserInterfac in the stack trace. Both are related to the IBM sddpcm device driver. They appeared to be the likely culprits. Searching for these presented us with a couple of potential reasons for the crash, such as too many paths configured for a sddpcm device (which we checked and confirmed was far less than the maximum of 32). So, my next question was, what version of sddpcm was installed? We found that the customer had (unexpectedly) two different versions of sddpcm installed. In the Global LPAR, the sddpcm version was 2.6.9.0 (the latest) and in the vWPAR, 2.6.6.0. During the TL update, the customer had updated sddpcm to the latest level available, but had forgotten to update sddpcm inside the vWPAR as well. We then discovered, that if they simply ran "pcmpath query device" from inside the vWPAR, this would crash the partition. The latest sddpcm readme file contained the following information "5557  Fix for AIX 7.1 crash during pcmpath query device"! This was indeed the cause of the system crash. After the customer updated sddpcm, inside the vWPAR, the system was stable and the problem was resolved.

 

If you encounter a system crash in the future, and there's minidump data available, why not consider using the minidump reporting tool to analyse the issue? It might just help speed up the root cause analysis of the problem.

 

 

 

The latest release of the VIOS provides a way to automatically backup your virtual device configuration whenever it changes. From the IBM Knowledge Center for POWER8:

 

https://www.ibm.com/support/knowledgecenter/POWER8/p8hcg/p8hcg_viosbr.htm

 

"The viosbr command automatically creates a backup, whenever there are any configuration changes. This functionality is known as the autoviosbr backup. It is triggered every hour, and checks if there are any configuration changes, or any other changes. If it detects any changes, a backup is created. Otherwise, no action is taken. The backup files resulting from the autoviosbr backup are located under the default path /home/padmin/cfgbackups with the names autoviosbr_SSP.<cluster_name>.tar.gz for cluster level and autoviosbr_<hostname>.tar.gz for node level. The cluster-level backup file is present only in the default path of the database node.

 

The -autobackup flag is provided for the autoviosbr backup functionality. By default, autoviosbr backup is enabled on the system. To disable the autoviosbr backup, use the stop parameter and to enable it you can use the start parameter. When the autoviosbr backupis disabled, no autoviosbr related tar.gz file is generated.

 

To check if the autoviosbr backup file, present in the default path is up to date, you can use the status parameter. To access the cluster-level backup file on any node of the cluster, use the save parameter. This action is necessary as the cluster-level backup file is present in the default path of the database node only.

 

If the node is a part of cluster, you can use the -type flag to specify the parameter. The parameter can be either cluster or node, depending on if it is a cluster-level or a node-level backup.

Flags""

 

On your VIOS, under oem_setup_env (as root), you'll find the following new entry in root's crontab:

 

# crontab -l | grep autoviosbr

0 * * * * /usr/ios/sbin/autoviosbr -start 1>/dev/null 2>/dev/null

 

This entry will check for any configuration changes and generate a new backup if necessary. Here's an example from my VIOS, running 2.2.5.10.

 

$ ioslevel

2.2.5.10

 

I create a new virtual optical device, which should trigger a new backup the next time the autoviosbr script runs (once per hour). Prior to creating the device, viosbr shows the autobackup status as Complete (no changes). I ensure that autobackup is configured by stopping and starting it with the viosbr command.

 

$ viosbr -autobackup stop -type node

Autobackup stopped successfully.

 

$ viosbr -autobackup start -type node

Autobackup started successfully.

 

$ viosbr -autobackup status -type node

Node configuration changes:Complete.

 

$ mkvdev -fbo -vadapter vhost34

vtopt13 Available

 

Immediately after the vtopt device is created, the autobackup status displays as Pending (something has changed but has not yet been backed up).

 

$ viosbr -autobackup status -type node

Node configuration changes:Pending.

 

The autoviosbr file is created in /home/padmin/cfgbackups.

 

$ r oem

oem_setup_env

 

# cd /home/padmin/cfgbackups

# ls -tlr

total 72

-rw-r--r--    1 root     staff         12189 May 10 14:00 autoviosbr_s824vio2.tar.gz

 

On the hour, the autoviosbr script runs, notices that the configuration has changed and generates a new viosbr backup file. The viosbr autobackup status changes to Complete.

 

$ viosbr -autobackup status -type node

Node configuration changes:Complete.

 

# ls -ltr

total 88

-rw-r--r--    1 root     staff         12218 May 10 15:00 autoviosbr_s824vio2.tar.gz

 

What's inside the tar file?

 

# cp /home/padmin/cfgbackups/autoviosbr_s824vio2.tar.gz /tmp/cg/

# cd /tmp/cg

# gzip -d autoviosbr_s824vio2.tar.gz

# tar -xvf autoviosbr_s824vio2.tar

x ArtexRules_MTM8286-42A02214F58VP2.xml, 20549 bytes, 41 media blocks.

x autoviosbr_s824vio2, 198554 bytes, 388 media blocks.

# ls -ltr

total 888

-rw-r--r--   1 root staff  198554 May 10 15:00 autoviosbr_s824vio2

-rw-r--r--   1 root staff  20549 May 10 15:00 ArtexRules_MTM8286-42A02214F58VP2.xml

-rw-r--r--   1 root staff  225280 May 10 15:00 autoviosbr_s824vio2.tar

 

The ArtexRules file contains device specific configuration attributes.

 

# head ArtexRules_MTM8286-42A02214F58VP2.xml

<?xml version="1.0" encoding="UTF-8"?>

<Profile origin="get" version="3.0.0" date="2017-05-10T04:10:54Z">

 <Catalog id="devParam.disk.fcp.mpioosdisk" version="3.0">

  <Parameter name="reserve_policy" value="single_path" applyType="nextboot" reboot="true">

   <Target class="device" instance="disk/fcp/mpioosdisk"/>

  </Parameter>

 </Catalog>

 <Catalog id="devParam.disk.fcp.mpioapdisk" version="3.0">

  <Parameter name="reserve_policy" value="single_path" applyType="nextboot" reboot="true">

   <Target class="device" instance="disk/fcp/mpioapdisk"/>

#

 

The autoviosbr file contains virtual device configuration information. In this file I can confirm that the configuration of my new virtual optical device (vtopt13) has been backed up.

 

# grep vtopt13 autoviosbr_s824vio2

                <name>vtopt13</name>

                        <vtdName>vtopt13</vtdName>

                        <value>vtopt13</value>

                                          

# vi autoviosbr_s824vio2

...

        <virtDevOPT>

                <name>vtopt13</name>

                <state>AVAILABLE</state>

                <locCode>U8286.42A.214F58V-V2-C101-L2</locCode>

                <unique_type>virtual_target/vtdev/fbopt</unique_type>

                <type>BDOPFBOPT</type>

                <fbOpt>

                </fbOpt>

                <CuAtcount>2</CuAtcount>

                <CuAt name="LogicalUnitAddr" value="0x8200000000000000" action="FALSE" />

                <CuAt name="udid" value="19cc3cb76ad94674c3" action="TRUE" />

        </virtDevOPT>

...

 

If you want to force a backup to run, before the next hour, manually run the following as root (oem_setup_env):

 

$ oem_setup_env

# /usr/ios/sbin/autoviosbr -start

 

On more than one occasion I’ve written articles and blogs on how to migrate AIX systems to a new version of the AIX operating system. You can find a list these articles (and others) here. Each of the NIM articles focuses on migrating AIX systems (which are configured as NIM clients). The approach is always the same; use a NIM master to migrate the NIM clients to the next release of AIX. What they don’t discuss is how to migrate your NIM master to a new version of the OS. This is the very first step you should take before you consider migrating your clients. The NIM master should always be at the same or higher AIX level than the level you are migrating to on a client. So, in this latest article, I’ll discuss, step by step, how to migrate your NIM master from AIX 7.1 to AIX 7.2 (the latest release of the AIX OS).

 

https://www.ibm.com/developerworks/community/blogs/cgaix/resource/Migrating_NIMMaster_AIX72_VML.pdf

I LPM'ed an AIX LPAR from Frame A to Frame B. The LPAR id before the LPM was 99 and after the LPM it's still 99. And the system id has changed, as expected. Good.

 

Before migration.

 

root@lpar1 / # uname -L

99 lpar1

 

root@lpar1 / # lsattr -El sys0 -a systemid

systemid IBM,017268B60 Hardware system identifier False

 

After migration.

 

root@lpar1 / # uname -L

99 lpar1

 

root@lpar1 / # lsattr -El sys0 -a systemid

systemid IBM,0157F5B16 Hardware system identifier False

 

Great, that's exactly what I wanted.

 

Hang on a minute! What kind of sorcery is this?!

 

root@lpar1 / # errpt | grep sys

60AFC9E5   0405132517 I O sys0           Partition ID changed since last boot.

 

root@lpar1 / # errpt -aN sys0

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

LABEL:          PARTID_CHANGE

IDENTIFIER:     60AFC9E5

 

Date/Time:       Wed Apr  5 13:25:53 EET 2017

Sequence Number: 81372

Machine Id:      000157F5B16

Node Id:         lpar1

Class:           O

Type:            INFO

WPAR:            Global

Resource Name:   sys0

 

Description

Partition ID changed since last boot.

 

Whaddaya mean my partiton ID changed since last boot?! It hasn't! I know this for a fact! Look at the uname output above!!

 

Well, I'm 100% correct, the partition id HAS NOT CHANGED! But the system id has....and this is the cause of the "informational" message in the AIX error report.

 

AIX uses the output from 'uname -f' to detect if the system AND/OR partition id have changed since last boot.

 

So, in my case, the partition id (99 dec/63 hex) did not change but (as you'd expect with LPM) the system id (shown in hex below) has changed, hence the message "Partition ID changed since last boot".

 

Before LPM.

 

root@lpar1 / # uname -f

80000BA02DC00063

 

After LPM.

 

root@lpar1 / # uname -f

800016B466F00063

 

From the uname man page:

 

-F Displays a system identification string comprised of hexadecimal characters. This identification string is the same for all partitions on a particular system.

                                                     

-f Similar to the F flag, except that the partition number is also used in the calculation of this string. The resulting identification string is unique for each partition on a particular system.

 

So, no problem here. Nothing to see, nothing to do. Move along! 

AIX has a new “critical volume group” capability which will monitor for the loss or failure of a volume group. You can apply this to any volume group, including rootvg. If applied to rootvg, then you can monitor for the loss of the root volume group.

 

This feature may be useful if your AIX LPAR experiences a loss of SAN connectivity e.g. total loss of access to SAN storage and/or all SAN switches. Typically, when this happens, AIX will continue to run, in memory for a period of time and will not immediately crash. Often you can still log on to the AIX system but if you attempt to write a file you’ll see in I/O error. But even then the system may (potentially) remain up. When the SAN issue is resolved the AIX system may continue running, with file systems in read-only mode (or not, it depends) but to really resolve the issue you would still need to reboot the AIX LPAR in order for it regain access to its disks. This can result in the need to run fsck against file systems. Note that the behaviour you encounter will be impacted by a variety of factors, such as length and type of outage. As always, your mileage may vary!

 

You can encounter this behaviour with both VSCSI and NPIV SAN booted LPARs. This new AIX VG option, which caters for the scenario described above, is not enabled by default. From the chvg man page:

 

“-r y | n                      Changes the critical volume group (VG) option of the volume group.

 

n                                  Disables the critical VG option of the volume group.

 

y                                  Enables the critical VG option of the volume group. If the volume group is set

to the critical VG, any I/O request failure starts the Logical Volume Manager

(LVM) metadata write operation to check the state of the disk before

returning the I/O failure. If the critical VG option is set to rootvg and if the

volume group losses access to quorum set of disks (or all disks if quorum

disabled), instead of moving the VG to an offline state, the node is crashed

and a message is displayed on the console.”

 

PowerHA also caters for and supports this now....and should already be enabled by default. You want this feature enabled for your HA clusters so that they respond appropriately to loss of the root volume group and initiate a failover.

 

smitty sysmirror -> Custom Cluster Configuration -> Events -> System Events -> Change/Show Event Response (smitty cm_change_show_sys_event)

 

                     Change/Show Event Response

 

Type or select values in entry fields.

Press Enter AFTER making all desired changes.

 

                        [Entry Fields]

* Event Name            ROOTVG                 +

 

* Response              Log event and reboot   +

* Active                Yes                    +

 

"Exploitation of LVM rootvg failure monitoring

 

AIX LVM has recently added the capability to change a volume group to be a known as critical volume group. Though PowerHA has allowed critical volume groups in the past, that

only applied to non-operating system/data volume groups. PowerHA v7.2 now also takes advantage of this functionality specifically for rootvg. If the volume group is set to the critical VG, any I/O request failure starts the Logical Volume Manager (LVM) metadata write operation to check the state of the disk before returning the I/O failure. If the critical VG option is set to rootvg and if the volume group losses access to quorum set of disks (or all disks if quorum is disabled), instead of moving the VG to an offline state, the node is crashed and a message is displayed on the console. You can set and validate rootvg as a critical volume group by executing the commands shown below. The command has to run once since we are using the CAA distributed command clcmd.

 

# clcmd chvg -r y rootvg

# clcmd lsvg rootvg |grep CRIT

DISK BLOCK SIZE: 512 CRITICAL VG: yes

DISK BLOCK SIZE: 512 CRITICAL VG: yes"

 

To test this new feature in my lab, I simulated a disk "failure" or accidental unmapping/removal of a rootvg disk from an LPAR.

 

On the AIX LPAR, prior to disk failure simulation, I turn on the “CRITICAL VG” option for rootvg.

 

# oslevel -s

7200-00-00-0000

 

# lsvg rootvg | grep CRIT

DISK BLOCK SIZE:    512                      CRITICAL VG:    no

 

# chvg -r y rootvg

 

# lsvg rootvg | grep CRIT

DISK BLOCK SIZE:    512                      CRITICAL VG:    yes

 

On the VIOS, I unmap the rootvg disk from the corresponding vhost adapter:

 

$ lsmap -vadapter vhost30

SVSA            Physloc                                      Client Partition ID

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

vhost30         U8286.42A.214F58V-V2-C38                     0x0000001d

 

VTD                   vtscsi59

Status                Available

LUN                   0x8100000000000000

Backing device        volume-AIX71LabImage-b8588f28-00000033-boot--26bf124d-40b3.acc7e518f3f561d4719fcecfff88b0f1

Physloc

Mirrored              N/A

 

VTD                   vtscsi60

Status                Available

LUN                   0x8200000000000000

Backing device        volume-AIX71LabImage-b8588f28-00000033-data--1830bd26-ba42.81823bdb90537250b95b3b2f35bb55f9

Physloc

Mirrored              N/A

 

$ lu -list | grep volume-A | grep Lab

volume-AIX71LabImage-b~ 10240       7790        acc7e518f3f561d4719fcecfff88b0f1

volume-AIX71LabImage-b~ 1024        1021        81823bdb90537250b95b3b2f35bb55f9

 

$ lu -unmap -luudid acc7e518f3f561d4719fcecfff88b0f1

 

$ lsmap -vadapter vhost30

SVSA            Physloc                                      Client Partition ID

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

vhost30         U8286.42A.214F58V-V2-C38                     0x0000001d

 

VTD                   vtscsi60

Status                Available

LUN                   0x8200000000000000

Backing device        volume-AIX71LabImage-b8588f28-00000033-data--1830bd26-ba42.81823bdb90537250b95b3b2f35bb55f9

Physloc

Mirrored              N/A

 

On the AIX LPAR, I attempt to create (write) a file in /tmp (which resides in rootvg):

 

# touch /tmp/mynewfile

 

The LPAR stops responding immediately. I can no longer connect or login to it.

 

I then remap the disk and restart the LPAR. The AIX error report shows that the system halted due a critical VG going offline.

 

$ lu -map -luudid acc7e518f3f561d4719fcecfff88b0f1 -vadapter vhost30

 

$ lsmap -vadapter vhost30

SVSA            Physloc                                      Client Partition ID

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

vhost30         U8286.42A.214F58V-V2-C38                     0x0000001d

 

VTD                   vtscsi59

Status                Available

LUN                   0x8100000000000000

Backing device        volume-AIX71LabImage-b8588f28-00000033-boot--26bf124d-40b3.acc7e518f3f561d4719fcecfff88b0f1

Physloc

Mirrored              N/A

 

VTD                   vtscsi60

Status                Available

LUN                   0x8200000000000000

Backing device        volume-AIX71LabImage-b8588f28-00000033-data--1830bd26-ba42.81823bdb90537250b95b3b2f35bb55f9

Physloc

Mirrored              N/A

 

# errpt -a

...

LABEL:          KERNEL_PANIC

IDENTIFIER:     225E3B63

 

Date/Time:       Wed Mar  1 14:27:51 AEDT 2017

Sequence Number: 215

Machine Id:      00F94F584C00

Node Id:         aix72lab

Class:           S

Type:            TEMP

WPAR:            Global

Resource Name:   PANIC

 

Description

SOFTWARE PROGRAM ABNORMALLY TERMINATED

 

        Recommended Actions

        PERFORM PROBLEM DETERMINATION PROCEDURES

 

Detail Data

ASSERT STRING

 

PANIC STRING

Critical VG Force off, halting.

 

This feature is available with AIX 6.1 or later.

 

IV52743: ADD CRITICAL VG SUPPORT FOR ROOTVG APPLIES TO AIX 7100-03

http://www-01.ibm.com/support/docview.wss?uid=isg1IV52743

 

Whilst working with one of my AIX customers recently I discovered a problem with NIMSH and SSL. The customer had updated their NIM master from AIX 7.1 TL4 SP1 to AIX 7.1 TL4 SP3. After the SP update, any attempt to connect to a NIM client (over NIMSH+SSL), from the NIM master, would simply hang. For example, we tried to list the filesets on the NIM client with this command, which never returned any output.

 

[root@750lpar4]/ # nim -o lslpp 750lpar9

 

The /var/adm/ras/nimsh.log file, on the NIM client, showed that the NIMSH session stopped here:

 

…

Thu Jan 12 14:31:49 2017        Loading certificates..

Thu Jan 12 14:31:49 2017        Loading private key file..

Thu Jan 12 14:31:49 2017        create BIO

…

 

NIM master: 750lpar4

7100-04-03-1543

 

NIM client: 750lpar9

7100-04-02-1614

 

[root@750lpar4]/ # lsnim -l 750lpar9

750lpar9:

   class          = machines

   type           = standalone

   connect        = nimsh (secure)

   platform       = chrp

   netboot_kernel = 64

   if1            = 10_1_50 750lpar9 0

   cable_type1    = N/A

   Cstate         = ready for a NIM operation

   prev_state     = not running

   Mstate         = currently running

   cpuid          = 00F603CD4C00

   Cstate_result  = success

 

The root cause of the problem become apparent when we ran truss against the nim –o command.

 

[root@750lpar4]/ # truss -adef -o truss.lsnim.out -w all nim -o lslpp 750lpar9

 

[root@750lpar4]/ # cat truss.lsnim.out

…

13959372: C o u l d   n o t   l o a d   m o d u l e   / u s r / l i b / l

13959372: i b s s l . s o .\n S y s t e m   e r r o r :   N o   s u c h

13959372: f i l e   o r   d i r e c t o r y

…

19267612: C o u l d   n o t   l o a d   m o d u l e   / u s r / l i b / l

19267612: i b c r y p t o . s o .\n S y s t e m   e r r o r :   N o   s u

19267612: c h   f i l e   o r   d i r e c t o r y

 

The required shared library object files were missing on the NIM master.

 

[root@750lpar4]/usr/lib # ls -ltr libssl.so libcrypto.so

libssl.so not found

libcrypto.so not found

 

We fixed this issue by extracting the missing files from the (existing) /usr/lib/libssl.a and /usr/lib/libcrypto.a archives.

 

[root@750lpar4]/usr/lib # slibclean

 

[root@750lpar4]/usr/lib # /bin/ar -v -x /usr/lib/libssl.a /usr/lib/libssl.so

x - /usr/lib/libssl.so

 

[root@750lpar4]/usr/lib # /bin/ar -v -x /usr/lib/libcrypto.a /usr/lib/libcrypto.so

x - /usr/lib/libcrypto.so

 

[root@750lpar4]/usr/lib # ls -ltr libssl.so libcrypto.so

-rwxr-xr-x    1 root     system       724913 Jan 18 09:08 libssl.so

-rwxr-xr-x    1 root     system      3031337 Jan 18 09:08 libcrypto.so

 

After that, the nim –o commands started working again.

 

[root@750lpar4]/usr/lib # nim -o showlog 750lpar9

HELLO

 

So, the question is why did this happen? Well, in the past, the libssl.so.0.9.8 shared object was extracted by NIM, but more recent updates by the OpenSSL version has forced IBM to move to libssl.so. Usually, the extracted shared library object is added (if not currently present) when nimconfig -c is run.  But given that this is an existing NIM master, we did not want to run this again (as we would lose all of the current SSL key access). So extracting the objects is preferred. The problem is due to the fact that the libssl.so and libcrypto.so files are not populated when the AIX 7100-04-03 update is applied. This is a bug and will be officially addressed, soon, under APAR IV93152 NIM push operation to client hang on nimsh over SSL.

 

I believe this issue may also occur when you migrate your NIM master from AIX 7.1 to 7.2 (with nimadm for example). But I need to do more testing to reproduce and confirm the issue.

 

Here’s one good reason to setup NIMSH over SSL.

 

NIMSH, SSL and LPM

https://www.ibm.com/developerworks/community/blogs/cgaix/entry/NIMSH_SSL_and_LPM?lang=en

 

The following link is a great reference guide for configuring NIMSH over SSL.

 

NIMSH over SSL

http://www-01.ibm.com/support/docview.wss?uid=isg3T1024615

 

 

 

Recently I've come across an odd issue at two different customers. I thought I'd share the experience, in case others also come across this strange behaviour.

 

In both cases they reported j2pg high CPU usage.

 

Similar to this...

 

And, in both cases, we discovered many /usr/sbin/update processes running. Unexpectedly.

 

When we stopped these processes, j2pg's CPU consumption dropped to nominal levels.

 

The j2pg process is responsible for, among other things, flushing data to disk and is called by the sync(d) process.

 

The /usr/sbin/update command is just a script that calls sync in a loop. Its purpose it to "..periodically update the super block., ..execute a sync subroutine every 30 seconds. This action ensures the file system is up-to-date in the event of a system crash".

 

http://www.ibm.com/support/knowledgecenter/ssw_aix_71/com.ibm.aix.cmds5/update.htm

 

# cat /usr/sbin/update

...BLAH...

PATH=/usr/bin:/usr/sbin:/etc

 

while true

do

sync

sleep 30

done &

exit 0

 

Because of the large number of /usr/sbin/update (sync) processes (in some cases over 150 of them), j2pg was constantly kept busy, assisting with flushing data to disk.

 

It appears that the application team (in both cases) was attempting to perform some sort of SQL "update" but due to an issue with their shell environment/PATH setting they were calling /usr/sbin/update instead of the intended update (or UPDATE) command. And yes, a non-root user can call /usr/sbin/update - no problem. So, in the "ps -ef" output we found processes that looked similar to this:

 

fred 50791260 1 0 Jan 09 - 0:04 /usr/bin/bsh /usr/sbin/update prd_ctl_q_and_p.af_data_obj set as_of_dt=2016-12-09 00:00:00.000000 where DATA_OBJ_NM like %LOANIQ%20161209%

 

# ls -ltr /usr/sbin/update

-r-xr-xr-x    1 bin      bin             943 Aug 17 2011  /usr/sbin/update

The application teams were directed to fix their scripts to prevent them calling /usr/sbin/update and instead call the correct command.

 

And here’s some information (more than you’ll probably ever need to know) about j2pg on AIX.

 

"j2pg - Kernel process integral to processing JFS2 I/O requests.

The kernel thread is responsible of managing I/Os in JFS2 filesystems,
so it is normal to see it running in case of lot of I/Os or syncd.

And we could see that j2pg runs syncHashList() very often.The sync is
done in syncHashList(). In syncHashList(), all inodes are extracted from hash
list. And whether the inode needs to synchronize or not is then judged
by iSyncNeeded().

** note that a sync() call will cause the system to scan *all* the
memory currently used for filecaching to see which pages are dirty
and have to be synced to disk

Therefore, the cause of j2pg having this spike is determined by the
two calls that were being made (iSyncNeeded ---> syncHashList). What is
going on here is a flush/sync of the JFS2 metadata to disk. Apparently
some program went recursively through the filesystem accessing files
forcing the inode access timestamp to change. These changes would have
to propogated to the disk.

Here's a few reasons why j2pg would be active and consume high CPU:
1. If there several process issuing sync then the j2pg process will be
very active using cpu resources.
2. If there is file system corruption then the j2pg will use more cpu
resources.
3. If the storage is not running data fast enough then the j2pg process
will be using high amount of cpu resources.

j2pg will get started for any JFS2 dir activity.
Another event that can cause j2pg activity, is syncd.
If the system experiences a lot of JFS2 dir activity, the j2pg process
will also be active handling the I/O.
Since syncd flushes I/O from real memory to disk, then any JFS2 dir's
with files in the buffer will also be hit."

"Checking the syncd...

From data, we see:
$ grep -c sync psb.elfk
351 << this is high
$ grep sync psb.elfk | grep -c oracle
348 << syncd called by Oracle user only

It appears that the number of sync which causes j2pg
to run is causing spikes.

We see:
/usr/sbin/syncd 60

J2pg is responsible for flushing data to disk and is
usually called by the syncd process. If you have a
large number of sync processes running on the system,
that would explain the high CPU for j2pg

The syncd setting determines the frequency with which
the I/O disk-write buffers are flushed.

The AIX default value for syncd as set in /sbin/rc.boot
is 60. It is recommended to change this value to 10.

This will cause the syncd process to run more often
and not allow the dirty file pages to accumulate,
so it runs more frequently but for shorter period of
time. If you wish to make this permanent then edit
the /sbin/rc.boot file and change to the 60 to 10.

You may consider mounting all of the
non-rootvg file systems with the 'noatime' option.
This can be done without any outage:

However selecting a non-peak production hours is better:

Use the commands below: For Example:
# mount -o remount,noatime /oracle
Then use chfs to make is persistent:
# chfs -a options=noatime /oracle

- noatime -
Turns off access-time updates. Using this option can
improve performance on file systems where a large
number of files are read frequently and seldom updated.
If you use the option, the last access time for a file
cannot be determined. If neither atime nor noatime is
specified, atime is the default value."