open-power / op-build

Buildroot overlay for Open Power
GNU General Public License v2.0
105 stars 183 forks source link

Petitboot menu loses shows no entries fails on every maas deployments for Firestone following PSU Fault 2 and PSU Fault 1 #725

Open larrymi opened 8 years ago

larrymi commented 8 years ago

The issue described below has been recreated. Basically, after multiple maas deployments, the boot order is gone.

When it first occurred on 10/18, there was a single entry for the disk but no entries for the network devices. This time there is not a single entry.

It should be noted that for the first occurrence that the issue went away after doing a hard power cycle from remote PDUs on 10/25. In other words, we did the equivalent of unplugging the system and plugging it back in.

The maas deployments are with MAAS 2.1 but it was originally hit while using MAAS 2.0. A curtin preseed workaround has been in place since 4/13 as noted in https://bugs.launchpad.net/maas/+bug/1558747.

System last deployed successfully at ~00:05UTC per maas event log:

----------------------------------------------------------------------------------------------------------
Node changed status - From 'Deploying' to 'Deployed'    Fri, 04 Nov. 2016 00:05:20
----------------------------------------------------------------------------------------------------------

The subsequent install fails:

----------------------------------------------------------------------------------------------------------
Node changed status - From 'Deploying' to 'Failed deployment'   Fri, 04 Nov. 2016 02:46:28
Marking node failed - Machine operation 'Deploying' timed out after 40 minutes. Fri, 04 Nov. 2016 02:46:28
----------------------------------------------------------------------------------------------------------

Per the event log extracted from the web console, those events below are the last one shown (extracted at 1130 UTC). Strangely, there are no other events shown after 7634 and 7633 which could be indication of underlying issue that leads to current state of the system. Timestamp do seem to match timestamps on the maas event logs (last successful deployment and first failed deployment).

----------------------------------------------------------------------------------------------------------
7634    11/04/2016 00:41:30 PSU Fault 1 Power Supply    Power Supply Input Lost (AC/DC) - Asserted
7633    11/04/2016 00:09:34 PSU Fault 2 Power Supply    Power Supply Input Lost (AC/DC) - Deasserted
7632    11/04/2016 00:04:03 FW Boot Progress    BIOS POST Progress  Progress-Secondary processor(s) initialization. - Asserted
7631    11/04/2016 00:03:55 FW Boot Progress    BIOS POST Progress  Progress-PCI resource configuration. - Asserted
7630    11/04/2016 00:03:51 FW Boot Progress    BIOS POST Progress  Progress-User authentication. - Asserted
7629    11/04/2016 00:03:25 FW Boot Progress    BIOS POST Progress  Progress-Secondary processor(s) initialization. - Asserted
7628    11/04/2016 00:03:24 FW Boot Progress    BIOS POST Progress  Progress-Secondary processor(s) initialization. - Asserted
7627    11/04/2016 00:03:16 FW Boot Progress    BIOS POST Progress  Progress-Memory initialization. - Asserted
7626    11/04/2016 00:02:54 FW Boot Progress    BIOS POST Progress  Progress-User authentication. - Asserted
7625    11/03/2016 23:56:26 FW Boot Progress    BIOS POST Progress  Progress-Secondary processor(s) initialization. - Asserted
7624    11/03/2016 23:56:21 FW Boot Progress    BIOS POST Progress  Progress-PCI resource configuration. - Asserted
7623    11/03/2016 23:56:15 FW Boot Progress    BIOS POST Progress  Progress-User authentication. - Asserted
7622    11/03/2016 23:55:47 FW Boot Progress    BIOS POST Progress  Progress-Secondary processor(s) initialization. - Asserted
7621    11/03/2016 23:55:45 FW Boot Progress    BIOS POST Progress  Progress-Secondary processor(s) initialization. - Asserted
7620    11/03/2016 23:55:38 FW Boot Progress    BIOS POST Progress  Progress-Memory initialization. - Asserted
7619    11/03/2016 23:55:16 FW Boot Progress    BIOS POST Progress  Progress-User authentication. - Asserted
7618    11/03/2016 23:15:08 PSU Fault 2 Power Supply    Power Supply Input Lost (AC/DC) - Asserted
7617    11/03/2016 17:31:59 FW Boot Progress    BIOS POST Progress  Progress-Secondary processor(s) initialization. - Asserted
7616    11/03/2016 17:31:52 FW Boot Progress    BIOS POST Progress  Progress-PCI resource configuration. - Asserted
7615    11/03/2016 17:31:47 FW Boot Progress    BIOS POST Progress  Progress-User authentication. - Asserted
7614    11/03/2016 17:31:21 FW Boot Progress    BIOS POST Progress  Progress-Secondary processor(s) initialization. - Asserted
7613    11/03/2016 17:31:19 FW Boot Progress    BIOS POST Progress  Progress-Secondary processor(s) initialization. - Asserted
7612    11/03/2016 17:31:11 FW Boot Progress    BIOS POST Progress  Progress-Memory initialization. - Asserted
7611    11/03/2016 17:30:50 FW Boot Progress    BIOS POST Progress  Progress-User authentication. - Asserted
7610    11/03/2016 17:22:28 FW Boot Progress    BIOS POST Progress  Progress-Secondary processor(s) initialization. - Asserted
7609    11/03/2016 17:22:19 FW Boot Progress    BIOS POST Progress  Progress-PCI resource configuration. - Asserted
7608    11/03/2016 17:22:15 FW Boot Progress    BIOS POST Progress  Progress-User authentication. - Asserted
7607    11/03/2016 17:21:49 FW Boot Progress    BIOS POST Progress  Progress-Secondary processor(s) initialization. - Asserted
7606    11/03/2016 17:21:48 FW Boot Progress    BIOS POST Progress  Progress-Secondary processor(s) initialization. - Asserted
7605    11/03/2016 17:21:40 FW Boot Progress    BIOS POST Progress  Progress-Memory initialization. - Asserted
7604    11/03/2016 17:21:19 FW Boot Progress    BIOS POST Progress  Progress-User authentication. - Asserted
7603    11/03/2016 16:52:23 FW Boot Progress    BIOS POST Progress  Progress-Secondary processor(s) initialization. - Asserted
7602    11/03/2016 16:52:14 FW Boot Progress    BIOS POST Progress  Progress-PCI resource configuration. - Asserted
7601    11/03/2016 16:52:10 FW Boot Progress    BIOS POST Progress  Progress-User authentication. - Asserted
7600    11/03/2016 16:51:44 FW Boot Progress    BIOS POST Progress  Progress-Secondary processor(s) initialization. - Asserted
7599    11/03/2016 16:51:43 FW Boot Progress    BIOS POST Progress  Progress-Secondary processor(s) initialization. - Asserted
7598    11/03/2016 16:51:35 FW Boot Progress    BIOS POST Progress  Progress-Memory initialization. - Asserted
7597    11/03/2016 16:51:13 FW Boot Progress    BIOS POST Progress  Progress-User authentication. - Asserted
7596    11/03/2016 16:42:52 FW Boot Progress    BIOS POST Progress  Progress-Secondary processor(s) initialization. - Asserted
7595    11/03/2016 16:42:44 FW Boot Progress    BIOS POST Progress  Progress-PCI resource configuration. - Asserted
7594    11/03/2016 16:42:40 FW Boot Progress    BIOS POST Progress  Progress-User authentication. - Asserted
7593    11/03/2016 16:42:14 FW Boot Progress    BIOS POST Progress  Progress-Secondary processor(s) initialization. - Asserted
7592    11/03/2016 16:42:13 FW Boot Progress    BIOS POST Progress  Progress-Secondary processor(s) initialization. - Asserted
7591    11/03/2016 16:42:05 FW Boot Progress    BIOS POST Progress  Progress-Memory initialization. - Asserted
7590    11/03/2016 16:41:44 FW Boot Progress    BIOS POST Progress  Progress-User authentication. - Asserted
7589    11/03/2016 15:29:39 FW Boot Progress    BIOS POST Progress  Progress-Secondary processor(s) initialization. - Asserted
7588    11/03/2016 15:29:31 FW Boot Progress    BIOS POST Progress  Progress-PCI resource configuration. - Asserted
7587    11/03/2016 15:29:27 FW Boot Progress    BIOS POST Progress  Progress-User authentication. - Asserted
7586    11/03/2016 15:29:02 FW Boot Progress    BIOS POST Progress  Progress-Secondary processor(s) initialization. - Asserted
7585    11/03/2016 15:29:00 FW Boot Progress    BIOS POST Progress  Progress-Secondary processor(s) initialization. - Asserted
----------------------------------------------------------------------------------------------------------

