[PLUG] incron issue
Denis Heidtmann
denis.heidtmann at gmail.com
Wed Nov 22 03:12:17 UTC 2017
Me looking at kernel software would be no more educational than me reading
about it in Greek. And I did not think I wanted to debug the spooler,
whatever that is.
So to get down to the essentials, using only IN_CLOSE_WRITE, I get four
events (with this particular application printing). For a big print job
the timespan from the first event to the last is 10 seconds. I can explore
my two other applications and come up with a maximum (probable) time. Add
a buffer to that and use that time as a delay prior to printing the file.
That was my intended approach.
As I understand your approach it is to check the time stamp for the file in
question, delay 2 seconds, then assume if no change has occurred, the file
is ready to print. Is this understanding correct? If so, this assumes
that the driver/application changes the file more frequently than every 2
seconds. To explore that, I was trying to send the time to the log every
time I got an icron invocation with the IN_ALL_EVENTS mask. Hence my use
of that mask and trying to capture the time to the log. This, I hope,
explains why I wanted to see the result of <echo -n "time: $(stat -c '%Y'
$1)" >> /home/denis/incronlog.log>, and the question of why no time appears
in the log. Notice that there are many cases in the log where $1 appears
to be a filename.
-Denis
On Tue, Nov 21, 2017 at 1:37 PM, Tomas Kuchta <tomas.kuchta.lists at gmail.com>
wrote:
> Of course that you see some/many invocations without any file names when
> you trigger on all directory events. All sorts of of processes go by all
> sorts of directories all the time on modern desktop. Not all of them look
> at files.
>
> What your aim is, I believe/hope, to respond to print file write and close
> - and send that file to a printer. Ideally deleting or backing that file
> away from the print dir. You want to do that reliably and without multiple
> processes acting on any given file.
>
> If you want to debug print job spooler, I would suggest to do just that. Do
> exactly what you need to do, keep it simple, and expand from there.
>
> If you are curious about kernel interworks, I would suggest to start
> looking at kernel documentation and source code - it is more systematic way
> of learning. Unfortunately, I am not the right person to have meaningful
> conversation about kernel and VFS events/triggers. My knowledge is too
> shallow for that.
>
> Good luck,
> Tomas
>
> On Nov 21, 2017 9:44 AM, "Denis Heidtmann" <denis.heidtmann at gmail.com>
> wrote:
>
> > It is fully my intention to use only IN_CLOSE_WRITE in the final version.
> > I currently am using IN_ALL_EVENTS just to see what the print
> > driver/application is doing. In fact, when I first started working on
> this
> > I used just IN_CLOSE_WRITE and saw 4 invocations. That is what sent me
> > exploring.
> >
> > Regarding what is in $1, I see what seems to me to indicate a file name
> in
> > $1 *sometimes*. Why only sometimes? Here is the test script:
> > #! /bin/bash
> > # test of incron
> > echo -n "time: $(stat -c '%Y' $1)" >> /home/denis/incronlog.log
> > echo "test: $1 $2" >> /home/denis/incronlog.log
> >
> > I get perhaps 270 invocations with IN_ALL_EVENTS. A sampling shows some
> > responses with the file name, but no times:
> >
> > test: IN_ACCESS,IN_ISDIR
> > time: test: IN_CLOSE_NOWRITE,IN_ISDIR
> > time: test: IN_CLOSE_NOWRITE,IN_ISDIR
> > time: test: tst1.PLT IN_OPEN
> > time: time: test: tst1.PLT IN_OPEN
> > test: tst1.PLT IN_OPEN
> > time: test: tst1.PLT IN_CLOSE_NOWRITE
> > time: test: tst1.PLT IN_ACCESS
> > time: test: tst1.PLT IN_CLOSE_NOWRITE
> > time: time: test: IN_CLOSE_NOWRITE,IN_ISDIR
> > test: IN_ACCESS,IN_ISDIR
> > time: test: tst1.PLT IN_CLOSE_NOWRITE
> >
> > There are a number of questions raised by this, but I expect that most
> can
> > be explained by the rapid multiple invocations. Does that also explain
> the
> > missing times?
> >
> > -Denis
> >
> >
> > On Tue, Nov 21, 2017 at 12:23 AM, Tomas Kuchta <
> > tomas.kuchta.lists at gmail.com
> > > wrote:
> >
> > > $(some command) will simply execute the command and give return value.
> > >
> > > You do not see any time stamp because you are not giving stat a file.
> $1,
> > > in
> > > your case, doesn't contain file name.
> > >
> > > I have asked or suggested before to only use IN_CLOSE_WRITE event. That
> > is
> > > what you want - run the script after the file/dir was written to and is
> > > closed. Not the other times when you look at it or read the file with
> > your
> > > script. Taking those other events off should solve the multiple
> > invocation
> > > problem.
> > >
> > > I hope it helps,
> > > Tomas
> > >
> > >
> > > On Nov 20, 2017 5:54 PM, "Denis Heidtmann" <denis.heidtmann at gmail.com>
> > > wrote:
> > >
> > > Working my way through the script, trying to understand the behavior.
> > Here
> > > is a simple test:
> > >
> > > #! /bin/bash
> > > # test of incron
> > > echo -n "time: $(stat -c '%Y' $1)" >> /home/denis/incronlog.log
> > > echo "test: $1 $2" >> /home/denis/incronlog.log
> > > # sleep 10
> > >
> > > It generates what I would expect when executed from the command line:
> > > ~/scripts/intest.sh examples.desktop:
> > > time: 1464568514test: examples.desktop
> > >
> > > But when invoked by incron the line including the time is empty except
> > for
> > > the word "time:" The time value is absent.
> > > time: time: test: IN_ACCESS,IN_ISDIR
> > > test: IN_CLOSE_NOWRITE,IN_ISDIR
> > > time: test: IN_ACCESS,IN_ISDIR
> > > time: test: IN_OPEN,IN_ISDIR
> > > time: test: IN_OPEN,IN_ISDIR
> > > etc.
> > >
> > > My knowledge of the use of $, (, ", ', and { is lacking, so I expect
> > > that is where the trouble lies.
> > >
> > > Is the problem obvious?
> > >
> > > Thanks,
> > > -Denis
> > >
> > > On Sun, Nov 19, 2017 at 10:42 PM, Tomas Kuchta <
> > > tomas.kuchta.lists at gmail.com
> > > > wrote:
> > >
> > > > The script I posted does its own locking, so that other copies would
> > know
> > > > that it is already running and what file it is serving.
> > > >
> > > > See the lock file being created, checked and removed.
> > > >
> > > > Tomas
> > > >
> > > > On Nov 19, 2017 9:10 PM, "Denis Heidtmann" <
> denis.heidtmann at gmail.com>
> > > > wrote:
> > > >
> > > > > Your script has things in it that stretch my knowledge of Bash, so
> > > > > understanding what it does is difficult for me.
> > > > >
> > > > > I have no experience with file locking. Is this a standard
> protocol?
> > > > > Since the print file is created by a Windows print driver, I wonder
> > if
> > > > the
> > > > > locking which is described in the ubuntu docs is reliably
> applicable.
> > > > >
> > > > > This is likely a discussion that stretches what is reasonable to
> > > attempt
> > > > > via a forum, since I need considerable education.
> > > > >
> > > > > I appreciate your efforts. I will play with it in an attempt to
> > learn
> > > > what
> > > > > you are proposing, but do not be surprised if it takes me some
> time.
> > > > >
> > > > > -Denis
> > > > >
> > > > >
> > > > >
> > > > > On Sat, Nov 18, 2017 at 9:17 PM, Tom <tomas.kuchta.lists at gmail.com
> >
> > > > wrote:
> > > > >
> > > > > > Hi Denis,
> > > > > >
> > > > > > Try something like the script below.
> > > > > > It uses a lock to detect its own invocation as well as multiple
> > > > > > invocations of self. If it prints it backs up the printed file,
> so
> > > you
> > > > > > should not lose anything, should things go south.
> > > > > >
> > > > > > Note: I did not properly test it. So, give it good pass over and
> > test
> > > > > > it before calling it a day. As I said, it should not loose any
> > print
> > > > > > files and you should know if it prints.
> > > > > >
> > > > > > Please insert your own print command instead of the echo "" and
> > > > > > redirect the output to a log file or /dev/null so it does not end
> > up
> > > > > > with incron.
> > > > > >
> > > > > > Beware of broken script lines by the email.
> > > > > >
> > > > > > I hope that it works as intended or as an example,
> > > > > > Tomas
> > > > > >
> > > > > > #!/bin/bash
> > > > > > ##########################################
> > > > > > # This command submits a file to print
> > > > > > # It is triggered by incron and tries to
> > > > > > # gracefully deal with multiple incron invocations
> > > > > > # and waits for file to be closed by the
> > > > > > # print application.
> > > > > > # Example incron line:
> > > > > > # printDirToMonitor IN_CLOSE_WRITE submitPrinterJob.bash $#
> > > > > > ##########################################
> > > > > > lockDir=/tmp/
> > > > > > lockFileBaseName=/tmp/submitPrinterJob
> > > > > > thisPid=$$
> > > > > > fileToPrint=$1
> > > > > > printedFilesDir=/home/$USER/printedFilesDir
> > > > > > mkdir -p $printedFilesDir
> > > > > >
> > > > > > searchLockPattern="${lockFileBaseName}_${fileToPrint}_*.lock"
> > > > > > myLockFileName="${lockFileBaseName}_${
> > fileToPrint}_${thisPid}.lock"
> > > > > >
> > > > > > # check if the file to print is still there
> > > > > > if [ -e $fileToPrint ]; then
> > > > > > # Check if another script is running and serving this file
> > > > > > # Issue lock if not
> > > > > > c=0
> > > > > > while (( $c < 2 )); do
> > > > > > if [ ! -e $searchLockPattern ]; then
> > > > > > # Cannot see any other process'lock
> > > > > > touch $myLockFileName
> > > > > > else
> > > > > > # there is a lock
> > > > > > if [ ! -e $myLockFileName ]; then
> > > > > > # the lock is not mine --> exit without printing,
> > > > > > # make sure not to leave own lock, in case it take time
> to
> > > > > > # show up
> > > > > > rm -f $myLockFileName
> > > > > > exit 0
> > > > > > fi
> > > > > > fi
> > > > > > # There should be a lock and mine --> do nothing , just wait
> > > > > > c=$(( $c + 1 ))
> > > > > > sleep 2
> > > > > > done
> > > > > > # if I got here I got a lock --> send the file to printer
> > > > > > if [ ! -e $fileToPrint ]; then
> > > > > > echo "WARNING: File $fileToPrint disapeared"
> > > > > > else
> > > > > > echo "Printing file $fileToPrint"
> > > > > > # backing up and removing printed file
> > > > > > mv $fileToPrint $printedFilesDir
> > > > > > sleep 1
> > > > > > # removing lock file
> > > > > > rm -f $myLockFileName
> > > > > > fi
> > > > > > fi
> > > > > > exit 0
> > > > > > ##########################################
> > > > > >
> > > > > > On Sat, 2017-11-18 at 15:01 -0800, Denis Heidtmann wrote:
> > > > > > > It turns out that the multiple file closings is at least
> > partially
> > > > > > > attributable to the application, since another application had
> > two
> > > > > > > closings
> > > > > > > rather than four. Using the application with the four
> closings I
> > > > > > > tried
> > > > > > > again with a much more complicated drawing. This slowed down
> the
> > > > > > > writing
> > > > > > > of the print file to 10 seconds. Those 10 seconds were taken
> up
> > > > > > > mostly
> > > > > > > between the first and second closing (4 sec.) and the third and
> > > > > > > fourth (6
> > > > > > > sec.) I may need to put a delay at the start of my printing
> > script
> > > > > > > so it
> > > > > > > does not try to print an incomplete file.
> > > > > > >
> > > > > > > An aside: The "masks" in the incrontab are separated by comas
> > but
> > > no
> > > > > > > spaces are allowed.
> > > > > > >
> > > > > > > Nothing turns out as simple as it appears initially.
> > > > > > >
> > > > > > > -Denis
> > > > > > >
> > > > > > > On Fri, Nov 17, 2017 at 11:38 PM, Tom <
> > > tomas.kuchta.lists at gmail.com>
> > > > > > > wrote:
> > > > > > >
> > > > > > > >
> > > > > > > > I am glad you worked it out. Well done.
> > > > > > > >
> > > > > > > > Darn fast computers!!
> > > > > > > >
> > > > > > > > -T
> > > > > > > >
> > > > > > > > On Fri, 2017-11-17 at 18:04 -0800, Denis Heidtmann wrote:
> > > > > > > > >
> > > > > > > > > On the "Create": this convinces me that I should take up
> > > > > > > > > drinking
> > > > > > > > > coffee,
> > > > > > > > > so some stronger brain stimulant. Dumb.
> > > > > > > > >
> > > > > > > > > On the multiple entries, I think the issue is that my test
> > > script
> > > > > > > > > is
> > > > > > > > > very
> > > > > > > > > short and fast. I added a sleep 10 and I get only one
> > > entry--the
> > > > > > > > > first
> > > > > > > > > one. Apparently the print driver (or the program calling
> it)
> > > > > > > > > closes
> > > > > > > > > the
> > > > > > > > > file multiple times. I added $% to the incrontab file and
> %2
> > > to
> > > > > > > > > the
> > > > > > > > > script
> > > > > > > > > (but w/o the sleep in my script) I got:
> > > > > > > > >
> > > > > > > > > test1 create test23 IN_CLOSE_WRITE
> > > > > > > > > test1 create test23.PLT IN_CLOSE_WRITE
> > > > > > > > > test1 create test23.PLT IN_CLOSE_WRITE
> > > > > > > > > test1 create test23.PLT IN_CLOSE_WRITE
> > > > > > > > >
> > > > > > > > > This behavior of the driver/application seems not the best,
> > but
> > > > > > > > > there
> > > > > > > > > is
> > > > > > > > > nothing to be done about it. I assume that my printing
> > script
> > > > > > > > > will
> > > > > > > > > take
> > > > > > > > > sufficient time it will not matter.
> > > > > > > > >
> > > > > > > > > I recorded the times associated with the four log entries.
> > It
> > > > > > > > > was
> > > > > > > > > 347 msec
> > > > > > > > > overall, with the last step taking most of this time at
> about
> > > 300
> > > > > > > > > msec. So
> > > > > > > > > my anticipation that the multiple writes/closing will not
> > > matter
> > > > > > > > > seems
> > > > > > > > > reasonable. Let's hope so.
> > > > > > > > >
> > > > > > > > > Thanks again for the suggestion.
> > > > > > > > >
> > > > > > > > > -Denis
> > > > > > > > >
> > > > > > > > > On Fri, Nov 17, 2017 at 2:02 PM, Tomas Kuchta
> > > <tomas.kuchta.lists
> > > > > > > > > @gma
> > > > > > > > > il.com>
> > > > > > > > > wrote:
> > > > > > > > >
> > > > > > > > > >
> > > > > > > > > >
> > > > > > > > > > If I recall incron details correctly, you get multiple
> > > entries
> > > > > > > > > > in
> > > > > > > > > > your log
> > > > > > > > > > because you run your script multiple times at different
> > > events:
> > > > > > > > > > IN_CLOSE_WRITE,IN_NO_LOOP
> > > > > > > > > >
> > > > > > > > > > Your other question: You see "create" in your log because
> > > that
> > > > > > > > > > is
> > > > > > > > > > what your
> > > > > > > > > > echo command puts there in your script.
> > > > > > > > > >
> > > > > > > > > > -Tomas
> > > > > > > > > >
> > > > > > > > > > On Nov 17, 2017 11:47 AM, "Denis Heidtmann"
> > > <denis.heidtmann at gm
> > > > > > > > > > ail.
> > > > > > > > > > com>
> > > > > > > > > > wrote:
> > > > > > > > > >
> > > > > > > > > > I have pursued Tomas' advice to use incron to
> automatically
> > > > > > > > > > send
> > > > > > > > > > files
> > > > > > > > > > written by the win2k print driver to the printer. I have
> > > > > > > > > > everything down
> > > > > > > > > > to one issue. To test, I have a simple script
> (intest.sh)
> > > that
> > > > > > > > > > just sends
> > > > > > > > > > the event responded to to a log file:
> > > > > > > > > >
> > > > > > > > > > #! /bin/bash
> > > > > > > > > > # test of incron
> > > > > > > > > > echo "tes1 create " $1 >> /home/denis/incronlog.log
> > > > > > > > > >
> > > > > > > > > > The incron table is:
> > > > > > > > > >
> > > > > > > > > > /home/denis/win2kfiles/Print_files
> > IN_CLOSE_WRITE,IN_NO_LOOP
> > > > > > > > > > /home/denis/scripts/intest.sh $#
> > > > > > > > > >
> > > > > > > > > > The resulting log is:
> > > > > > > > > >
> > > > > > > > > > tes1 create test12
> > > > > > > > > > tes1 create test12.PLT
> > > > > > > > > > tes1 create test12.PLT
> > > > > > > > > > tes1 create test12.PLT
> > > > > > > > > >
> > > > > > > > > > It generates multiple entries for one file added (i.e.,
> one
> > > > > > > > > > print
> > > > > > > > > > command). I added IN_ONESHOT to the incrontab:
> > > > > > > > > >
> > > > > > > > > > /home/denis/win2kfiles/Print_files
> > > > > > > > > > IN_CLOSE_WRITE,IN_ONESHOT,IN_NO_LOOP
> > > > > > > > > > /home/denis/scripts/intest.sh $#
> > > > > > > > > >
> > > > > > > > > > I still got multiple entries in the log.
> > > > > > > > > >
> > > > > > > > > >
> > > > > > > > > > Questions:
> > > > > > > > > > Why does the log not say "close" instead of "create"?
> > > > > > > > > > Why four entries?
> > > > > > > > > > What might the result be when the script intest.sh is
> > > replaced
> > > > > > > > > > by
> > > > > > > > > > one that
> > > > > > > > > > prints and deletes the files? Will it be called 4 times
> in
> > > > > > > > > > rapid
> > > > > > > > > > succession?
> > > > > > > > > >
> > > > > > > > > > Any suggestions for testing further?
> > > > > > > > > >
> > > > > > > > > > Thanks,
> > > > > > > > > > -Denis
> > > > > > > > > > _______________________________________________
> > > > > > > > > > PLUG mailing list
> > > > > > > > > > PLUG at pdxlinux.org
> > > > > > > > > > http://lists.pdxlinux.org/mailman/listinfo/plug
> > > > > > > > > > _______________________________________________
> > > > > > > > > > PLUG mailing list
> > > > > > > > > > PLUG at pdxlinux.org
> > > > > > > > > > http://lists.pdxlinux.org/mailman/listinfo/plug
> > > > > > > > > >
> > > > > > > > > _______________________________________________
> > > > > > > > > PLUG mailing list
> > > > > > > > > PLUG at pdxlinux.org
> > > > > > > > > http://lists.pdxlinux.org/mailman/listinfo/plug
> > > > > > > > _______________________________________________
> > > > > > > > PLUG mailing list
> > > > > > > > PLUG at pdxlinux.org
> > > > > > > > http://lists.pdxlinux.org/mailman/listinfo/plug
> > > > > > > >
> > > > > > > _______________________________________________
> > > > > > > PLUG mailing list
> > > > > > > PLUG at pdxlinux.org
> > > > > > > http://lists.pdxlinux.org/mailman/listinfo/plug
> > > > > > _______________________________________________
> > > > > > PLUG mailing list
> > > > > > PLUG at pdxlinux.org
> > > > > > http://lists.pdxlinux.org/mailman/listinfo/plug
> > > > > >
> > > > > _______________________________________________
> > > > > PLUG mailing list
> > > > > PLUG at pdxlinux.org
> > > > > http://lists.pdxlinux.org/mailman/listinfo/plug
> > > > >
> > > > _______________________________________________
> > > > PLUG mailing list
> > > > PLUG at pdxlinux.org
> > > > http://lists.pdxlinux.org/mailman/listinfo/plug
> > > >
> > > _______________________________________________
> > > PLUG mailing list
> > > PLUG at pdxlinux.org
> > > http://lists.pdxlinux.org/mailman/listinfo/plug
> > > _______________________________________________
> > > PLUG mailing list
> > > PLUG at pdxlinux.org
> > > http://lists.pdxlinux.org/mailman/listinfo/plug
> > >
> > _______________________________________________
> > PLUG mailing list
> > PLUG at pdxlinux.org
> > http://lists.pdxlinux.org/mailman/listinfo/plug
> >
> _______________________________________________
> PLUG mailing list
> PLUG at pdxlinux.org
> http://lists.pdxlinux.org/mailman/listinfo/plug
>
More information about the PLUG
mailing list