Verbosity flags have no effect or crash application at startup when statet first in INSANED_EXTRAOPTS

[antimatter84]

I wanted to get more verbose logging from insaned and provided more v's to INSANED_EXTRAOPTS like this:

INSANED_EXTRAOPTS="--sleep-ms=1000 --suspend-after-event -vv"

So for every 'v' the verbosity level is incremented. In the C++ code, most calls to InsaneDaemon::log(...) use log levels ranging from 0 to 2. But even with "-vv", none of these logs are printed to /var/log/insaned.log. Some of the log messages should be written when an scanner button event triggers. The default log file is used.

Another issue: When placing "-vv" at the beginning of the INSANED_EXTRAOPTS string, the daemon fails during startup. Example:

INSANED_EXTRAOPTS="-vv --sleep-ms=1000 --suspend-after-event"

$ sudo systemctl restart insaned
Job for insaned.service failed because the control process exited with error code. See "systemctl status insaned.service" and "journalctl -xe" for details.

$ sudo systemctl status insaned
● insaned.service - SANE scanner button polling service
   Loaded: loaded (/lib/systemd/system/insaned.service; enabled; vendor preset: enabled)
   Active: inactive (dead) (Result: exit-code) since Mo 2018-07-09 11:09:56 CEST; 1min 31s ago
  Process: 25017 ExecStart=/usr/bin/insaned -p /var/run/insaned/insaned.pid ${INSANED_EXTRAOPTS} (code=exited, status=1/FAILURE)
 Main PID: 24999 (code=exited, status=1/FAILURE)

Jul 09 11:09:56 MYHOSTNAME systemd[1]: Failed to start SANE scanner button polling service.
Jul 09 11:09:56 MYHOSTNAME systemd[1]: insaned.service: Unit entered failed state.
Jul 09 11:09:56 MYHOSTNAME systemd[1]: insaned.service: Failed with result 'exit-code'.
Jul 09 11:09:56 MYHOSTNAME systemd[1]: insaned.service: Service hold-off time over, scheduling restart.
Jul 09 11:09:56 MYHOSTNAME systemd[1]: Stopped SANE scanner button polling service.
Jul 09 11:09:56 MYHOSTNAME systemd[1]: insaned.service: Start request repeated too quickly.
Jul 09 11:09:56 MYHOSTNAME systemd[1]: Failed to start SANE scanner button polling service.
Jul 09 11:09:58 MYHOSTNAME systemd[1]: Stopped SANE scanner button polling service.
Jul 09 11:09:58 MYHOSTNAME systemd[1]: insaned.service: Start request repeated too quickly.
Jul 09 11:09:58 MYHOSTNAME systemd[1]: Failed to start SANE scanner button polling service.

$ journalctl -xe
<snip>
-- Unit insaned.service has begun starting up.
Jul 09 11:09:56 MYHOSTNAME insaned[25017]: /usr/bin/insaned: invalid option -- ' '
Jul 09 11:09:56 MYHOSTNAME systemd[1]: insaned.service: Control process exited, code=exited status=1
Jul 09 11:09:56 MYHOSTNAME systemd[1]: Failed to start SANE scanner button polling service.
-- Subject: Unit insaned.service has failed
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit insaned.service has failed.
-- 
-- The result is failed.

System: Linux Mint 19 Cinnamon

[abusenius]

Looks like systemd does not split ${INSANED_EXTRAOPTS} on whitespace and passes all of it as one big parameter, but it is not recognized as error... I'll try to reproduce this on my ubuntu machine.

Maybe removing quotes from INSANED_EXTRAOPTS="-vv --sleep-ms=1000 --suspend-after-event" will help.

[antimatter84]

I tried, but the double quotes are not the problem. I removed the curly braces { } around the $INSANED_EXTRAOPTS variable in the insaned.service file. Then systemd stopped complaining.

Edit: Ah, here is an explanation for that: https://stackoverflow.com/questions/33097284/bash-brace-expansion-in-systemd-execstart Instead of removing the curly braces, double dollar should also have worked: $${INSANED_EXTRAOPTS} (not tested)