These are critical errors in the system log that seems to correspond to the last boot (console output below):

----------------------------------------------------------------------------------------------------------
1   Nov 4 10:55:16  localhost   IPMIMain: [697 CRITICAL][OEMHooksHandler.c:1179]Device on Bus :/dev/i2c12 and Slave:71 not present
2   Nov 4 10:55:16  localhost   IPMIMain: [697 CRITICAL][OEMHooksHandler.c:1182]Device on Bus :/dev/i2c12 and Slave:72 present
3   Nov 4 10:55:16  localhost   IPMIMain: [697 CRITICAL][OEMHooksHandler.c:1182]Device on Bus :/dev/i2c12 and Slave:73 present
4   Nov 4 10:55:16  localhost   IPMIMain: [697 CRITICAL][OEMHooksHandler.c:1203]CentaurSetting::Device on Bus :/dev/i2c12 and Slave:40 not present
5   Nov 4 10:55:16  localhost   IPMIMain: [697 CRITICAL][OEMHooksHandler.c:1203]CentaurSetting::Device on Bus :/dev/i2c12 and Slave:41 not present
6   Nov 4 10:55:16  localhost   IPMIMain: [697 CRITICAL][OEMHooksHandler.c:1179]Device on Bus :/dev/i2c13 and Slave:70 not present
7   Nov 4 10:55:16  localhost   IPMIMain: [697 CRITICAL][OEMHooksHandler.c:1179]Device on Bus :/dev/i2c13 and Slave:71 not present
8   Nov 4 10:55:16  localhost   IPMIMain: [697 CRITICAL][OEMHooksHandler.c:1179]Device on Bus :/dev/i2c13 and Slave:72 not present
9   Nov 4 10:55:16  localhost   IPMIMain: [697 CRITICAL][OEMHooksHandler.c:1179]Device on Bus :/dev/i2c13 and Slave:73 not present
10  Nov 4 10:55:16  localhost   IPMIMain: [697 CRITICAL][OEMHooksHandler.c:1203]CentaurSetting::Device on Bus :/dev/i2c13 and Slave:40 not present
11  Nov 4 10:55:16  localhost   IPMIMain: [697 CRITICAL][OEMHooksHandler.c:1203]CentaurSetting::Device on Bus :/dev/i2c13 and Slave:41 not present
12  Nov 4 10:55:16  localhost   IPMIMain: [697 CRITICAL][OEMHooksHandler.c:1203]CentaurSetting::Device on Bus :/dev/i2c13 and Slave:42 not present
13  Nov 4 10:55:16  localhost   IPMIMain: [697 CRITICAL][OEMHooksHandler.c:1203]CentaurSetting::Device on Bus :/dev/i2c13 and Slave:43 not present
14  Nov 4 10:55:16  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
15  Nov 4 10:55:16  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
16  Nov 4 10:55:17  localhost   IPMIMain: [697 CRITICAL][App/AppDevice/WDT.c:144]WDTTimerTask : pBMCInfo->HostOFFStopWDT = 1
17  Nov 4 10:55:17  localhost   IPMIMain: [697 CRITICAL][App/AppDevice/WDT.c:150]WDTTimerTask : pBMCInfo->HostOFFStopWDT = 0
18  Nov 4 10:55:17  localhost   IPMIMain: [697 CRITICAL][OEMHooksHandler.c:1375]set_proper_frequency_uart: Error in setting registers involves setting proper frequency for uart
19  Nov 4 10:55:19  localhost   IPMIMain: [697 CRITICAL][BTIfc.c:64] LPC Reset Occurred
20  Nov 4 10:55:22  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
21  Nov 4 10:55:22  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
22  Nov 4 10:55:27  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
23  Nov 4 10:55:27  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
24  Nov 4 10:55:27  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
25  Nov 4 10:55:28  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
26  Nov 4 10:55:28  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
27  Nov 4 10:55:28  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
28  Nov 4 10:55:28  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
29  Nov 4 10:55:28  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
30  Nov 4 10:55:28  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
31  Nov 4 10:55:29  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
32  Nov 4 10:55:29  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
33  Nov 4 10:55:29  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
34  Nov 4 10:55:29  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
35  Nov 4 10:55:29  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
36  Nov 4 10:55:29  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
37  Nov 4 10:55:30  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
38  Nov 4 10:55:30  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
39  Nov 4 10:55:30  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
40  Nov 4 10:55:30  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
41  Nov 4 10:55:30  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
42  Nov 4 10:55:30  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
43  Nov 4 10:55:31  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
44  Nov 4 10:55:31  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
45  Nov 4 10:55:31  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
46  Nov 4 10:55:31  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
47  Nov 4 10:55:31  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
48  Nov 4 10:55:31  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
49  Nov 4 10:55:32  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
50  Nov 4 10:55:32  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
51  Nov 4 10:55:32  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
52  Nov 4 10:55:32  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
53  Nov 4 10:55:32  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
54  Nov 4 10:55:36  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
55  Nov 4 10:55:36  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
56  Nov 4 10:55:36  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
57  Nov 4 10:55:36  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
58  Nov 4 10:55:36  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
59  Nov 4 10:55:43  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
60  Nov 4 10:55:51  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
61  Nov 4 10:55:52  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
62  Nov 4 10:56:02  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
63  Nov 4 10:56:02  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
64  Nov 4 10:56:18  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
65  Nov 4 10:56:20  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
66  Nov 4 10:56:31  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
67  Nov 4 10:56:31  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
68  Nov 4 10:56:31  localhost   IPMIMain: [697 CRITICAL][OEMCmdsHelper.c:1484]Failed in Writing the NVR File
----------------------------------------------------------------------------------------------------------

From the audit log:

