AutoShutDown issues - Does not work on 2nd shutdown

  • Hi guys,


    I have some issues related to the autoshutdown plugin but first I'd like to share my hardware profile:


    OMV 2.1.8 installed on USB 3.0 Stick
    AsRock N3150 ITX Mainboard
    4GB RAM
    4 HDDs
    No Raid
    3.16 Backport Kernel installed - Without this kernel I had issues with my NIC


    Actually my problem is that the autoshutdown plugin only works on first execution. After I wake the pc up 2nd time it does not work anymore. See below for an extract from the log. By the way, even with the other kernel it did not work either.


    Aug 21 17:19:56 Desty-Media logger: autoshutdown[21877]: INFO: ' new supervision cycle started - check active hosts or processes'
    Aug 21 17:19:56 Desty-Media logger: autoshutdown[21877]: INFO: ' retrieve list of active IPs for 'eth0' ...'
    Aug 21 17:19:58 Desty-Media logger: autoshutdown[21877]: INFO: ' No active IPs in the specified IP-Range found'
    Aug 21 17:19:58 Desty-Media logger: autoshutdown[21877]: INFO: ' Check Connections for 'eth0''
    Aug 21 17:19:58 Desty-Media logger: autoshutdown[21877]: INFO: ' ULDL-Traffic-Check for 'eth0''
    Aug 21 17:19:58 Desty-Media logger: autoshutdown[21877]: INFO: ' eth0: over the last 90 seconds: DL: 0.0 kB/s; UL: 0.0 kB/s'
    Aug 21 17:19:58 Desty-Media logger: autoshutdown[21877]: INFO: ' eth0: UL- and DL-Rate is under 800 kB/s -> next check'
    Aug 21 17:20:04 Desty-Media logger: autoshutdown[21877]: INFO: ' No active hosts or processes within network range, 0 cycles until shutdown...'
    Aug 21 17:20:04 Desty-Media logger: autoshutdown[21877]: INFO: ' Shutdown issued: 'pm-hibernate''
    Aug 21 17:20:04 Desty-Media logger: autoshutdown[21877]: INFO: ' '
    Aug 21 17:20:04 Desty-Media logger: autoshutdown[21877]: INFO: ' '
    Aug 21 17:20:12 Desty-Media logger: autoshutdown[23566]: INFO: ' XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX'
    Aug 21 17:20:12 Desty-Media logger: autoshutdown[23566]: INFO: ' XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX'
    Aug 21 17:20:12 Desty-Media logger: autoshutdown[23566]: INFO: ' XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX'
    Aug 21 17:20:12 Desty-Media logger: autoshutdown[23566]: INFO: ' X Version: 0.9.9.10'
    Aug 21 17:20:12 Desty-Media logger: autoshutdown[23566]: INFO: ' Initialize logging to local6'
    Aug 21 17:20:12 Desty-Media logger: autoshutdown[23566]: INFO: ' /etc/autoshutdown.conf loaded'
    Aug 21 17:20:12 Desty-Media logger: autoshutdown[23566]: INFO: ' ------------------------------------------------------'
    Aug 21 17:20:12 Desty-Media logger: autoshutdown[23566]: INFO: ' Checking config'
    Aug 21 17:20:12 Desty-Media logger: autoshutdown[23566]: INFO: ' LOADPROCNAMES is set to: 'smbd,nfsd,transmission-daemon,mt-daapd,forked-daapd' (default)'
    Aug 21 17:20:12 Desty-Media logger: autoshutdown[23566]: INFO: ' TEMPPROCNAMES is set to: in.'tftpd' (default)'
    Aug 21 17:20:12 Desty-Media logger: autoshutdown[23566]: INFO: ' If you want more processes monitored, please have a look at the expert-settings'
    Aug 21 17:20:12 Desty-Media logger: autoshutdown[23566]: WARN: ' HDDIOCHECK is set to false'
    Aug 21 17:20:12 Desty-Media logger: autoshutdown[23566]: WARN: ' Ignoring HDDIO_RATE'
    Aug 21 17:20:12 Desty-Media logger: autoshutdown[23566]: INFO: ' SHUTDOWNCOMMAND is set to 'pm-hibernate''
    Aug 21 17:20:12 Desty-Media logger: autoshutdown[23566]: INFO: ' Your Kernel supports the following modes from pm-utils:'
    Aug 21 17:20:12 Desty-Media logger: autoshutdown[23566]: INFO: ' Kernel supports SUSPEND (SUSPEND to RAM)'
    Aug 21 17:20:12 Desty-Media logger: autoshutdown[23566]: INFO: ' Kernel supports HIBERNATE (SUSPEND to DISK)'
    Aug 21 17:20:12 Desty-Media logger: autoshutdown[23566]: INFO: ' Kernel supports HYBRID-SUSPEND (to DISK & to RAM)'
    Aug 21 17:20:12 Desty-Media logger: autoshutdown[23566]: WARN: ' LOADAVERAGECHECK is set to false'
    Aug 21 17:20:12 Desty-Media logger: autoshutdown[23566]: WARN: ' Ignoring LOADAVERAGE'
    Aug 21 17:20:12 Desty-Media logger: autoshutdown[23566]: INFO: ' ------------------------------------------------------'
    Aug 21 17:20:12 Desty-Media logger: autoshutdown[23566]: INFO: ' Reading NICs ,IPs, ...'
    Aug 21 17:20:12 Desty-Media logger: autoshutdown[23566]: INFO: ' NIC 'bond0' not found, skipping 'bond0''
    Aug 21 17:20:12 Desty-Media logger: autoshutdown[23566]: INFO: ' NIC 'eth0' found: try to get IP'
    Aug 21 17:20:12 Desty-Media logger: autoshutdown[23566]: INFO: ' _check_networkconfig(): Run: #1: IP-Adress found'
    Aug 21 17:20:12 Desty-Media logger: autoshutdown[23566]: INFO: ' 'eth0' has IP: 192.168.0.6'
    Aug 21 17:20:12 Desty-Media logger: autoshutdown[23566]: INFO: ' NIC 'eth1' not found, skipping 'eth1''
    Aug 21 17:20:12 Desty-Media logger: autoshutdown[23566]: INFO: ' Pinglist deleted'
    Aug 21 17:20:12 Desty-Media logger: autoshutdown[23566]: INFO: '---------------- script started ----------------------'


    As you can see the script tries to execute "pm-hibernate" but without any success. Does anyone have a clue what the issue is? Actually it did not work correctly right from the start (directly after installation and configuration of OMV).
    By the way: I already switched off every UEFI option that allows to boot the computer with the exception of WOL.


    Thanks a lot

  • See extract of syslog, maybe this helps as well:


    Aug 21 17:58:21 Desty-Media - : autoshutdown [23566]: INFO: Shutdown issued: 'pm-hibernate'
    Aug 21 17:58:21 Desty-Media anacron[30803]: Anacron 2.3 started on 2015-08-21
    Aug 21 17:58:21 Desty-Media anacron[30803]: Normal exit (0 jobs run)
    Aug 21 17:58:22 Desty-Media autoshutdown [30978]: hibernate/suspend: autoshutdown-script stop from /etc/pm/sleep.d/autoshutdown-restart
    Aug 21 17:58:22 Desty-Media /etc/init.d/autoshutdown: Try to stop: There seems to be no running process of autoshutdown: /usr/local/bin/autoshutdown.sh
    Aug 21 17:58:22 Desty-Media /etc/init.d/autoshutdown: autoshutdown stopping failed!
    Aug 21 17:58:28 Desty-Media kernel: [ 7973.440290] PM: Syncing filesystems ... done.
    Aug 21 17:58:28 Desty-Media kernel: [ 7973.442706] Freezing user space processes ... (elapsed 0.001 seconds) done.
    Aug 21 17:58:28 Desty-Media kernel: [ 7973.444111] PM: Marking nosave pages: [mem 0x0009d000-0x000fffff]
    Aug 21 17:58:28 Desty-Media kernel: [ 7973.444117] PM: Marking nosave pages: [mem 0x5f12e000-0x5f1a8fff]
    Aug 21 17:58:28 Desty-Media kernel: [ 7973.444142] PM: Marking nosave pages: [mem 0x5f2ad000-0x5fa11fff]
    Aug 21 17:58:28 Desty-Media kernel: [ 7973.444178] PM: Marking nosave pages: [mem 0x5fbdb000-0x5ffc5fff]
    Aug 21 17:58:28 Desty-Media kernel: [ 7973.444198] PM: Marking nosave pages: [mem 0x60000000-0xffffffff]
    Aug 21 17:58:28 Desty-Media kernel: [ 7973.447351] PM: Basic memory bitmaps created
    Aug 21 17:58:28 Desty-Media kernel: [ 7973.447721] PM: Preallocating image memory... done (allocated 303322 pages)
    Aug 21 17:58:28 Desty-Media kernel: [ 7973.653226] PM: Allocated 1213288 kbytes in 0.20 seconds (6066.44 MB/s)
    Aug 21 17:58:28 Desty-Media kernel: [ 7973.653229] Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
    Aug 21 17:58:28 Desty-Media kernel: [ 7973.654812] Suspending console(s) (use no_console_suspend to debug)
    Aug 21 17:58:28 Desty-Media kernel: [ 7973.655769] i8042 kbd 00:03: System wakeup enabled by ACPI
    Aug 21 17:58:28 Desty-Media kernel: [ 7973.672549] PM: freeze of devices complete after 17.734 msecs
    Aug 21 17:58:28 Desty-Media kernel: [ 7973.673104] PM: late freeze of devices complete after 0.549 msecs
    Aug 21 17:58:28 Desty-Media kernel: [ 7973.674305] PM: noirq freeze of devices complete after 1.196 msecs
    Aug 21 17:58:28 Desty-Media kernel: [ 7973.674365] ACPI: Preparing to enter system sleep state S4
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.080444] PM: Saving platform NVS memory
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.086487] Disabling non-boot CPUs ...
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.086541] intel_pstate CPU 1 exiting
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.087934] kvm: disabling virtualization on CPU1
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.087998] smpboot: CPU 1 is now offline
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.088665] intel_pstate CPU 2 exiting
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.090267] kvm: disabling virtualization on CPU2
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.191834] smpboot: CPU 2 is now offline
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.192456] intel_pstate CPU 3 exiting
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.193950] kvm: disabling virtualization on CPU3
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.193960] smpboot: CPU 3 is now offline
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.194990] PM: Creating hibernation image:
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.285811] PM: Need to copy 302240 pages
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.285817] PM: Normal pages needed: 302240 + 1024, available pages: 612030
    Aug 21 17:58:28 Desty-Media kernel: [ 7975.035188] PM: Hibernation image created (302240 pages copied)
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.195218] PM: Restoring platform NVS memory
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.198284] Enabling non-boot CPUs ...
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.198484] x86: Booting SMP configuration:
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.198485] smpboot: Booting Node 0 Processor 1 APIC 0x2
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.214802] kvm: enabling virtualization on CPU1
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.217077] Intel pstate controlling: cpu 1
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.217152] CPU1 is up
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.217298] smpboot: Booting Node 0 Processor 2 APIC 0x4
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.233618] kvm: enabling virtualization on CPU2
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.235897] Intel pstate controlling: cpu 2
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.235962] CPU2 is up
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.236101] smpboot: Booting Node 0 Processor 3 APIC 0x6
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.252421] kvm: enabling virtualization on CPU3
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.254735] Intel pstate controlling: cpu 3
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.254800] CPU3 is up
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.256705] ACPI: Waking up from system sleep state S4
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.464322] acpi LNXPOWER:00: Turning OFF
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.464914] PM: noirq thaw of devices complete after 0.577 msecs
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.465325] PM: early thaw of devices complete after 0.372 msecs
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.465955] i8042 kbd 00:03: System wakeup disabled by ACPI
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.506226] r8169 0000:03:00.0 eth0: link down
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.556217] PM: thaw of devices complete after 90.929 msecs
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.556695] PM: writing image.
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.567112] PM: Using 3 thread(s) for compression.

  • your system seems to enter "S4" = Hibernation but something wakes it up just after hibnernation:

    Code
    Aug 21 17:58:28 Desty-Media kernel: [ 7973.655769] i8042 kbd 00:03: System wakeup enabled by ACPI
    ...
    Aug 21 17:58:28 Desty-Media kernel: [ 7974.256705] ACPI: Waking up from system sleep state S4


    Please check your BIOS. Maybe you have eneabled "Wake up on Mouse move" or something like that.
    If that doesn't work:
    1. disable the autoshutdown script completely
    2. reboot
    3. login via SSH and execute "pm-hibernate"
    4. see what your PC does, wait 5 min and try to wake it up with mouse or keyboard
    (5 min because then I can clearly see a difference between hibernation and anything else in the log)
    5. wake it up with WOL
    6. repeat 3. - 5. and see if it works as expected
    7. please upload the whole syslog on pastebin and send me the link

  • Hi,


    thanks for your quick reply.


    1. disable the autoshutdown script completely
    I disabled the plugin in the specific tab


    2. reboot
    3. login via SSH and execute "pm-hibernate"
    This does work, even many times after another


    4. see what your PC does, wait 5 min and try to wake it up with mouse or keyboard
    (5 min because then I can clearly see a difference between hibernation and anything else in the log)
    This does work as well.


    5. wake it up with WOL
    Does work as well.


    6. repeat 3. - 5. and see if it works as expected
    Yes, no problems at all if executed manually.


    7. please upload the whole syslog on pastebin and send me the link


    http://pastebin.com/FbWaLQsL (syslog after pm-hibernate; wakeup executed using P/S2 keyboard)
    http://pastebin.com/dBCV6ACh (syslog after pm-hibernate; wakeup executed using WOL)


    Maybe this'll help to clearify things.

  • Hello,


    my problem seems to be exactly the same.
    So what was the solution ?


    My Server: Asrock N3150-ITX, debian wheezy 7.9 as base system, OMV stoneburner 2.1.23 installed according to howto of Solo0815, backport kernel 3.16


    Thanks !

  • I had a similar problem after upgrading to the latest version, which has been solved by the developers in the meantime. The problem was that the autoshutdown service did not restart after resume. In my particular case the file /etc/pm/sleep.d/autoshutdown.conf was not executable.

    OMV 3.0.94


    Hardware:
    ASRock N3700-ITX
    1x4GB DDR3-1600 SO-DIMM
    2x4000GB WD Red and 2x4000GB WD Green in mdadm RAID5
    16 GB Mach Xtreme Technology Ultra MX-ES USB 3.0 as root
    Fractal Design Node 304 with PicoPSU

Participate now!

Don’t have an account yet? Register yourself now and be a part of our community!