hp-sendfax stop working after upgrade

[_AnK]

HP Linux Imaging and Printing System (ver. 3.12.9)
PC Sendfax Utility ver. 9.0
System Tray Status Service ver. 2.0

Description of problem:
After updating hplip from 3.12.6 to 3.12.9 version (using yum), hp-sendfax stop working.
When executing: hp-sendfax -n -f 18884732963 -l debug test
I observe the following lines over and over:

hp-sendfax[10322]: debug: Waiting for fax...
hp-sendfax[10322]: debug: [dbus.String(u'hpfax:/net/Officejet_4620_series?zc=HPB4B52F1D2587'), dbus.String(u''), dbus.Int32(0), dbus.String(u'akavalov'), dbus.Int32(119), dbus.String(u''), dbus.Double(0.0), dbus.String(u'')]
No communication with the FAX.

Reproducible always.

Additional info:
Hardware - HP OFFICEJET 4620 AIO.
Linux armat1.home 3.4.11-1.fc16.x86_64 #1 SMP Sun Sep 16 13:50:06 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux

Disabling SElinux does not change this behavour. Any ideas?

[Gaurav Sood (gaurav-sood)]

Try sending fax using the GUI of hp-sendfax utility. Just run 'hp-sendfax' on the terminal and follow the subsequent GUI steps

[_AnK (andk)]

I try that - no good. I also try to reinstall hplip(and gui). THen fisically attached the printer to PC via USB and install the device(s). Still fax is not working. What is puzzling is that in the earlier version it worked fine even as a network fax. I found the following lines in the error_log file:
W [25/Sep/2012:10:05:09 -0400] [CGI] Missing NickName and ModelName in /usr/share/cups/model/foomatic-db-ppds/Epson/eplp880c.ppd.gz!
W [25/Sep/2012:10:05:09 -0400] [CGI] Missing NickName and ModelName in /usr/share/cups/model/foomatic-db-ppds/Epson/eplp950c.ppd.gz!
W [25/Sep/2012:10:05:09 -0400] [CGI] Missing NickName and ModelName in /usr/share/cups/model/foomatic-db-ppds/Epson/eplp980c.ppd.gz!
W [25/Sep/2012:10:05:09 -0400] [CGI] Missing NickName and ModelName in /usr/share/cups/model/foomatic-db-ppds/Epson/eplp830c.ppd.gz!
W [25/Sep/2012:10:05:09 -0400] [CGI] Missing NickName and ModelName in /usr/share/cups/model/foomatic-db-ppds/Epson/eplp960s.ppd.gz!
W [25/Sep/2012:10:05:09 -0400] [CGI] Missing NickName and ModelName in /usr/share/cups/model/foomatic-db-ppds/Epson/eplp850c.ppd.gz!
W [25/Sep/2012:10:05:09 -0400] [CGI] Missing NickName and ModelName in /usr/share/cups/model/foomatic-db-ppds/Epson/eplp920c.ppd.gz!
W [25/Sep/2012:10:05:09 -0400] [CGI] Missing NickName and ModelName in /usr/share/cups/model/foomatic-db-ppds/Epson/eplp9100.ppd.gz!
W [25/Sep/2012:10:05:09 -0400] [CGI] Missing NickName and ModelName in /usr/share/cups/model/foomatic-db-ppds/KONICA_MINOLTA/KOC451JX.ppd.gz!
W [25/Sep/2012:10:05:09 -0400] [CGI] Missing NickName and ModelName in /usr/share/cups/model/foomatic-db-ppds/Brother/BR5070DN_GPL.ppd.gz!
W [25/Sep/2012:10:05:51 -0400] failed to CreateProfile: org.freedesktop.ColorManager.AlreadyExists:profile id 'Officejet_4620-Gray..' already exists
W [25/Sep/2012:10:05:51 -0400] failed to CreateProfile: org.freedesktop.ColorManager.AlreadyExists:profile id 'Officejet_4620-RGB..' already exists
W [25/Sep/2012:10:05:51 -0400] failed to CreateDevice: org.freedesktop.ColorManager.AlreadyExists:device id 'cups-Officejet_4620' already exists
W [25/Sep/2012:10:05:51 -0400] failed to CreateProfile: org.freedesktop.ColorManager.AlreadyExists:profile id 'Officejet_4620-Gray..' already exists
W [25/Sep/2012:10:05:51 -0400] failed to CreateProfile: org.freedesktop.ColorManager.AlreadyExists:profile id 'Officejet_4620-RGB..' already exists
W [25/Sep/2012:10:05:51 -0400] failed to CreateDevice: org.freedesktop.ColorManager.AlreadyExists:device id 'cups-Officejet_4620' already exists
W [25/Sep/2012:10:05:51 -0400] failed to CreateProfile: org.freedesktop.ColorManager.AlreadyExists:profile id 'Officejet_4620_fax-Gray..' already exists
W [25/Sep/2012:10:05:51 -0400] failed to CreateProfile: org.freedesktop.ColorManager.AlreadyExists:profile id 'Officejet_4620_fax-RGB..' already exists
W [25/Sep/2012:10:05:51 -0400] failed to CreateDevice: org.freedesktop.ColorManager.AlreadyExists:device id 'cups-Officejet_4620_fax' already exists
W [25/Sep/2012:10:05:51 -0400] failed to CreateProfile: org.freedesktop.ColorManager.AlreadyExists:profile id 'Officejet_4620_fax-Gray..' already exists
W [25/Sep/2012:10:05:51 -0400] failed to CreateProfile: org.fr...