----------------------------------------------------------------------------------------------------------
1   Oct 25 17:54:53 localhost   IPMIMain: [697 INFO][SATLOG] Sensor Number: 0xce : One of these bits 0xffffff3e got asserted for this sensor.
2   Oct 25 17:54:53 localhost   IPMIMain: [697 INFO][LEDACTION] Sensor Number: 0xce : Turning ON Fault LED.
3   Oct 25 17:54:56 localhost   IPMIMain: [697 INFO][LEDACTION] Sensor Number: 0xce : Turning OFF Fault LED.
4   Oct 25 23:13:02 localhost   IPMIMain: [697 INFO][SATLOG] Sensor Number: 0xce : One of these bits 0xffffff3e got asserted for this sensor.
5   Oct 25 23:13:02 localhost   IPMIMain: [697 INFO][LEDACTION] Sensor Number: 0xce : Turning ON Fault LED.
6   Oct 25 23:13:05 localhost   IPMIMain: [697 INFO][LEDACTION] Sensor Number: 0xce : Turning OFF Fault LED.
7   Nov 3 23:15:11  localhost   IPMIMain: [697 INFO][SATLOG] Sensor Number: 0xce : One of these bits 0xffffff3e got asserted for this sensor.
8   Nov 3 23:15:11  localhost   IPMIMain: [697 INFO][LEDACTION] Sensor Number: 0xce : Turning ON Fault LED.
9   Nov 4 00:09:37  localhost   IPMIMain: [697 INFO][LEDACTION] Sensor Number: 0xce : Turning OFF Fault LED.
----------------------------------------------------------------------------------------------------------

Below is the console output:

1.68760|ERRL|Dumping errors reported prior to registration
  3.45447|Ignoring boot flags, incorrect version 0x0
  3.69549|ISTEP  6. 3
  4.13398|ISTEP  6. 4
  4.13482|ISTEP  6. 5
  7.94156|HWAS|PRESENT> DIMM[03]=00000000AAAA0000
  7.94157|HWAS|PRESENT> Membuf[04]=0C00000000000000
  7.94157|HWAS|PRESENT> Proc[05]=C000000000000000
 20.69739|ISTEP  6. 6
 20.78604|ISTEP  6. 7
 20.78667|ISTEP  6. 8
 20.81641|ISTEP  6. 9
 23.41379|ISTEP  6.10
 23.46115|ISTEP  6.11
 25.21539|ISTEP  6.12
 25.21648|ISTEP  6.13
 25.21731|ISTEP  7. 1
 25.27388|ISTEP  7. 2
 25.38960|ISTEP  7. 3
 25.41675|ISTEP  7. 4
 25.45579|ISTEP  7. 5
 25.64747|ISTEP  7. 6
 25.67591|ISTEP  7. 7
 25.88581|ISTEP  7. 8
 26.02574|ISTEP  7. 9
 26.02627|ISTEP  8. 1
 26.19268|ISTEP  8. 2
 27.00470|ISTEP  8. 3
 27.01470|ISTEP  8. 4
 27.24980|ISTEP  8. 5
 27.25079|ISTEP  8. 6
 27.82594|ISTEP  8. 7
 27.82641|ISTEP  8. 8
 27.83808|ISTEP  9. 1
 28.20900|ISTEP  9. 2
 28.79637|ISTEP 10. 1
 29.14610|ISTEP 10. 2
 29.71266|ISTEP 10. 3
 29.71340|ISTEP 10. 4
 29.71426|ISTEP 10. 5
 29.71482|ISTEP 10. 6
 29.71543|ISTEP 10. 7
 29.71626|ISTEP 10. 8
 29.71692|ISTEP 10. 9
 29.71748|ISTEP 10.10
 29.71826|ISTEP 10.11
 29.71889|ISTEP 10.12
 29.71946|ISTEP 10.13
 29.72027|ISTEP 10.14
 29.72083|ISTEP 11. 1
 29.98855|ISTEP 11. 2
 29.98931|ISTEP 11. 3
 30.14035|ISTEP 11. 4
 30.21257|ISTEP 11. 5
 30.34714|ISTEP 11. 6
 30.99457|ISTEP 11. 7
 30.99583|ISTEP 11. 8
 31.19726|ISTEP 11. 9
 31.19826|ISTEP 11.10
 31.26071|ISTEP 11.11
 31.26135|ISTEP 11.12
 31.26213|ISTEP 11.13
 31.26425|ISTEP 12. 1
 31.36637|ISTEP 12. 2
 31.44808|ISTEP 12. 3
 31.47923|ISTEP 12. 4
 31.75743|ISTEP 12. 5
 31.75819|ISTEP 13. 1
 31.85192|ISTEP 13. 2
 31.88343|ISTEP 13. 3
 31.90415|ISTEP 13. 4
 31.93550|ISTEP 13. 5
 31.93821|ISTEP 13. 6
 32.67465|ISTEP 13. 7
 32.83238|ISTEP 13. 8
 32.98321|ISTEP 13. 9
 33.89127|ISTEP 13.10
 33.91314|ISTEP 13.11
 33.99076|ISTEP 13.12
 33.99169|ISTEP 14. 1
 34.02302|ISTEP 14. 2
 34.03365|ISTEP 14. 3
 36.00666|ISTEP 14. 4
 36.03845|ISTEP 14. 5
 36.10044|ISTEP 14. 6
 36.10131|ISTEP 14. 7
 36.19342|ISTEP 14. 8
 36.19526|ISTEP 15. 1
 38.22430|ISTEP 15. 2
 38.23583|ISTEP 15. 3
 38.36112|ISTEP 16. 1
 39.53477|ISTEP 16. 2
 39.90167|ISTEP 16. 3
 39.91682|ISTEP 16. 4
 39.93002|ISTEP 18.13
 40.31547|ISTEP 18.14
 40.33768|ISTEP 21. 1
 51.28653|htmgt|OCCs are now running in ACTIVE state
 59.14588|ISTEP 21. 2
 59.13840|ISTEP 21. 3
