Bug 240411 - devd behaves odd when action uses single quotes
Summary: devd behaves odd when action uses single quotes
Status: Closed FIXED
Alias: None
Product: Base System
Classification: Unclassified
Component: bin (show other bugs)
Version: 12.0-RELEASE
Hardware: Any Any
: --- Affects Many People
Assignee: Warner Losh
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2019-09-08 09:07 UTC by nvass
Modified: 2021-07-08 05:04 UTC (History)
3 users (show)

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description nvass 2019-09-08 09:07:01 UTC
Using this rule on FreeBSD-12:
notify 10 {
        match "system"          "ZFS";
        match "type"            "misc.fs.zfs.scrub_start";
        action "touch /var/run/scrub_$pool_name; logger -t ZFS 'zpool $pool_name started scrubbing'";
};

notify 10 {
        match "system"          "ZFS";
        match "type"            "misc.fs.zfs.scrub_finish";
        action "rm /var/run/scrub_$pool_name; logger -t ZFS 'zpool $pool_name finished scrubbing'";
};

creates these messages in /var/log/messages
Sep  8 11:51:35 aurora ZFS[12797]: vdev state changed, pool_guid=$5355245379867352521 vdev_guid=$1907996185387027531
Sep  8 11:51:35 aurora ZFS[12798]: vdev state changed, pool_guid=$5355245379867352521 vdev_guid=$9030209902286509774
Sep  8 11:51:35 aurora ZFS[12799]: vdev state changed, pool_guid=$5355245379867352521 vdev_guid=$2872996488705391350
Sep  8 11:51:35 aurora ZFS[12800]: vdev state changed, pool_guid=$5355245379867352521 vdev_guid=$13633596582270114039
Sep  8 11:51:35 aurora ZFS[12801]: zpool $aurora-os started scrubbing

The pool name should be aurora-os without the leading dollar sign. This only happens when variables are enclosed in single quotes. The same rule behaves correctly on earlier versions. 

/var/run/devd.pipe on FBSD-12:
!system=ZFS subsystem=ZFS type=resource.fs.zfs.statechange  version=0 class=resource.fs.zfs.statechange pool_guid=5355245379867352521 vdev_guid=1907996185387027531
!system=ZFS subsystem=ZFS type=resource.fs.zfs.statechange  version=0 class=resource.fs.zfs.statechange pool_guid=5355245379867352521 vdev_guid=9030209902286509774
!system=ZFS subsystem=ZFS type=resource.fs.zfs.statechange  version=0 class=resource.fs.zfs.statechange pool_guid=5355245379867352521 vdev_guid=2872996488705391350
!system=ZFS subsystem=ZFS type=resource.fs.zfs.statechange  version=0 class=resource.fs.zfs.statechange pool_guid=5355245379867352521 vdev_guid=13633596582270114039
!system=ZFS subsystem=ZFS type=misc.fs.zfs.scrub_start  pool_name=aurora-os pool_guid=5355245379867352521
!system=ZFS subsystem=ZFS type=misc.fs.zfs.history_event  pool_name=aurora-os pool_guid=5355245379867352521 history_hostname=aurora.local history_internal_str=func=1 mintxg=0 maxtxg=1064734 history_internal_name=scan setup history_txg=1064734 history_time=1567933234



/var/run/devd.pipe on FBSD-10:
!system=ZFS subsystem=ZFS type=misc.fs.zfs.scrub_start  pool_name=clio pool_guid=1203689305036940146
Comment 1 Renato Botelho freebsd_committer freebsd_triage 2019-09-26 17:13:04 UTC
It seems to be introduced by this commit:

https://svnweb.freebsd.org/base?view=revision&revision=338888
Comment 2 Warner Losh freebsd_committer freebsd_triage 2019-09-26 17:31:47 UTC
Looks like a bug to me... The referenced commit is correct for other cases, but not for this one. I'll look into it.
Comment 3 Renato Botelho freebsd_committer freebsd_triage 2020-05-01 15:41:48 UTC
(In reply to Warner Losh from comment #2)
Hi Warner!

Did you have any chance to look into this issue?
Comment 4 Warner Losh freebsd_committer freebsd_triage 2020-05-01 15:47:04 UTC
(In reply to Renato Botelho from comment #3)

I haven't had a chance to look at it, but the quotes in the examples aren't needed. logger will do the right thing without them with multiple arguments. And in a strict /bin/sh world, nothing should be expanded inside single quotes. One can make a good case for passing them to the child shell.

In any case, it's behaving in a way that's not right either in the intuitive sense, nor in the historic behavior of shells.
Comment 5 Warner Losh freebsd_committer freebsd_triage 2020-10-09 15:04:17 UTC
Another example

action "logger -p local7.err -t ZFS 'vdev problem, zpool=$pool path=$vdev_path type=$type'";

Gets expanded to 

logger -p local7.err -t ZFS 'vdev problem, zpool=$'$pool' path=$'$vdev_path' type=$'$type''

which leads to the extra $. This makes the expansion of $foo one argument, protecting it from the usual list of troublesome characters, at the expense of breaking this case.
Comment 6 commit-hook freebsd_committer freebsd_triage 2020-10-09 15:30:08 UTC
A commit references this bug:

Author: imp
Date: Fri Oct  9 15:29:06 UTC 2020
New revision: 366578
URL: https://svnweb.freebsd.org/changeset/base/366578

Log:
  Avoid using single quotes in arguments to logger.

  Single quotes interfere with the workaround put in with r335753 and
  aren't necessary in this case. I believe that all the underling issues
  with r335753 have been corrected, but need to do more extensive
  followup before reverting it as a bad idea.

  PR: 240411
  MFC After: 2 days (to give it time to get into 12.2)

Changes:
  head/sbin/devd/zfs.conf
Comment 7 Renato Botelho freebsd_committer freebsd_triage 2020-10-23 13:16:48 UTC
(In reply to commit-hook from comment #6)
The problem persists and here are the steps to reproduce it.  I wrote this script:

#!/bin/sh

echo "Param1 = '${1}'" >> /root/log
echo "Param2 = '${2}'" >> /root/log

And added this action on devd config:

notify 0 {
        match "system"          "IFNET";
        match "type"            "LINK_UP";
        media-type              "ethernet";
    action "/root/log.sh -c 'interface linkup start '$subsystem";
};

notify 0 {
        match "system"          "IFNET";
    match "type"            "LINK_DOWN";
    media-type              "ethernet";
    action "/root/log.sh -c 'interface linkup stop '$subsystem";
};

And got the following output on /root/log:

Param1 = '-c'
Param2 = 'interface linkup start $em0'
Comment 8 Warner Losh freebsd_committer freebsd_triage 2020-10-24 00:22:14 UTC
(In reply to Renato Botelho from comment #7)

I have a very similar test script and after I restarted devd, I couldn't reproduce it.
Comment 9 Warner Losh freebsd_committer freebsd_triage 2021-07-08 05:04:05 UTC
This has been fixed. If issues remain, please reopen.