Thanks for your patience, David, and for the very useful training.
OK. I like a challenge!
I found that the debugfs was already mounted and that I had missed copying the diagnose.shutdown script into /usr/lib/systemd/system-shutdown/
Now I have a log file which shows the sequence of the shutdown process and a "Schrodinger's cat" conundrum (I prefer the term Schrondinbug, because I like cats).
The tuned process is halted about 1.1 seconds into the shutdown (see attached). So now I know how it should work.
I suppose it's now a matter of throwing in some other random processes to make it not work again????
Any suggestions?
Cheers
Bill
-----Original message-----
> From:David Sommerseth <[log in to unmask]>
> Sent: Sunday 22nd January 2017 7:38
> To: Bill Maidment <[log in to unmask]>; [log in to unmask]
> Subject: Re: SL7.3RC2 shutdown slow
>
> On 21/01/17 05:16, Bill Maidment wrote:
> > He! He! He!
> > I've installed the shutdown diagnostic and on reboot there is no delay on shutdown!
> > Unfortunately, ftrace was not installed, so I couldn't analyse what was not happening.
>
> Ftrace is a kernel component which is enabled by default. But you need
> to have the debugfs mounted at the appropriate place. For more info:
> <https://access.redhat.com/documentation/en-US/Red_Hat_Enterprise_Linux/7/html/Developer_Guide/ftrace.html>
>
> > I removed the diagnostic and the shutdown delay returned.
> > So it seems that the more you search for something, the more it goes away.
> > I am out of my depth now, so I'll leave this issue as an exercise for the brave.
>
> Oh, those are "funny" ... and they are usually called Heisenbugs ...
> <https://en.wikipedia.org/wiki/Heisenbug>
>
> I would then look more carefully at what this shutdown diagnostics
> enables under the hood ... and see if you can figure out what triggers
> the delay to disappear. Or if it is just as simple as something being
> shutdown in the wrong order and a delay somewhere avoids a little
> timeout causing the delay you see.
>
>
> --
> kind regards,
>
> David Sommerseth
>
>
> > -----Original message-----
> >> From:Bill Maidment <[log in to unmask]>
> >> Sent: Saturday 21st January 2017 7:48
> >> To: David Sommerseth <[log in to unmask]>; [log in to unmask]
> >> Subject: RE: SL7.3RC2 shutdown slow
> >>
> >> David
> >> Thanks for the info. However, this only deals with booting. My issue is with shutdown.
> >> Your other email points to a shutdown diagnostic, so I'll try that, but I'm a bit wary of that not being a stable process.
> >>
> >>
> >> -----Original message-----
> >>> From:David Sommerseth <[log in to unmask]>
> >>> Sent: Saturday 21st January 2017 2:11
> >>> To: Bill Maidment <[log in to unmask]>; [log in to unmask]
> >>> Subject: Re: SL7.3RC2 shutdown slow
> >>>
> >>> On 20/01/17 09:11, Bill Maidment wrote:
> >>>> Update.....
> >>>>
> >>>> After shutting down several times everything seems to have settled
> >>>> down and there is no delay. Maybe I'm too impatient. Or something
> >>>> needed time to stabilize.
> >>>
> >>> When you experience such issues, systemd does have a good way to help
> >>> point fingers at why the boot process lags ...
> >>>
> >>> # systemd-analyze blame
> >>>
> >>> Replace 'blame' with 'plot', and you'll get an SVG file with a graphical
> >>> presentation of the boot process, in which order unit files started,
> >>> when they started and how much time each of them needed. Or use 'dot'
> >>> to get a similar view in the dot(1) format.
> >>>
> >>>
> >>> --
> >>> kind regards,
> >>>
> >>> David Sommerseth
> >>>
> >>>
> >>>> -----Original message-----
> >>>>> From:Bill Maidment <[log in to unmask]>
> >>>>> Sent: Friday 20th January 2017 17:58
> >>>>> To: [log in to unmask]
> >>>>> Subject: SL7.3RC2 shutdown slow
> >>>>>
> >>>>> Hi
> >>>>> I've created a new KVM guest using RC2 and no problems installing and updating from 7rolling, but rebooting is very slow.
> >>>>> I tried doing a shutdown and notice a 1min 30sec delay shutting down Dynamic System Tuning Daemon.
> >>>>> Is this expected behaviour on a new install?
> >>>>>
> >>>>> Cheers
> >>>>> Bill Maidment
> >>>>>
> >>>>>
> >>>
> >>>
> >>
> >>
>
>
>
start-diagnose-(1364) exited at 0s, got signals:
systemd-cgroups(1415) exited at 0.617941s, got signals:
gmain(1072) exited at 1.066476s, got signals: 9(1.066257)
tuned(1010) exited at 1.168763s, got signals:
systemd-cgroups(1416) exited at 1.416016s, got signals:
ip6tables-resto(1418) exited at 3.171939s, got signals:
network(1420) exited at 3.837197s, got signals:
iptables-restor(1419) exited at 4.124070s, got signals:
sort(1425) exited at 4.854279s, got signals:
sed(1426) exited at 4.857348s, got signals:
sed(1424) exited at 4.873828s, got signals:
ls(1423) exited at 4.878966s, got signals:
network(1422) exited at 4.911658s, got signals: 17(4.880866)
ebtables-restor(1421) exited at 5.174055s, got signals:
awk(1427) exited at 5.371188s, got signals:
awk(1428) exited at 5.604870s, got signals:
ip6tables-resto(1429) exited at 6.210744s, got signals:
systemctl(1430) exited at 6.885756s, got signals:
grep(1431) exited at 6.888711s, got signals:
iptables-restor(1432) exited at 7.052736s, got signals:
grep(1433) exited at 7.121991s, got signals:
grep(1434) exited at 7.345437s, got signals:
grep(1438) exited at 8.106250s, got signals:
ip(1437) exited at 8.125635s, got signals:
ebtables-restor(1435) exited at 8.154354s, got signals:
mountpoint(1442) exited at 8.738971s, got signals:
mountpoint(1443) exited at 9.033708s, got signals:
ifdown(1441) exited at 9.062300s, got signals: 17(8.740938) 17(9.042000)
rmmod(1440) exited at 9.315819s, got signals:
rmmod(1445) exited at 10.104431s, got signals:
rmmod(1446) exited at 10.825007s, got signals:
rmmod(1449) exited at 11.259292s, got signals:
nmcli(1450) exited at 11.274524s, got signals: 9(11.274517)
gmain(1452) exited at 11.274575s, got signals: 9(11.274573)
nmcli(1448) exited at 11.274595s, got signals:
gdbus(1453) exited at 11.275345s, got signals: 9(11.274966)
ifdown(1447) exited at 11.276812s, got signals: 17(11.276619)
rmmod(1451) exited at 11.282219s, got signals:
rmmod(1454) exited at 11.301109s, got signals:
mountpoint(1456) exited at 11.309820s, got signals:
mountpoint(1458) exited at 11.318524s, got signals:
rmmod(1457) exited at 11.319075s, got signals:
ifdown-eth(1455) exited at 11.320877s, got signals: 17(11.309864) 17(11.320735)
rmmod(1459) exited at 11.343066s, got signals:
nmcli(1463) exited at 11.381922s, got signals: 9(11.381915)
nmcli(1461) exited at 11.381951s, got signals:
gmain(1464) exited at 11.381960s, got signals: 9(11.381956)
gdbus(1465) exited at 11.382346s, got signals: 9(11.381997)
ifdown-eth(1460) exited at 11.383491s, got signals: 17(11.383316)
ip(1466) exited at 11.389295s, got signals:
rmmod(1462) exited at 11.390118s, got signals:
grep(1467) exited at 11.392279s, got signals:
rmmod(1468) exited at 11.406109s, got signals:
mountpoint(1472) exited at 11.414454s, got signals:
rmmod(1471) exited at 11.420661s, got signals:
mountpoint(1473) exited at 11.423860s, got signals:
ifdown-ipv6(1470) exited at 11.424035s, got signals: 17(11.414500) 17(11.423902)
rmmod(1474) exited at 11.442127s, got signals:
rmmod(1476) exited at 11.460669s, got signals:
rmmod(1478) exited at 11.479196s, got signals:
nmcli(1479) exited at 11.491476s, got signals: 9(11.491471)
gmain(1481) exited at 11.491493s, got signals: 9(11.491491)
nmcli(1477) exited at 11.491511s, got signals:
gdbus(1482) exited at 11.491985s, got signals: 9(11.491636)
ifdown-ipv6(1475) exited at 11.493212s, got signals: 17(11.493030)
rmmod(1480) exited at 11.506126s, got signals:
ip(1483) exited at 11.509427s, got signals:
grep(1484) exited at 11.510742s, got signals:
sysctl(1486) exited at 11.524133s, got signals:
rmmod(1485) exited at 11.525131s, got signals:
sysctl(1487) exited at 11.539079s, got signals:
rmmod(1488) exited at 11.542213s, got signals:
sysctl(1489) exited at 11.554999s, got signals:
ip(1491) exited at 11.561160s, got signals:
rmmod(1490) exited at 11.562440s, got signals:
ip(1492) exited at 11.570462s, got signals:
ip(1494) exited at 11.574307s, got signals:
rmmod(1493) exited at 11.577679s, got signals:
ip(1495) exited at 11.582034s, got signals:
ip(1497) exited at 11.589277s, got signals:
ifdown-ipv6(1469) exited at 11.589582s, got signals: 17(11.424059) 17(11.493227) 17(11.510779) 17(11.524190) 17(11.539146) 17(11.555056) 17(11.561197) 17(11.570505) 17(11.574342) 17(11.582070) 17(11.589314)
rmmod(1496) exited at 11.594162s, got signals:
rmmod(1499) exited at 11.612455s, got signals:
rmmod(1500) exited at 11.634145s, got signals:
pidof(1498) exited at 11.642479s, got signals:
ip(1502) exited at 11.653186s, got signals:
rmmod(1501) exited at 11.654125s, got signals:
ip(1503) exited at 11.663708s, got signals:
rmmod(1504) exited at 11.671003s, got signals:
ip(1505) exited at 11.673473s, got signals:
grep(1506) exited at 11.673750s, got signals:
rmmod(1507) exited at 11.689176s, got signals:
mountpoint(1510) exited at 11.697205s, got signals:
rmmod(1511) exited at 11.704536s, got signals:
mountpoint(1512) exited at 11.708562s, got signals:
ifdown-post(1509) exited at 11.708746s, got signals: 17(11.697246) 17(11.708608)
rmmod(1513) exited at 11.729119s, got signals:
rmmod(1516) exited at 11.748134s, got signals:
nmcli(1518) exited at 11.770868s, got signals: 9(11.770862)
gmain(1519) exited at 11.770885s, got signals: 9(11.770884)
nmcli(1515) exited at 11.770904s, got signals:
gdbus(1520) exited at 11.771259s, got signals: 9(11.770909)
rmmod(1517) exited at 11.772168s, got signals:
ifdown-post(1514) exited at 11.774109s, got signals: 17(11.773931)
ifdown-routes(1522) exited at 11.785882s, got signals:
rmmod(1521) exited at 11.790094s, got signals:
ip(1523) exited at 11.798233s, got signals:
grep(1524) exited at 11.798334s, got signals:
ip(1525) exited at 11.807130s, got signals:
grep(1526) exited at 11.807392s, got signals:
ip(1528) exited at 11.820310s, got signals:
sed(1529) exited at 11.820890s, got signals:
ifdown-post(1527) exited at 11.821115s, got signals: 17(11.820940)
gmain( 897) exited at 11.882963s, got signals: 9(11.882955)
firewalld( 651) exited at 11.891210s, got signals: 15(1.734789)
polkitd( 595) exited at 11.900771s, got signals: 9(11.900759)
gmain( 635) exited at 11.900792s, got signals: 9(11.900783)
JS( 637) exited at 11.900807s, got signals: 9(11.900802)
JS( 638) exited at 11.900815s, got signals: 9(11.900813)
runaway-killer-( 649) exited at 11.900823s, got signals: 9(11.900821)
gdbus( 636) exited at 11.901719s, got signals: 9(11.900831)
dbus-daemon( 594) exited at 11.902736s, got signals: 32(11.899825) 9(11.902733)
dbus-daemon( 592) exited at 11.902905s, got signals: 15(11.898518)
systemd-cgroups(1532) exited at 11.912393s, got signals:
systemd-cgroups(1531) exited at 11.912464s, got signals:
systemd-cgroups(1533) exited at 11.919841s, got signals:
skipcpio(1401) exited at 12.418588s, got signals:
cpio(1403) exited at 12.424706s, got signals:
gzip(1402) exited at 12.424835s, got signals:
rm(1534) exited at 12.429723s, got signals:
dracut-initramf(1393) exited at 12.429905s, got signals: 17(12.424876) 17(12.429755)
systemd-cgroups(1535) exited at 12.434545s, got signals:
firewall-cmd(1530) exited at 12.515308s, got signals:
ifdown-post(1536) exited at 12.517153s, got signals:
ifdown-post(1508) exited at 12.517406s, got signals: 17(11.708779) 17(11.774124) 17(11.785919) 17(11.798367) 17(11.807424) 17(11.821158) 17(12.516343) 17(12.517178)
ifdown-eth(1439) exited at 12.517713s, got signals: 17(9.063284) 17(11.276827) 17(11.320902) 17(11.383507) 17(11.392319) 17(11.589630) 17(11.643186) 17(11.653228) 17(11.663756) 17(11.673788) 17(12.517449)
network(1436) exited at 12.518181s, got signals: 17(8.135540) 17(12.517761)
mountpoint(1539) exited at 12.523982s, got signals:
mountpoint(1540) exited at 12.525620s, got signals:
ifdown(1538) exited at 12.525772s, got signals: 17(12.524018) 17(12.525652)
ifdown(1542) exited at 12.534312s, got signals:
sed(1543) exited at 12.534519s, got signals:
ifdown(1541) exited at 12.534748s, got signals: 17(12.534579)
nmcli(1545) exited at 12.544032s, got signals:
nmcli(1546) exited at 12.544364s, got signals: 9(12.544044)
ifdown(1544) exited at 12.544629s, got signals: 17(12.544433)
mountpoint(1548) exited at 12.548531s, got signals:
mountpoint(1549) exited at 12.550139s, got signals:
ifdown-eth(1547) exited at 12.550290s, got signals: 17(12.548582) 17(12.550173)
ifdown-eth(1551) exited at 12.558512s, got signals:
sed(1552) exited at 12.558747s, got signals:
ifdown-eth(1550) exited at 12.558945s, got signals: 17(12.558789)
nmcli(1554) exited at 12.568037s, got signals:
nmcli(1555) exited at 12.568361s, got signals: 9(12.568049)
ifdown-eth(1553) exited at 12.568610s, got signals: 17(12.568422)
grep(1557) exited at 12.571552s, got signals:
ip(1556) exited at 12.571663s, got signals:
mountpoint(1560) exited at 12.575951s, got signals:
mountpoint(1561) exited at 12.577537s, got signals:
ifdown-ipv6(1559) exited at 12.577719s, got signals: 17(12.575990) 17(12.577591)
ifdown-ipv6(1563) exited at 12.586277s, got signals:
sed(1564) exited at 12.586475s, got signals:
ifdown-ipv6(1562) exited at 12.586697s, got signals: 17(12.586519)
nmcli(1566) exited at 12.595676s, got signals:
nmcli(1567) exited at 12.596006s, got signals: 9(12.595687)
ifdown-ipv6(1565) exited at 12.596218s, got signals: 17(12.596066)
ip(1568) exited at 12.604101s, got signals:
grep(1569) exited at 12.604207s, got signals:
sysctl(1570) exited at 12.606870s, got signals:
sysctl(1571) exited at 12.609260s, got signals:
sysctl(1572) exited at 12.611657s, got signals:
ip(1573) exited at 12.612786s, got signals:
ip(1574) exited at 12.614369s, got signals:
ip(1575) exited at 12.615421s, got signals:
ifdown-ipv6(1558) exited at 12.615715s, got signals: 17(12.577742) 17(12.586711) 17(12.596231) 17(12.604236) 17(12.606916) 17(12.609305) 17(12.611699) 17(12.612818) 17(12.614400) 17(12.615453)
pidof(1576) exited at 12.620802s, got signals:
ip(1577) exited at 12.622192s, got signals:
ip(1578) exited at 12.623319s, got signals:
ip(1579) exited at 12.626027s, got signals:
grep(1580) exited at 12.626135s, got signals:
mountpoint(1583) exited at 12.629953s, got signals:
mountpoint(1584) exited at 12.631616s, got signals:
ifdown-post(1582) exited at 12.631770s, got signals: 17(12.629987) 17(12.631648)
ifdown-post(1586) exited at 12.639734s, got signals:
sed(1587) exited at 12.639932s, got signals:
ifdown-post(1585) exited at 12.640118s, got signals: 17(12.639972)
nmcli(1589) exited at 12.649356s, got signals:
nmcli(1590) exited at 12.649730s, got signals: 9(12.649368)
ifdown-post(1588) exited at 12.649946s, got signals: 17(12.649792)
ifdown-routes(1591) exited at 12.652236s, got signals:
ip(1592) exited at 12.654925s, got signals:
grep(1593) exited at 12.655005s, got signals:
ip(1594) exited at 12.657353s, got signals:
grep(1595) exited at 12.657444s, got signals:
ifdown-post(1596) exited at 12.658308s, got signals:
ifdown-post(1581) exited at 12.658532s, got signals: 17(12.631790) 17(12.640129) 17(12.649959) 17(12.652267) 17(12.655064) 17(12.657474) 17(12.658343)
ifdown-eth(1537) exited at 12.658827s, got signals: 17(12.525792) 17(12.534762) 17(12.544645) 17(12.550310) 17(12.558957) 17(12.568626) 17(12.571702) 17(12.615757) 17(12.620845) 17(12.622226) 17(12.623351) 17(12.626166) 17(12.658592)
sysctl(1597) exited at 12.661874s, got signals:
mountpoint(1600) exited at 12.665699s, got signals:
mountpoint(1601) exited at 12.667290s, got signals:
init.ipv6-globa(1599) exited at 12.667445s, got signals: 17(12.665738) 17(12.667325)
sysctl(1602) exited at 12.680173s, got signals:
sysctl(1603) exited at 12.682432s, got signals:
sysctl(1604) exited at 12.684780s, got signals:
sysctl(1605) exited at 12.687136s, got signals:
sysctl(1606) exited at 12.689433s, got signals:
sysctl(1607) exited at 12.691786s, got signals:
sysctl(1608) exited at 12.694135s, got signals:
sysctl(1609) exited at 12.696429s, got signals:
sysctl(1610) exited at 12.698779s, got signals:
sysctl(1611) exited at 12.701178s, got signals:
sysctl(1612) exited at 12.703463s, got signals:
sysctl(1613) exited at 12.705810s, got signals:
ip(1614) exited at 12.708814s, got signals:
awk(1615) exited at 12.708938s, got signals:
init.ipv6-globa(1616) exited at 12.709136s, got signals:
init.ipv6-globa(1598) exited at 12.709498s, got signals: 17(12.667465) 17(12.680219) 17(12.682478) 17(12.684824) 17(12.687183) 17(12.689479) 17(12.691830) 17(12.694181) 17(12.696475) 17(12.698824) 17(12.701224) 17(12.703509) 17(12.705856) 17(12.709173)
rm(1617) exited at 12.710929s, got signals:
network(1417) exited at 12.711218s, got signals: 17(3.843863) 17(4.913336) 17(5.378001) 17(5.608928) 17(6.891236) 17(7.123023) 17(7.346877) 17(12.519862) 17(12.658872) 17(12.661922) 17(12.709539) 17(12.710957)
systemd-cgroups(1618) exited at 12.725525s, got signals:
systemd-random-(1620) exited at 12.733997s, got signals:
systemd-update-(1619) exited at 12.737093s, got signals:
systemd-cgroups(1621) exited at 12.740380s, got signals:
audit_send_repl(1622) exited at 12.825457s, got signals:
auditd( 588) exited at 12.835751s, got signals:
auditd( 573) exited at 12.836984s, got signals: 15(12.825161)
umount(1624) exited at 12.859796s, got signals:
systemd-cgroups(1625) exited at 12.865515s, got signals:
xfsaild/vda1( 546) exited at 13.120890s, got signals:
xfs-eofblocks/v( 545) exited at 13.120978s, got signals:
xfs-log/vda1( 544) exited at 13.120994s, got signals:
xfs-reclaim/vda( 543) exited at 13.121008s, got signals:
xfs-cil/vda1( 542) exited at 13.121021s, got signals:
xfs-data/vda1( 540) exited at 13.121035s, got signals:
xfs-conv/vda1( 541) exited at 13.121048s, got signals:
xfs-buf/vda1( 539) exited at 13.121062s, got signals:
umount(1623) exited at 13.121513s, got signals:
systemd-cgroups(1626) exited at 13.135479s, got signals:
systemctl(1628) exited at 13.164815s, got signals:
systemd-cgroups(1629) exited at 13.169467s, got signals:
lvmetad(1630) exited at 13.191002s, got signals:
lvm(1627) exited at 13.193105s, got signals:
systemd-udevd(1444) exited at 13.455254s, got signals: 19(13.445474)
systemd-journal( 469) exited at 13.455734s, got signals: 19(13.445453)
lvmetad( 490) exited at 13.457007s, got signals: 19(13.445464) 15(13.452601)
systemd-udevd( 492) exited at 13.457174s, got signals: 19(13.445467)
kdmflush( 365) exited at 14.080258s, got signals:
bioset( 366) exited at 14.080304s, got signals:
mdadm(1634) exited at 14.549794s, got signals:
mdadm.shutdown(1632) exited at 14.549951s, got signals: 17(14.549841)
mount(1635) exited at 14.565164s, got signals:
|