[_AnK (andk)]

In addition in 'messages' file i found the following error message(s):
Sep 25 10:31:57 armat1 hpcupsfax[7813]: prnt/hpijs/hpcupsfax.cpp 678: hpcupsfax: argv[0] = Officejet_4620_fax
Sep 25 10:31:57 armat1 hpcupsfax[7813]: prnt/hpijs/hpcupsfax.cpp 678: hpcupsfax: argv[1] = 143
Sep 25 10:31:57 armat1 hpcupsfax[7813]: prnt/hpijs/hpcupsfax.cpp 678: hpcupsfax: argv[2] = akavalov
Sep 25 10:31:57 armat1 hpcupsfax[7813]: prnt/hpijs/hpcupsfax.cpp 678: hpcupsfax: argv[3] = test.txt
Sep 25 10:31:57 armat1 hpcupsfax[7813]: prnt/hpijs/hpcupsfax.cpp 678: hpcupsfax: argv[4] = 1
Sep 25 10:31:57 armat1 hpcupsfax[7813]: prnt/hpijs/hpcupsfax.cpp 678: hpcupsfax: argv[5] = finishings=3 number-up=1 job-uuid=urn:uuid:b3ea3de6-c967-3d97-518c-4a340cd73f0c job-originating-host-name=localhost time-at-creation=1348583517 time-at-processing=1348583517 AP_D_InputSlot=
Sep 25 10:31:57 armat1 hpcupsfax[7813]: prnt/hpijs/hpcupsfax.cpp 692: ERROR: Unable to open Fax output file - /var/log/hp/tmp/hplipfaxLog_F5wKmN for writing
Sep 25 10:31:58 armat1 abrt: detected unhandled Python exception in '/usr/lib/cups/backend/hpfax'
Sep 25 10:31:58 armat1 abrtd: New client connected
Sep 25 10:31:58 armat1 abrtd: Directory 'pyhook-2012-09-25-10:31:58-7814' creation detected
Sep 25 10:31:58 armat1 abrt-server[7816]: Saved Python crash dump of pid 7814 to /var/spool/abrt/pyhook-2012-09-25-10:31:58-7814
Sep 25 10:31:58 armat1 abrtd: New problem directory /var/spool/abrt/pyhook-2012-09-25-10:31:58-7814, processing
Sep 25 10:32:02 armat1 hp-sendfax: hp-sendfax[7808]: error: User exit

The line above: ERROR: Unable to open Fax output file - /var/log/hp/tmp/hplipfaxLog_F5wKmN for writing
especially looks worrisom. I do check and indeed there is no tmp directory in /var/log/hp
Should i create it myself? Any suggestions where to dig in further ?

[_AnK (andk)]

Further investigation narrowed the problem to the following 2:
1) I manually created the /var/log/hp/tmp directory (see error message above). In Selinux Permissive mode the fax started working fine. However i do not see anythin spooling into the tmp directory. Looks like it is not really needed however python code looking for it. I am not sure why?
2) Although fax is working I am getting the following AVC denial report. Seems some policy chagesrequired:

