raw1394 problems galore

[Gene Heskett]

Stefan Richter wrote:
> Gene Heskett wrote:
>> Stefan Richter wrote:
>>> HP dv5120us is based on Turion 64. Do you run a 64bit kernel on it? Then
>>> the following bug may prevent access:
>>> http://bugzilla.kernel.org/show_bug.cgi?id=4779
> ...
>> No 64 bit kernels ever, this has always been a 32 bit install.
> 
> Hmm.
> 
> ...
>> Oct 16 11:16:31 diablo kernel: ohci1394: fw-host0: OHCI-1394 1.1 (PCI):
>> IRQ=[10]  MMIO=[c0209000-c02097ff]  Max Packet=[2048]  IR/IT contexts=[
>> 4/8]
> 
> There should be a message like "ieee1394: Host added: ID:BUS[0-00:1023]
>  GUID..." shortly later. It's logged at kern.debug level though.

I had udev set for debug earlier, lemme check the older log.

In logs reaching back 8 days while I messed with this, the string
"ieee1394: Host added: ID:BUS" never appears.

>> Then, manually loaded via 'modprobe raw1394':
>>
>> Oct 16 11:50:11 diablo kernel: ieee1394: raw1394: /dev/raw1394 device
>> initialized

But there are lots of the above, and hundreds of:
Oct 15 19:47:32 diablo udevd[417]: udev_event_run: seq 775 forked, pid 
[2645], 'add' 'ieee1394', 0 seconds old
Oct 15 19:47:32 diablo udevd[417]: udev_event_run: seq 777 forked, pid 
[2646], 'add' 'ieee1394', 0 seconds old
Oct 15 19:47:32 diablo udevd-event[2645]: wait_for_sysfs: file 
'/sys/devices/pci0000:00/0000:00:14.4/0000:03:04.2/fw-host0/08004601044684e4/bus
' appeared after 0 loops
Oct 15 19:47:32 diablo udevd-event[2645]: pass_env_to_socket: passed -1 
bytes to socket '/org/kernel/udev/monitor',
Oct 15 19:47:32 diablo udevd-event[2645]: run_program: 
'/lib/udev/udev_run_hotplugd'
Oct 15 19:47:32 diablo udevd-event[2645]: run_program: 
'/lib/udev/udev_run_hotplugd' returned with status 0
Oct 15 19:47:32 diablo udevd-event[2645]: run_program: 
'/lib/udev/udev_run_devd'
Oct 15 19:47:32 diablo udevd-event[2645]: run_program: 
'/lib/udev/udev_run_devd' returned with status 0
Oct 15 19:47:32 diablo udevd-event[2645]: pass_env_to_socket: passed 242 
bytes to socket '/org/freedesktop/hal/udev_event',
Oct 15 19:47:32 diablo udevd-event[2645]: udev_event_run: seq 775 finished
Oct 15 19:47:32 diablo udevd[417]: udev_done: seq 775, pid [2645] exit 
with 0, 0 seconds old
Oct 15 19:47:32 diablo udevd-event[2646]: wait_for_sysfs: file 
'/sys/devices/pci0000:00/0000:00:14.4/0000:03:04.2/fw-host0/623f0200cbe5407d/bus
' appeared after 0 loops
Oct 15 19:47:32 diablo udevd[417]: udev_event_run: seq 776 forked, pid 
[2649], 'add' 'ieee1394_node', 0 seconds old
Oct 15 19:47:32 diablo udevd-event[2646]: pass_env_to_socket: passed -1 
bytes to socket '/org/kernel/udev/monitor',
Oct 15 19:47:32 diablo udevd-event[2646]: run_program: 
'/lib/udev/udev_run_hotplugd'
Oct 15 19:47:32 diablo udevd-event[2649]: pass_env_to_socket: passed -1 
bytes to socket '/org/kernel/udev/monitor',
Oct 15 19:47:32 diablo udevd-event[2646]: run_program: 
'/lib/udev/udev_run_hotplugd' returned with status 0
Oct 15 19:47:32 diablo udevd-event[2649]: run_program: 
'/lib/udev/udev_run_hotplugd'
Oct 15 19:47:32 diablo udevd-event[2646]: run_program: 
'/lib/udev/udev_run_devd'
Oct 15 19:47:32 diablo udevd[417]: udev_event_run: seq 779 forked, pid 
[2651], 'add' 'ieee1394', 0 seconds old
Oct 15 19:47:32 diablo udevd-event[2651]: wait_for_sysfs: file 
'/sys/devices/pci0000:00/0000:00:14.4/0000:03:04.2/fw-host0/08004601044684e4/080
04601044684e4-0/bus' appeared after 0 loops