[31509188636,5] SkiBoot skiboot-5.1.13 starting...
[31509192260,5] initial console log level: memory 7, driver 5
[31509194960,6] CPU: P8 generation processor(max 8 threads/core)
[31509197494,7] CPU: Boot CPU PIR is 0x0450 PVR is 0x004d0200
[31509200268,7] CPU: Initial max PIR set to 0x1fff
[31510280347,5] OPAL table: 0x300a0840 .. 0x300a0cb0, branch table: 0x30002000
[31510289399,5] FDT: Parsing fdt @0xff00000
[31514753901,5] XSCOM: chip 0x0 at 0x3fc0000000000 [P8 DD2.0]
[31514762602,5] XSCOM: chip 0x8 at 0x3fc4000000000 [P8 DD2.0]
[31514769362,6] XSTOP: XSCOM addr = 0x2010c82, FIR bit = 31
[31514772277,6] MFSI 0:0: Initialized
[31514774136,6] MFSI 0:2: Initialized
[31514775974,6] MFSI 0:1: Initialized
[31514778163,6] MFSI 8:0: Initialized
[31514780038,6] MFSI 8:2: Initialized
[31514781894,6] MFSI 8:1: Initialized
[31515029064,5] LPC: Bus on chip 0 PCB_Addr=0xb0020
[31515041856,5] LPC: Default bus on chip 0
[31515146327,6] MEM: parsing reserved memory from node /ibm,hostboot/reserved-memory
[31515157080,7] HOMER: Init chip 0
[31515159637,7]   PBA BAR0 : 0x00000007fd800000
[31515162036,7]   PBA MASK0: 0x0000000000300000
[31515164418,7]   HOMER Image at 0x7fd800000 size 4MB
[31515167776,7]   PBA BAR2 : 0x40000007fda00000
[31515170149,7]   PBA MASK2: 0x0000000000000000
[31515172364,7]   SLW Image at 0x7fda00000 size 1MB
[31515175670,7]   PBA BAR3 : 0x00000007ff800000
[31515178022,7]   PBA MASK3: 0x0000000000700000
[31515180434,7]   OCC Common Area at 0x7ff800000 size 8MB
[31515183023,7] HOMER: Init chip 8
[31515185370,7]   PBA BAR0 : 0x00000007fdc00000
[31515187698,7]   PBA MASK0: 0x0000000000300000
[31515189955,7]   HOMER Image at 0x7fdc00000 size 4MB
[31515193173,7]   PBA BAR2 : 0x40000007fde00000
[31515195558,7]   PBA MASK2: 0x0000000000000000
[31515197761,7]   SLW Image at 0x7fde00000 size 1MB
[31515200894,7]   PBA BAR3 : 0x00000007ff800000
[31515203226,7]   PBA MASK3: 0x0000000000700000
[31515205506,7]   OCC Common Area at 0x7ff800000 size 8MB
[31515365238,7] AST: PNOR LPC offset: 0x0c000000
[31515442732,5] PLAT: Using virtual UART
[31523379566,5] PLAT: Detected Firestone platform
[31542272903,5] CENTAUR: Found centaur for chip 0x0 channel 4
[31542360095,5] CENTAUR:   FSI host: 0x0 cMFSI0 port 7
[31542530821,5] CENTAUR: Found centaur for chip 0x0 channel 5
[31542774080,5] CENTAUR:   FSI host: 0x0 cMFSI0 port 6
[31543129071,5] PSI[0x000]: Found PSI bridge [working=1, active=0]
[31543270293,5] PSI[0x008]: Found PSI bridge [working=1, active=0]
[1038701837,5] BT: Interface initialized, IO 0x00e4
[1397725666,4] SLW: HB-provided idle states property found
[1397898831,5] NVRAM: Size is 576 KB
[1654104647,3] NVRAM: Layout appears sane
[1654460924,5] CAPI: Preloading ucode 200ea
[1654519627,5] FLASH: Queueing preload of 2/200ea
[1654747669,5] FLASH: Queueing preload of 0/0
[1654989620,7] FFS: Partition map size: 0x1000
[1656927996,7] FLASH: CAPP partition has ECC
[1659126400,7] FLASH: flash subpartition eyecatcher CAPP
[1659128599,7] FLASH: flash found subpartition: 1 size: 36432 offset 4096
[1661514669,5] FLASH: Queueing preload of 1/0
[1664153648,5] Chip 0 Found PBCQ0 at /xscom@3fc0000000000/pbcq@2012000
[1665960856,5] Chip 0 Found PBCQ1 at /xscom@3fc0000000000/pbcq@2012400
[1668160270,5] Chip 8 Found PBCQ0 at /xscom@3fc4000000000/pbcq@2012000
[1670443795,5] Chip 8 Found PBCQ1 at /xscom@3fc4000000000/pbcq@2012400
[1672636698,5] Chip 8 Found PBCQ2 at /xscom@3fc4000000000/pbcq@2012800
[1677140128,3] PHB0: Base location code not found !
[2206310045,3] PHB1: Base location code not found !
[3176413537,3] PHB2: Base location code not found !
[4150136661,3] PHB3: Base location code not found !
[4716977151,3] PHB4: Base location code not found !
[5933793805,5] PCI: Resetting PHBs...
[8691027482,3] FLASH: No ROOTFS partition
[9788073818,5] PCI: Probing slots...
[9788190560,5] PHB0:00:00.0 [ROOT] 1014 03dc R:00 C:060400 B:00..00 SLOT=Slot5 
[9788325006,5] PHB1:00:00.0 [ROOT] 1014 03dc R:00 C:060400 B:00..00 SLOT=Slot4 
[9788574367,5] PHB2:00:00.0 [ROOT] 1014 03dc R:00 C:060400 B:00..00 SLOT=Slot2 
[9788881734,5] PHB3:00:00.0 [ROOT] 1014 03dc R:00 C:060400 B:00..00 SLOT=Backplane PLX 
[9789116799,5] PHB4:00:00.0 [ROOT] 1014 03dc R:00 C:060400 B:00..00 SLOT=Slot1 
[9789349801,5] Releasing unused memory:
[9789495370,5]     ibm,firmware-heap: 2797272/13631488 used
[9789675982,5]     ibm,firmware-allocs-memory@0: 20709888/33390854144 used
[9789893153,5] Reserved regions:
[9789934616,5]   0x0007ff800000..0007ffffffff : ibm,occ-common-area@7ff800000
[9800586542,5]   0x0007fdc00000..0007fdffffff : ibm,homer-image@7fdc00000
[9800847435,5]   0x0007fd800000..0007fdbfffff : ibm,homer-image@7fd800000
[9801116720,5]   0x0007fd700000..0007fd7fffff : ibm,hbrt-vpd-image@7fd700000
[9801371286,5]   0x0007fd6d0000..0007fd6fffff : ibm,hbrt-target-image@7fd6d0000
[9801654428,5]   0x0007fd470000..0007fd6cffff : ibm,hbrt-code-image@7fd470000
[9801913436,5]   0x000031c00000..000032d9ffff : ibm,firmware-stacks
[9802148895,5]   0x000031000000..000031bfffff : ibm,firmware-data
[9802369583,5]   0x000030300000..000030ffffff : ibm,firmware-heap
[9802765206,5]   0x000030000000..0000302fffff : ibm,firmware-code
[9802997751,5]   0x000039c00000..00003afc01ff : ibm,firmware-allocs-memory@0
[9803270417,5] IPMI: Resetting boot count on successful boot
[9803492909,5] INIT: Waiting for kernel...
[9803546623,5] INIT: Kernel loaded, size: 15728640 bytes (0 = unknown preload)
[9803995423,5] INIT: 64-bit LE kernel discovered
[9804055374,5] INIT: 64-bit kernel entry at 0x20010000
[9804274461,5] OCC: All Chip Rdy after 0 ms
[9823518839,5] Free space in HEAP memory regions:
[9823627245,5] Region ibm,firmware-heap free: 9d6980
[9823747234,5] Region ibm,firmware-allocs-memory@0 free: 1c0a70
[9823981167,5] Total free: 12153840
[9824144113,5] INIT: Starting kernel at 0x20010000, fdt at 0x305acdc0 (size 0x1456c)
[9927563368,3] OPAL: Trying a CPU re-init with flags: 0x2
[    0.000000] opal: OPAL V3 detected !
[    0.000000] Using PowerNV machine description
[    0.000000] Page sizes from device-tree:
[    0.000000] base_shift=12: shift=12, sllp=0x0000, avpnm=0x00000000, tlbiel=1, penc=0
[    0.000000] base_shift=12: shift=16, sllp=0x0000, avpnm=0x00000000, tlbiel=1, penc=7
[    0.000000] base_shift=12: shift=24, sllp=0x0000, avpnm=0x00000000, tlbiel=1, penc=56
[    0.000000] base_shift=16: shift=16, sllp=0x0110, avpnm=0x00000000, tlbiel=1, penc=1
[    0.000000] base_shift=16: shift=24, sllp=0x0110, avpnm=0x00000000, tlbiel=1, penc=8
[    0.000000] base_shift=20: shift=20, sllp=0x0130, avpnm=0x00000000, tlbiel=0, penc=2
[    0.000000] base_shift=24: shift=24, sllp=0x0100, avpnm=0x00000001, tlbiel=0, penc=0
[    0.000000] base_shift=34: shift=34, sllp=0x0120, avpnm=0x000007ff, tlbiel=0, penc=3
[    0.000000] Using 1TB segments
[    0.000000] OPAL: Power8 LPC bus found, chip ID 0
[    0.000000] bootconsole [udbg0] enabled
[    0.000000] CPU maps initialized for 8 threads per core
 -> smp_release_cpus()