type=AVC msg=audit(1349021534.436:1191): avc: denied { write } for pid=10757 comm="hpfax" name="tmp" dev="dm-6" ino=17434475 scontext=system_u:system_r:hplip_t:s0-s0:c0.c1023 tcontext=unconfined_u:object_r:var_log_t:s0 tclass=dir
type=AVC msg=audit(1349021534.436:1191): avc: denied { add_name } for pid=10757 comm="hpfax" name="hpfax-pipe-155" scontext=system_u:system_r:hplip_t:s0-s0:c0.c1023 tcontext=unconfined_u:object_r:var_log_t:s0 tclass=dir
type=AVC msg=audit(1349021534.436:1191): avc: denied { create } for pid=10757 comm="hpfax" name="hpfax-pipe-155" scontext=system_u:system_r:hplip_t:s0-s0:c0.c1023 tcontext=system_u:object_r:var_log_t:s0 tclass=fifo_file
type=SYSCALL msg=audit(1349021534.436:1191): arch=c000003e syscall=133 success=yes exit=0 a0=282f48c a1=11b6 a2=0 a3=393dd400c4 items=0 ppid=1790 pid=10757 auid=4294967295 uid=0 gid=7 euid=0 suid=0 fsuid=0 egid=7 sgid=7 fsgid=7 tty=(none) ses=4294967295 comm="hpfax" exe="/usr/bin/python2.7" subj=system_u:system_r:hplip_t:s0-s0:c0.c1023 key=(null)
type=AVC msg=audit(1349021534.436:1192): avc: denied { write } for pid=10757 comm="hpfax" name="hpfax-pipe-155" dev="dm-6" ino=17434480 scontext=system_u:system_r:hplip_t:s0-s0:c0.c1023 tcontext=system_u:object_r:var_log_t:s0 tclass=fifo_file
type=AVC msg=audit(1349021534.436:1192): avc: denied { open } for pid=10757 comm="hpfax" name="hpfax-pipe-155" dev="dm-6" ino=17434480 scontext=system_u:system_r:hplip_t:s0-s0:c0.c1023 tcontext=system_u:object_r:var_log_t:s0 tclass=fifo_file
type=SYSCALL msg=audit(1349021534.436:1192): arch=c000003e syscall=2 success=yes exit=6 a0=2ad3340 a1=1 a2=1ff a3=676f6c2f7261762f items=0 ppid=1790 pid=10757 auid=4294967295 uid=0 gid=7 euid=0 suid=0 fsuid=0 egid=7 sgid=7 fsgid=7 tty=(none) ses=4294967295 comm="hpfax" exe="/usr/bin/python2.7" subj=system_u:system_r:hplip_t:s0-s0:c0.c1023 key=(null)
type=AVC msg=audit(1349021534.561:1193): avc: denied { remove_name } for pid=10757 comm="hpfax" name="hpfax-pipe-155" dev="dm-6" ino=17434480 scontext=system_u:system_r:hplip_t:s0-s0:c0.c1023 tcontext=unconfined_u:object_r:var_log_t:s0 tclass=dir
type=AVC msg=audit(1349021534.561:1193): avc: denied { unlink } for pid=10757 comm="hpfax" name="hpfax-pipe-155" dev="dm-6" ino=17434480 scontext=system_u:system_r:hplip_t:s0-s0:c0.c1023 tcontext=system_u:object_r:var_log_t:s0 tclass=fifo_file
type=SYSCALL msg=audit(1349021534.561:1193): arch=c000003e syscall=87 success=yes exit=0 a0=2ad3340 a1=ffffffff a2=393dfb8408 a3=676f6c2f7261762f items=0 ppid=1790 pid=10757 auid=4294967295 uid=0 gid=7 euid=0 suid=0 fsuid=0 egid=7 sgid=7 fsgid=7 tty=(none) ses=4294967295 comm="hpfax" exe="/usr/bin/python2.7" subj=system_u:system_r:hplip_t:s0-s0:c0.c1023 key=(null)

Can ...

[Jiri Popelka (jpopelka)]

The SELinux policy was changed upstream:
http://git.fedorahosted.org/cgit/selinux-policy.git/commit/?h=f16&id=03f9a2c1d2ac616e2d1c77a59171e3c50c9692cf

[Jiri Popelka (jpopelka)]

The missing /var/log/hp/tmp directory has been a Fedora hplip maintainer's (my) fault.

I think this ticket can be closed then.

[_AnK (andk)]

The update fix the problem with /var/log/hp/tmp directory. Thanks. Any idea when the policy change will be available?

[Jiri Popelka (jpopelka)]

You already asked in that selinux-policy bug (https://bugzilla.redhat.com/show_bug.cgi?id=861778), didn't you ? :-)

[Jiri Popelka (jpopelka)]

Closing, the problem has not been in hplip.

[_AnK (andk)]

OK. thanks