> OK.
> 
>> Oct 16 11:50:11 diablo kernel: audit(1161013811.874:4): avc:  denied  {
>> getattr } for  pid=2753 comm="pam_console_app" name="raw1394" dev=tmpfs
>>  ino=10625 scontext=system_u:system_r:pam_console_t:s0-s0:c0.c255
>> tcontext=system_u:object_r:device_t:s0 tclass=chr_file
>> Oct 16 11:50:11 diablo kernel: audit(1161013811.874:5): avc:  denied  {
>> setattr } for  pid=2753 comm="pam_console_app" name="raw1394" dev=tmpfs
>>  ino=10625 scontext=system_u:system_r:pam_console_t:s0-s0:c0.c255
>> tcontext=system_u:object_r:device_t:s0 tclass=chr_file
> 
> I don't get what this is about. Who denies what?
> 
It just says denied, but selinux is set permissive, so thats just a 
report of what would be denied if it was fully enabled.

>> SELinux is in permissive mode, and /dev/raw1394 has perms of:
>> [root at diablo ~]# ls -l /dev/raw1394
>> crw-rw-rw- 1 root root 171, 0 Oct 16 11:50 /dev/raw1394
>>
>> As I had given up, the camera is packed away, but I'll get it out and
>> connect it again for grins:
>>
>> And no further messages were logged when I plugged it in and turned it on.
> 
> There should be something like "ieee1394: Node added: ID:BUS[0-00:1023]
>  GUID..." and that the host changed from 0-00 to 1-00 at kern.debug level.

Never happens.

> 
>> kino-0.8 receives video from it in real time and is doing so right now,
>> and can capture it to file, and then play/edit that file, or could
>> saturday when I last tried it.  I ASSume that kino-0.9.2 could also
>> play/edit that file, but have not verified that by reinstalling 0.9.2.
> ...
>>> Did you run FC2 as 32bit environment on 32bit kernel?
>> Yes, and kino-0.7.5 died with kernel changes in the ieee1394 code
>> someplace at about 2.6.9 IIRC.
> ...
>>>> before someone just had to rewrite the 1394 stuff again?
>>> The 1394 kernel drivers are not being rewritten.
>> I was told it was a total rewrite of bad code when I complained about a
>> year ago.  My reply at the time was that it worked, and I don't often
>> fix things that are working.  I'm getting lazy in my dotage I guess.
> 
> I don't remember what was changed at that time. Maybe that was the
> addition of the new isochronous interface that I mentioned. The old one
> was (is?) still there but maybe there were interactions... However this
> is not related to the inability to issue AV/C commands, which are issued
> asynchronously. I think though that your kino 0.8.x package is
> configured to work isochronously via video1394(?)

Its showing raw1394, the other choice is dvgrab, which doesn't...

  but asynchronously via
> raw1394, and the kino 0.9.x package to do both via raw1394. But don't
> take my word on it, I keep mistaking one interface for another. I never
> used video cameras on FireWire myself.
> 
>> As for 1394commander or gscanbus, I have not managed to find rpms of
>> those in any of the repos yumex or SPM shows me.  They apparently are
>> not part of the FC5 tree.  I'd love to see what those 2 might have to
>> say about the system.  The only thing I do have is dvcont, which reports
>> this:
>>
>> [root at diablo ~]# dvcont dev 0 play
>> Could not find any AV/C devices on the 1394 bus.
>>
>> The camera is still plugged in and powered up.
> 
> Anything under /sys/bus/ieee1394/devices?
[root at diablo ~]# ls -R /sys/bus/ieee1394/devices
/sys/bus/ieee1394/devices:
08004601044684e4  08004601044684e4-0  623f0200cbe5407d 
623f0200cbe5407d-0  fw-host0

and:
[root at diablo ~]# ls -l /sys/bus/ieee1394/devices/fw-host0
lrwxrwxrwx 1 root root 0 Oct 16 11:16 /sys/bus/ieee1394/devices/fw-host0 
-> ../../../devices/pci0000:00/0000:00:14.4/0000:03:04.2/fw-host0
[root at diablo ~]#
> 
> It might be not too difficult to compile 1394commander since it doesn't
> have many library dependencies; just libraw1394 (probably as -devel
> package) and optionally readline. Gscanbus would show a bit more about
> attached devices without resorting to magic commands but it is a bit
> harder to compile, as a GUI program.

I'll put in the devel stuff and give it a shot.  And let the lists know.

Thanks, Stefan

-- 
Cheers, Gene