spinning_secondaries = 127
 <- smp_release_cpus()
[    0.000000] Starting Linux ppc64le #0 SMP Thu Mar 10 18:39:34 CST 2016
[    0.000000] -----------------------------------------------------
[    0.000000] ppc64_pft_size    = 0x0
[    0.000000] phys_mem_size     = 0x800000000
[    0.000000] cpu_features      = 0x077c7aed18500249
[    0.000000]   possible        = 0x1f7fffef18500649
[    0.000000]   always          = 0x0000000018100040
[    0.000000] cpu_user_features = 0xdc0065c7 0xae000000
[    0.000000] mmu_features      = 0x7c000003
[    0.000000] firmware_features = 0x0000000430000000
[    0.000000] htab_address      = 0xc0000007fa000000
[    0.000000] htab_hash_mask    = 0x3ffff
[    0.000000] -----------------------------------------------------
 <- setup_system()
[    0.000000] Linux version 4.4.3-openpower2 (fspbld@gfwa606.aus.stglabs.ibm.com) (gcc version 4.9.2 (Buildroot 2015.05-g6408c7e) ) #0 SMP Thu Mar 10 18:39:34 CST 2016
[    0.000000] Initializing IODA2 OPAL PHB /pciex@3fffe40000000
[    0.000000] PCI host bridge /pciex@3fffe40000000 (primary) ranges:
[    0.000000]  MEM 0x00003fe000000000..0x00003fe07ffeffff -> 0x0000000080000000 
[    0.000000]  MEM64 0x0000200000000000..0x000020ffffffffff -> 0x0000200000000000
[    0.000000]   256 (255) PE's M32: 0x80000000 [segment=0x800000]
[    0.000000]                  M64: 0x10000000000 [segment=0x100000000]
[    0.000000] Initializing IODA2 OPAL PHB /pciex@3fffe40100000
[    0.000000] PCI host bridge /pciex@3fffe40100000  ranges:
[    0.000000]  MEM 0x00003fe080000000..0x00003fe0fffeffff -> 0x0000000080000000 
[    0.000000]  MEM64 0x0000210000000000..0x000021ffffffffff -> 0x0000210000000000
[    0.000000]   256 (255) PE's M32: 0x80000000 [segment=0x800000]
[    0.000000]                  M64: 0x10000000000 [segment=0x100000000]
[    0.000000] Initializing IODA2 OPAL PHB /pciex@3fffe41000000
[    0.000000] PCI host bridge /pciex@3fffe41000000  ranges:
[    0.000000]  MEM 0x00003fe800000000..0x00003fe87ffeffff -> 0x0000000080000000 
[    0.000000]  MEM64 0x0000240000000000..0x000024ffffffffff -> 0x0000240000000000
[    0.000000]   256 (255) PE's M32: 0x80000000 [segment=0x800000]
[    0.000000]                  M64: 0x10000000000 [segment=0x100000000]
[    0.000000] Initializing IODA2 OPAL PHB /pciex@3fffe41100000
[    0.000000] PCI host bridge /pciex@3fffe41100000  ranges:
[    0.000000]  MEM 0x00003fe880000000..0x00003fe8fffeffff -> 0x0000000080000000 
[    0.000000]  MEM64 0x0000250000000000..0x000025ffffffffff -> 0x0000250000000000
[    0.000000]   256 (255) PE's M32: 0x80000000 [segment=0x800000]
[    0.000000]                  M64: 0x10000000000 [segment=0x100000000]
[    0.000000] Initializing IODA2 OPAL PHB /pciex@3fffe41200000
[    0.000000] PCI host bridge /pciex@3fffe41200000  ranges:
[    0.000000]  MEM 0x00003fe900000000..0x00003fe97ffeffff -> 0x0000000080000000 
[    0.000000]  MEM64 0x0000260000000000..0x000026ffffffffff -> 0x0000260000000000
[    0.000000]   256 (255) PE's M32: 0x80000000 [segment=0x800000]
[    0.000000]                  M64: 0x10000000000 [segment=0x100000000]
[    0.000000] OPAL nvram setup, 589824 bytes
[    0.000000] Zone ranges:
[    0.000000]   DMA      [mem 0x0000000000000000-0x00000007ffffffff]
[    0.000000]   DMA32    empty
[    0.000000]   Normal   empty
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000000000000-0x00000007ffffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x00000007ffffffff]
[    0.000000] PERCPU: Embedded 2 pages/cpu @c0000007fe200000 s43672 r0 d87400 u131072
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 523840
[    0.000000] Kernel command line: 
[    0.000000] PID hash table entries: 4096 (order: -1, 32768 bytes)
[    0.000000] Dentry cache hash table entries: 4194304 (order: 9, 33554432 bytes)
[    0.000000] Inode-cache hash table entries: 2097152 (order: 8, 16777216 bytes)
[    0.000000] Sorting __ex_table...
[    0.000000] Memory: 33304512K/33554432K available (11840K kernel code, 960K rwdata, 4936K rodata, 6400K init, 1638K bss, 249920K reserved, 0K cma-reserved)
[    0.000000] SLUB: HWalign=128, Order=0-3, MinObjects=0, CPUs=128, Nodes=1
[    0.000000] Hierarchical RCU implementation.
[    0.000000]  Build-time adjustment of leaf fanout to 64.
[    0.000000]  RCU restricting CPUs from NR_CPUS=2048 to nr_cpu_ids=128.
[    0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=64, nr_cpu_ids=128
[    0.000000] NR_IRQS:512 nr_irqs:512 16
[    0.000000] ICS OPAL backend registered
[    0.000003] clocksource: timebase: mask: 0xffffffffffffffff max_cycles: 0x761537d007, max_idle_ns: 440795202126 ns
[    0.000897] clocksource: timebase mult[1f40000] shift[24] registered
[    0.001862] Console: colour dummy device 80x25
[    0.002183] console [hvc0] enabled
[    0.002183] console [hvc0] enabled
[    0.002604] bootconsole [udbg0] disabled
[    0.002604] bootconsole [udbg0] disabled
[    0.003416] pid_max: default: 131072 minimum: 1024
[    0.003948] Mount-cache hash table entries: 65536 (order: 3, 524288 bytes)
[    0.004365] Mountpoint-cache hash table entries: 65536 (order: 3, 524288 bytes)
[    0.005971] EEH: PowerNV platform initialized
[    0.006150] POWER8 performance monitor hardware support registered
[    0.174913] Brought up 128 CPUs
[    0.177222] devtmpfs: initialized
[    0.181149] EEH: devices created
[    0.184593] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.185169] xor: measuring software checksum speed
[    0.281620]    8regs     : 15116.800 MB/sec
[    0.381636]    8regs_prefetch: 13612.800 MB/sec
[    0.481653]    32regs    : 15897.600 MB/sec
[    0.581672]    32regs_prefetch: 14336.000 MB/sec
[    0.681689]    altivec   : 22208.000 MB/sec
[    0.681795] xor: using function: altivec (22208.000 MB/sec)
[    0.682286] NET: Registered protocol family 16
[    0.691862] PCI: Probing PCI hardware
[    0.691991] PCI: I/O resource not set for host bridge /pciex@3fffe40000000 (domain 0)
[    0.692130] PCI host bridge to bus 0000:00
[    0.692298] pci_bus 0000:00: root bus resource [mem 0x3fe000000000-0x3fe07ffeffff] (bus address [0x80000000-0xfffeffff])
[    0.692377] pci_bus 0000:00: root bus resource [mem 0x200000000000-0x20feffffffff 64bit pref]
[    0.692448] pci_bus 0000:00: root bus resource [bus 00-ff]
[    0.692771] pci 0000:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[    0.692893] pci 0000:00:00.0: PCI bridge to [bus 01-ff]
[    0.693093] PCI: I/O resource not set for host bridge /pciex@3fffe40100000 (domain 1)
[    0.693170] PCI host bridge to bus 0001:00
[    0.693203] pci_bus 0001:00: root bus resource [mem 0x3fe080000000-0x3fe0fffeffff] (bus address [0x80000000-0xfffeffff])
[    0.693282] pci_bus 0001:00: root bus resource [mem 0x210000000000-0x21feffffffff 64bit pref]
[    0.693486] pci_bus 0001:00: root bus resource [bus 00-ff]
[    0.693698] pci 0001:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[    0.693959] pci 0001:00:00.0: PCI bridge to [bus 01-ff]
[    0.694024] PCI: I/O resource not set for host bridge /pciex@3fffe41000000 (domain 2)
[    0.694236] PCI host bridge to bus 0002:00
[    0.694267] pci_bus 0002:00: root bus resource [mem 0x3fe800000000-0x3fe87ffeffff] (bus address [0x80000000-0xfffeffff])
[    0.694347] pci_bus 0002:00: root bus resource [mem 0x240000000000-0x24feffffffff 64bit pref]
[    0.694554] pci_bus 0002:00: root bus resource [bus 00-ff]
[    0.694746] pci 0002:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[    0.695000] pci 0002:00:00.0: PCI bridge to [bus 01-ff]
[    0.695064] PCI: I/O resource not set for host bridge /pciex@3fffe41100000 (domain 3)
[    0.695274] PCI host bridge to bus 0003:00
[    0.695306] pci_bus 0003:00: root bus resource [mem 0x3fe880000000-0x3fe8fffeffff] (bus address [0x80000000-0xfffeffff])
[    0.695385] pci_bus 0003:00: root bus resource [mem 0x250000000000-0x25feffffffff 64bit pref]
[    0.695557] pci_bus 0003:00: root bus resource [bus 00-ff]
[    0.695779] pci 0003:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[    0.696032] pci 0003:00:00.0: PCI bridge to [bus 01-ff]
[    0.696096] PCI: I/O resource not set for host bridge /pciex@3fffe41200000 (domain 4)
[    0.696173] PCI host bridge to bus 0004:00
[    0.696336] pci_bus 0004:00: root bus resource [mem 0x3fe900000000-0x3fe97ffeffff] (bus address [0x80000000-0xfffeffff])
[    0.696416] pci_bus 0004:00: root bus resource [mem 0x260000000000-0x26feffffffff 64bit pref]
[    0.696486] pci_bus 0004:00: root bus resource [bus 00-ff]
[    0.696808] pci 0004:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[    0.696959] pci 0004:00:00.0: PCI bridge to [bus 01-ff]
[    0.697142] pci 0000:00:00.0: PCI bridge to [bus 01]
[    0.697212] pci 0001:00:00.0: PCI bridge to [bus 01]
[    0.697415] pci 0002:00:00.0: PCI bridge to [bus 01]
[    0.697481] pci 0003:00:00.0: PCI bridge to [bus 01]
[    0.697546] pci 0004:00:00.0: PCI bridge to [bus 01]
[    0.697660] pci 0000:00     : [PE# 000] Secondary bus 0 associated with PE#0
[    0.697912] pci 0000:01     : [PE# 001] Secondary bus 1 associated with PE#1
[    0.698228] pci 0001:00     : [PE# 000] Secondary bus 0 associated with PE#0
[    0.698443] pci 0001:01     : [PE# 001] Secondary bus 1 associated with PE#1
[    0.698625] pci 0002:00     : [PE# 000] Secondary bus 0 associated with PE#0
[    0.698805] pci 0002:01     : [PE# 001] Secondary bus 1 associated with PE#1
[    0.699124] pci 0003:00     : [PE# 000] Secondary bus 0 associated with PE#0
[    0.699306] pci 0003:01     : [PE# 001] Secondary bus 1 associated with PE#1
[    0.699606] pci 0004:00     : [PE# 000] Secondary bus 0 associated with PE#0
[    0.699787] pci 0004:01     : [PE# 001] Secondary bus 1 associated with PE#1
[    0.700434] PCI: Domain 0000 has 8 available 32-bit DMA segments
[    0.700484] PCI: 0 PE# for a total weight of 0
[    0.700528] PCI: Domain 0001 has 8 available 32-bit DMA segments
[    0.700579] PCI: 0 PE# for a total weight of 0
[    0.700619] PCI: Domain 0002 has 8 available 32-bit DMA segments
[    0.700733] PCI: 0 PE# for a total weight of 0
[    0.700878] PCI: Domain 0003 has 8 available 32-bit DMA segments
[    0.700929] PCI: 0 PE# for a total weight of 0
[    0.700969] PCI: Domain 0004 has 8 available 32-bit DMA segments
[    0.701018] PCI: 0 PE# for a total weight of 0
[    0.701327] EEH: PCI Enhanced I/O Error Handling Enabled
[    0.702267] powernv-rng: Registering arch random hook.
[    0.702646] random: nonblocking pool is initialized
[    0.901795] raid6: altivecx1 gen()  5075 MB/s
[    1.071845] raid6: altivecx2 gen()  8440 MB/s
[    1.241870] raid6: altivecx4 gen() 16750 MB/s
[    1.411899] raid6: altivecx8 gen() 22075 MB/s
[    1.581941] raid6: int64x1  gen()  2540 MB/s
[    1.751972] raid6: int64x1  xor()   907 MB/s
[    1.921990] raid6: int64x2  gen()  5073 MB/s
[    2.092010] raid6: int64x2  xor()  1812 MB/s
[    2.262039] raid6: int64x4  gen()  7789 MB/s
[    2.432064] raid6: int64x4  xor()  2958 MB/s
[    2.602094] raid6: int64x8  gen()  5087 MB/s
[    2.772124] raid6: int64x8  xor()  2181 MB/s
[    2.772260] raid6: using algorithm altivecx8 gen() 22075 MB/s
[    2.772353] raid6: using intx1 recovery algorithm
[    2.772493] vgaarb: loaded
[    2.772722] SCSI subsystem initialized
[    2.772844] usbcore: registered new interface driver usbfs
[    2.772896] usbcore: registered new interface driver hub
[    2.773268] usbcore: registered new device driver usb
[    2.773336] pps_core: LinuxPPS API ver. 1 registered
[    2.773377] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[    2.773454] PTP clock support registered
[    2.774533] clocksource: Switched to clocksource timebase
[    2.776388] NET: Registered protocol family 2
[    2.776703] TCP established hash table entries: 262144 (order: 5, 2097152 bytes)
[    2.777339] TCP bind hash table entries: 65536 (order: 4, 1048576 bytes)
[    2.777501] TCP: Hash tables configured (established 262144 bind 65536)
[    2.777588] UDP hash table entries: 16384 (order: 3, 524288 bytes)
[    2.777829] UDP-Lite hash table entries: 16384 (order: 3, 524288 bytes)
[    2.778173] NET: Registered protocol family 1
[    2.778494] RPC: Registered named UNIX socket transport module.
[    2.778672] RPC: Registered udp transport module.
[    2.778709] RPC: Registered tcp transport module.
[    2.778745] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    3.815847] futex hash table entries: 32768 (order: 6, 4194304 bytes)
[    3.820045] NFS: Registering the id_resolver key type
[    3.820221] Key type id_resolver registered
[    3.820271] Key type id_legacy registered
[    3.820807] SGI XFS with ACLs, security attributes, no debug enabled
[    3.822350] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 252)
[    3.822562] io scheduler noop registered
[    3.822625] io scheduler cfq registered (default)
[    3.822897] ipmi message handler version 39.2
[    3.822937] ipmi device interface
[    3.822984] ipmi-powernv ibm,opal:ipmi: Unable to map irq from device tree
[    3.825885] ipmi-powernv ibm,opal:ipmi: Found new BMC (man_id: 0x000000, prod_id: 0x0000, dev_id: 0x00)
[    3.834739] hvc0: raw protocol on /ibm,opal/consoles/serial@0 (boot console)
[    3.835131] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
[    3.835394] Generic RTC Driver v1.07
[    3.835481] powernv_rng: Registered powernv hwrng.
[    3.835548] [drm] Initialized drm 1.1.0 20060810
[    3.835595] [drm] radeon kernel modesetting enabled.
[    3.840812] brd: module loaded
[    3.847356] loop: module loaded
[    3.847661] Loading iSCSI transport class v2.0-870.
[    3.847847] alua: device handler registered
[    3.847882] Adaptec aacraid driver 1.2-1[41010]-ms
[    3.847950] qla2xxx [0000:00:00.0]-0005: : QLogic Fibre Channel HBA Driver: 8.07.00.26-k.
[    3.848038] iscsi: registered transport (qla4xxx)
[    3.848090] QLogic iSCSI HBA Driver
[    3.848122] Emulex LightPulse Fibre Channel SCSI driver 11.0.0.0.
[    3.848171] Copyright(c) 2004-2015 Emulex.  All rights reserved.
[    3.848276] megaraid cmm: 2.20.2.7 (Release Date: Sun Jul 16 00:01:03 EST 2006)
[    3.848355] megaraid: 2.20.5.1 (Release Date: Thu Nov 16 15:32:35 EST 2006)
[    3.848418] mpt3sas version 09.102.00.00 loaded
[    3.848533] ipr: IBM Power RAID SCSI Device Driver version: 2.6.3 (October 17, 2015)
[    3.848608] libcxgbi:libcxgbi_init_module: Chelsio iSCSI driver library libcxgbi v0.9.1-ko (Apr. 2015)
[    3.848678] libcxgbi:libcxgbi_init_module: tag itt 0x1fff, 13 bits, age 0xf, 4 bits.
[    3.848738] libcxgbi:ddp_setup_host_page_size: system PAGE 65536, ddp idx 3.
[    3.848799] Chelsio T3 iSCSI Driver cxgb3i v2.0.1-ko (Apr. 2015)
[    3.848858] iscsi: registered transport (cxgb3i)
[    3.848901] Chelsio T4/T5 iSCSI Driver cxgb4i v0.9.5-ko (Apr. 2015)
[    3.848960] iscsi: registered transport (cxgb4i)
[    3.849001] QLogic NetXtreme II iSCSI Driver bnx2i v2.7.10.1 (Jul 16, 2014)
[    3.849060] iscsi: registered transport (bnx2i)
[    3.851973] iscsi: registered transport (be2iscsi)
[    3.852018] In beiscsi_module_init, tt=c00000000172f5a0
[    3.852160] st: Version 20101219, fixed bufsize 32768, s/g segs 256
[    3.853269] tun: Universal TUN/TAP device driver, 1.6
[    3.853313] tun: (C) 1999-2004 Max Krasnyansky <maxk@qualcomm.com>
[    3.853435] pcnet32: pcnet32.c:v1.35 21.Apr.2008 tsbogend@alpha.franken.de
[    3.853512] cnic: QLogic cnicDriver v2.5.22 (July 20, 2015)
[    3.853751] bnx2x: QLogic 5771x/578xx 10/20-Gigabit Ethernet Driver bnx2x 1.712.30-0 (2014/02/10)
[    3.854066] e100: Intel(R) PRO/100 Network Driver, 3.5.24-k2-NAPI
[    3.854176] e100: Copyright(c) 1999-2006 Intel Corporation
[    3.854230] e1000: Intel(R) PRO/1000 Network Driver - version 7.3.21-k8-NAPI
[    3.854290] e1000: Copyright (c) 1999-2006 Intel Corporation.
[    3.854354] e1000e: Intel(R) PRO/1000 Network Driver - 3.2.6-k
[    3.854405] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.
[    3.854618] ixgbe: Intel(R) 10 Gigabit PCI Express Network Driver - version 4.2.1-k
[    3.854679] ixgbe: Copyright (c) 1999-2015 Intel Corporation.
[    3.854744] ixgb: Intel(R) PRO/10GbE Network Driver - version 1.0.135-k2-NAPI
[    3.854803] ixgb: Copyright (c) 1999-2008 Intel Corporation.
[    3.855018] myri10ge: Version 1.5.3-1.534
[    3.855133] QLogic/NetXen Network Driver v4.0.82
[    3.855189] Solarflare NET driver v4.0
[    3.855562] aoe: AoE v85 initialised.
[    3.855637] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    3.855690] ehci-pci: EHCI PCI platform driver
[    3.855744] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[    3.855796] ohci-pci: OHCI PCI platform driver
[    3.856007] usbcore: registered new interface driver usb-storage
[    3.856220] mousedev: PS/2 mouse device common for all mice
[    3.856524] i2c /dev entries driver
[    3.856740] at24 0-0052: 256 byte 24c02 EEPROM, writable, 1 bytes/write
[    3.856914] at24 0-0053: 256 byte 24c02 EEPROM, writable, 1 bytes/write
[    3.856980] at24 0-0054: 256 byte 24c02 EEPROM, writable, 1 bytes/write
[    3.857046] at24 0-0055: 256 byte 24c02 EEPROM, writable, 1 bytes/write
[    3.857113] at24 0-0056: 16384 byte 24c128 EEPROM, writable, 1 bytes/write
[    3.857359] at24 1-0052: 256 byte 24c02 EEPROM, writable, 1 bytes/write
[    3.857425] at24 1-0053: 256 byte 24c02 EEPROM, writable, 1 bytes/write
[    3.857491] at24 1-0054: 256 byte 24c02 EEPROM, writable, 1 bytes/write
[    3.857557] at24 1-0055: 256 byte 24c02 EEPROM, writable, 1 bytes/write
[    3.857630] at24 1-0057: 16384 byte 24c128 EEPROM, writable, 1 bytes/write
[    3.857857] at24 2-0050: 16384 byte 24c128 EEPROM, writable, 1 bytes/write
[    3.857923] at24 2-0051: 16384 byte 24c128 EEPROM, writable, 1 bytes/write
[    3.858026] at24 3-0050: 16384 byte 24c128 EEPROM, writable, 1 bytes/write
[    3.858093] at24 3-0051: 16384 byte 24c128 EEPROM, writable, 1 bytes/write
[    3.858328] at24 4-0050: 16384 byte 24c128 EEPROM, writable, 1 bytes/write
[    3.858436] at24 5-0050: 16384 byte 24c128 EEPROM, writable, 1 bytes/write
[    3.858504] at24 5-0051: 16384 byte 24c128 EEPROM, writable, 1 bytes/write
[    3.878886] at24 6-0050: 16384 byte 24c128 EEPROM, writable, 1 bytes/write
[    3.879423] at24 6-0051: 16384 byte 24c128 EEPROM, writable, 1 bytes/write
[    3.880421] md: linear personality registered for level -1
[    3.880727] md: raid0 personality registered for level 0
[    3.881164] md: raid1 personality registered for level 1
[    3.881621] md: raid10 personality registered for level 10
 Petitboot (dev.20160310)                     8335-GTA         0000000000000000
 ──────────────────────────────────────────────────────────────────────────────

  System information
  System configuration
  Language
  Rescan devices
  Retrieve config from URL
 *Exit to shell           

 ──────────────────────────────────────────────────────────────────────────────
 Enter=accept, e=edit, n=new, x=exit, l=language, h=help
 Welcome to Petitboot
larrymi commented 8 years ago

Looking back in the event log, I don't see any PSU Fault 1 or PSU Fault 2 so exact relevance of these errors is not clear. However, that they occurred between the last good deployment and the first bad one does raise a flag.

sammj commented 8 years ago

Please post /var/log/messages and /var/log/petitboot/pb-discover.log - perhaps Petitboot is not seeing the disks.

larrymi commented 8 years ago

@sammj please see the attached logs that you requested. logs.tar.gz

sammj commented 8 years ago

From the logs not even the kernel appears to think this machine has disks attached. Do you know exactly what should be appearing, and how it is attached (eg. as part of a RAID array)?

Also please post /sys/firmware/opal/msglog in case there's a more fundamental problem.

larrymi commented 8 years ago

@sammj in the logs that I included, there should be an lshw file. That contains the disks that were previously discovered.

larrymi commented 8 years ago

@sammj here's the /sys/firmware/opal/msglog sysfirmwareopalmsglog.log.gz

sammj commented 8 years ago
[7279045336,7] PHB3: Timeout waiting for electrical link
[7279047461,7] PHB3: DLP train control: 0x0fd0001101000000
[7279049941,7] PHB3: Slot freset: Retrying
[7279051718,7] PHB3: Slot freset: Asserting PERST
[7330251688,7] PHB4: Timeout waiting for link up

If your disks are behind one of these PHBs this could be the issue - if possible can you update to a more recent Skiboot version and retest?

larrymi commented 7 years ago

I have tried to build the last pflash and I am getting an error when I try to backup my existing skiboot:

To build it, I did the following: "git clone https://github.com/open-power/skiboot.git" On the target ppc64el system, I then ran make: "cd skiboot/external/pflash" "make"

Then this was from trying to backup the existing skiboot: ubuntu@entei:~/skiboot/external/pflash$ ./pflash -r zImage.backup -P BOOTKERNEL Couldn't initialise architecture flash structures

Then, I had planned to run command below to upgrade to v1.12: ./pflash -e -p zImage.epapr -P BOOTKERNEL

With the backup failing, I don't want to risk flashing to the latest until we understand this failure.

@sammj please take a look at the error above. Any idea as to what could be the issue and/or suggestion for how to go about updating?

ghost commented 7 years ago

@larrymi you will need to run pflash as root

YiannisGkoufas commented 6 years ago

Hi, I have started to see the same behavior, without maas deployment. On reboot suddenly it doesn't see any bootable partitions (or partitions in general). I am attaching the logs I collected using pb-sos. diag.zip Would really appreciate any help/suggestion.

sammj commented 6 years ago

Hi Yiannis, Looking at those logs the thing that stands out most is that pb-discover appears to have been run twice:

--- pb-discover ---
lang: en_US.utf8
Detected platform type: powerpc
...
process_read_stdout_once: read failed: Bad file descriptor
event_parse_ad_header: bad header:

--- pb-discover ---
lang: en_US.utf8
Detected platform type: powerpc

There are plenty of errors after that but that will be because you're running into https://github.com/open-power/petitboot/issues/32. This shouldn't happen without manual intervention, did you stop/start the Petitboot service?

That aside, in the first invocation of pb-discover it sees a few disks but either ignores them because they don't have a filesystem or doesn't find anything bootable on them. Which disks are you expecting to see boot options on? Run nvram --update-config petitboot,debug?=true and reboot to make Petitboot write some more detailed logs and we'll see if we can track that down.

YiannisGkoufas commented 6 years ago

Hi Samuel,

thanks for the info. I didn't restart petitboot manually, just rebooted the node. I updated the config and these are logs I am getting now.

diag.zip

sammj commented 6 years ago

Looking at the logs and having had a chance to jump on the machine in question, nothing really jumps out as a problem. Of the 15 disks there are four that udev can recognise as having a filesystem: sdc, sdd, sdf, and sdh. sdd and sdf have been mounted as ext4 but aren't boot partitions. sdc and sdh are both LVM members which your version of Petitboot doesn't support (v1.4.4). For everything else Linux is just refusing to mount it since there doesn't appear to be a filesystem. It would definitely help to know how this system was set up so we know what we're expecting to see a filesystem on; otherwise it's very very tempting to say it's not booting because there's nothing to boot. :)