Skip site navigation (1)Skip section navigation (2)
Date:      Sun, 7 Feb 2010 02:06:49 GMT
From:      RandomUser <rannumgen@globaleyes.net>
To:        freebsd-gnats-submit@FreeBSD.org
Subject:   kern/143623: firewire fails to attach DV camera and download DV stream
Message-ID:  <201002070206.o1726nju082477@www.freebsd.org>
Resent-Message-ID: <201002070210.o172A15j038260@freefall.freebsd.org>

next in thread | raw e-mail | index | archive | help

>Number:         143623
>Category:       kern
>Synopsis:       firewire fails to attach DV camera and download DV stream
>Confidential:   no
>Severity:       non-critical
>Priority:       medium
>Responsible:    freebsd-bugs
>State:          open
>Quarter:        
>Keywords:       
>Date-Required:
>Class:          sw-bug
>Submitter-Id:   current-users
>Arrival-Date:   Sun Feb 07 02:10:01 UTC 2010
>Closed-Date:
>Last-Modified:
>Originator:     RandomUser
>Release:        7.2-STABLE
>Organization:
>Environment:
7.2-STABLE FreeBSD 7.2-STABLE #7: Sun Jan 17 11:54:45 CST 2010


>Description:
Connect DV camera to firewire -> apparent fireware problems occur.
Attempt to download DV stream -> error message about "Bad file descriptor"

===== firewire dmesg entries =====
fwohci0: <1394 Open Host Controller Interface> mem 0xfc004000-0xfc0047ff irq 23 at device 9.4 on pci2
fwohci0: [FILTER]
fwohci0: OHCI version 1.10 (ROM=1)
fwohci0: No. of Isochronous channels is 4.
fwohci0: EUI64 00:90:e6:39:00:00:01:a4
fwohci0: Phy 1394a available S400, 2 ports.
fwohci0: Link S400, max_rec 2048 bytes.
firewire0: <IEEE1394(FireWire) bus> on fwohci0
fwe0: <Ethernet over FireWire> on firewire0
if_fwe0: Fake Ethernet address: 02:90:e6:00:01:a4
fwe0: Ethernet address: 02:90:e6:00:01:a4
fwip0: <IP over FireWire> on firewire0
fwip0: Firewire address: 00:90:e6:39:00:00:01:a4 @ 0xfffe00000000, S400, maxrec 2048
sbp0: <SBP-2/SCSI over FireWire> on firewire0
dcons_crom0: <dcons configuration ROM> on firewire0
dcons_crom0: bus_addr 0x1f88000
wohci0: Initiate bus reset
fwohci0: BUS reset
fwohci0: node_id=0xc800ffc0, gen=1, CYCLEMASTER mode
firewire0: 1 nodes, maxhop <= 0, cable IRM = 0 (me)
firewire0: bus manager 0 (me)

===== attach DV camera via firewire cable =====
fwohci0: Initiate bus reset
fwohci0: BUS reset
fwohci0: node_id=0xc800ffc0, gen=2, CYCLEMASTER mode
firewire0: 1 nodes, maxhop <= 0, cable IRM = 0 (me)
firewire0: bus manager 0 (me)
fwohci0: BUS reset
fwohci0: node_id=0x8800ffc0, gen=3, non CYCLEMASTER mode
firewire0: 2 nodes, maxhop <= 1, cable IRM = 1
fwohci0: too many cycle lost, no cycle master presents?
fwohci0: txd err= 3 miss Ack err
fwohci0: txd err= 3 miss Ack err
fwohci0: txd err= 3 miss Ack err
fwohci0: BUS reset
fwohci0: node_id=0x8800ffc0, gen=4, non CYCLEMASTER mode
firewire0: 2 nodes, maxhop <= 1, cable IRM = 1
firewire0: New S400 device ID:0000f000ffffffff
fwohci0: Initiate bus reset
fwohci0: BUS reset
fwohci0: node_id=0xc800ffc1, gen=5, CYCLEMASTER mode
firewire0: 2 nodes, maxhop <= 1, cable IRM = 1 (me)
firewire0: bus manager 1 (me)
fwohci0: BUS reset
fwohci0: node_id=0x8800ffc0, gen=6, non CYCLEMASTER mode
firewire0: 2 nodes, maxhop <= 1, cable IRM = 1
fwohci0: too many cycle lost, no cycle master presents?
fwohci0: BUS reset
fwohci0: node_id=0xc800ffc0, gen=7, CYCLEMASTER mode
firewire0: 1 nodes, maxhop <= 0, cable IRM = 0 (me)
firewire0: bus manager 0 (me)

==== attempt to use fwcontrol to download DV stream =====
fwcontrol -R recording.dv
fwcontrol: detect_recv_fn: ioctl FW_SSTBUF: Bad file descriptor

==== check firewire configuration ====
2 devices (info_len=2)
node           EUI64          status    hostname
   0  00-90-e6-39-00-00-01-a4      0    
   1  00-00-f0-00-ff-ff-ff-ff      1

==== ktrace dump of fwcontrol -R ====
  1796 ktrace   CALL  execve(0xbfbfe5a8,0xbfbfeb34,0xbfbfeb44)
  1796 ktrace   NAMI  "/bin/fwcontrol"
  1796 ktrace   RET   execve -1 errno 2 No such file or directory
  1796 ktrace   CALL  execve(0xbfbfe5a8,0xbfbfeb34,0xbfbfeb44)
  1796 ktrace   NAMI  "/sbin/fwcontrol"
  1796 ktrace   RET   execve -1 errno 2 No such file or directory
  1796 ktrace   CALL  execve(0xbfbfe5a8,0xbfbfeb34,0xbfbfeb44)
  1796 ktrace   NAMI  "/usr/sbin/fwcontrol"
  1796 ktrace   NAMI  "/libexec/ld-elf.so.1"
  1796 fwcontrol RET   execve 0
  1796 fwcontrol CALL  __sysctl(0xbfbfe464,0x2,0xbfbfe46c,0xbfbfe470,0,0)
  1796 fwcontrol SCTL  "kern.osreldate"
  1796 fwcontrol RET   __sysctl 0
  1796 fwcontrol CALL  mmap(0,0x130,PROT_READ|PROT_WRITE,MAP_ANON,0xffffffff,0,0)
  1796 fwcontrol RET   mmap 671592448/0x2807b000
  1796 fwcontrol CALL  munmap(0x2807b000,0x130)
  1796 fwcontrol RET   munmap 0
  1796 fwcontrol CALL  __sysctl(0xbfbfe4c8,0x2,0x28077c7c,0xbfbfe4d0,0,0)
  1796 fwcontrol SCTL  "hw.pagesize"
  1796 fwcontrol RET   __sysctl 0
  1796 fwcontrol CALL  mmap(0,0x8000,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,0xffffffff,0,0)
  1796 fwcontrol RET   mmap 671592448/0x2807b000
  1796 fwcontrol CALL  issetugid
  1796 fwcontrol RET   issetugid 0
  1796 fwcontrol CALL  open(0x28072532,O_RDONLY,<unused>0x1b6)
  1796 fwcontrol NAMI  "/etc/libmap.conf"
  1796 fwcontrol RET   open -1 errno 2 No such file or directory
  1796 fwcontrol CALL  open(0x28071783,O_RDONLY,<unused>0)
  1796 fwcontrol NAMI  "/var/run/ld-elf.so.hints"
  1796 fwcontrol RET   open 3
  1796 fwcontrol CALL  read(0x3,0xbfbfe21c,0x80)
  1796 fwcontrol GIO   fd 3 read 128 bytes
       0x0000 4568 6e74 0100 0000 8000 0000 f800 0000 0000  |Ehnt..............|
       0x0012 0000 f700 0000 0000 0000 0000 0000 0000 0000  |..................|
       0x0024 0000 0000 0000 0000 0000 0000 0000 0000 0000  |..................|
       0x0036 0000 0000 0000 0000 0000 0000 0000 0000 0000  |..................|
       0x0048 0000 0000 0000 0000 0000 0000 0000 0000 0000  |..................|
       0x005a 0000 0000 0000 0000 0000 0000 0000 0000 0000  |..................|
       0x006c 0000 0000 0000 0000 0000 0000 0000 0000 0000  |..................|
       0x007e 0000                                          |..|

  1796 fwcontrol RET   read 128/0x80
  1796 fwcontrol CALL  lseek(0x3,0x80,SEEK_SET,0)
  1796 fwcontrol RET   lseek 128/0x80
  1796 fwcontrol CALL  read(0x3,0x2807f000,0xf8)
  1796 fwcontrol GIO   fd 3 read 248 bytes
       "/lib:/usr/lib:/usr/lib/compat:/usr/local/lib:/usr/local/lib/compat/pkg:/usr\
	/local/lib/compat:/usr/local/lib/gegl-0.0:/usr/local/lib/graphviz:/usr/loca\
	l/lib/mysql:/usr/local/lib/nss:/usr/local/lib/portaudio2:/usr/local/lib/pth\
	:/usr/local/lib/sublib\0"
  1796 fwcontrol RET   read 248/0xf8
  1796 fwcontrol CALL  close(0x3)
  1796 fwcontrol RET   close 0
  1796 fwcontrol CALL  access(0x28080000,F_OK)
  1796 fwcontrol NAMI  "/lib/libc.so.7"
  1796 fwcontrol RET   access 0
  1796 fwcontrol CALL  open(0x2807c020,O_RDONLY,<unused>0)
  1796 fwcontrol NAMI  "/lib/libc.so.7"
  1796 fwcontrol RET   open 3
  1796 fwcontrol CALL  fstat(0x3,0xbfbfe4bc)
  1796 fwcontrol STRU  struct stat {dev=113, ino=24164355, mode=-r--r--r-- , nlink=1, uid=0, gid=0, rdev=96538368, atime=1265494611, stime=1263730855, ctime=1263730855, birthtime=1263730855, size=1032700, blksize=4096, blocks=2080, flags=0x20000 }
  1796 fwcontrol RET   fstat 0
  1796 fwcontrol CALL  read(0x3,0x28076bc0,0x1000)
  1796 fwcontrol GIO   fd 3 read 4096 bytes
       0x0000 7f45 4c46 0101 0109 0000 0000 0000 0000 0300  |.ELF..............|
       .
       .
       .
       0x0ff6 0000 0000 0000 e107 0000                      |..........|

  1796 fwcontrol RET   read 4096/0x1000
  1796 fwcontrol CALL  mmap(0,0xff000,PROT_NONE,MAP_PRIVATE|MAP_ANON|MAP_NOCORE,0xffffffff,0,0)
  1796 fwcontrol RET   mmap 671625216/0x28083000
  1796 fwcontrol CALL  mmap(0x28083000,0xe3000,PROT_READ|PROT_EXEC,MAP_PRIVATE|MAP_FIXED|MAP_NOCORE,0x3,0,0)
  1796 fwcontrol RET   mmap 671625216/0x28083000
  1796 fwcontrol CALL  mmap(0x28166000,0x6000,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_FIXED,0x3,0xe3000,0)
  1796 fwcontrol RET   mmap 672555008/0x28166000
  1796 fwcontrol CALL  mprotect(0x2816c000,0x16000,PROT_READ|PROT_WRITE)
  1796 fwcontrol RET   mprotect 0
  1796 fwcontrol CALL  close(0x3)
  1796 fwcontrol RET   close 0
  1796 fwcontrol CALL  sysarch(0xa,0xbfbfe530)
  1796 fwcontrol RET   sysarch 0
  1796 fwcontrol CALL  mmap(0,0x170,PROT_READ|PROT_WRITE,MAP_ANON,0xffffffff,0,0)
  1796 fwcontrol RET   mmap 672669696/0x28182000
  1796 fwcontrol CALL  munmap(0x28182000,0x170)
  1796 fwcontrol RET   munmap 0
  1796 fwcontrol CALL  mmap(0,0x52f0,PROT_READ|PROT_WRITE,MAP_ANON,0xffffffff,0,0)
  1796 fwcontrol RET   mmap 672669696/0x28182000
  1796 fwcontrol CALL  munmap(0x28182000,0x52f0)
  1796 fwcontrol RET   munmap 0
  1796 fwcontrol CALL  sigprocmask(SIG_BLOCK,0x28076b00,0xbfbfe50c)
  1796 fwcontrol RET   sigprocmask 0
  1796 fwcontrol CALL  sigprocmask(SIG_SETMASK,0x28076b10,0)
  1796 fwcontrol RET   sigprocmask 0
  1796 fwcontrol CALL  __sysctl(0xbfbfe4e4,0x2,0x2816cb40,0xbfbfe4ec,0,0)
  1796 fwcontrol SCTL  "kern.arandom"
  1796 fwcontrol RET   __sysctl 0
  1796 fwcontrol CALL  sigprocmask(SIG_BLOCK,0x28076b00,0xbfbfe4dc)
  1796 fwcontrol RET   sigprocmask 0
  1796 fwcontrol CALL  sigprocmask(SIG_SETMASK,0x28076b10,0)
  1796 fwcontrol RET   sigprocmask 0
  1796 fwcontrol CALL  __sysctl(0xbfbfe0c8,0x2,0x28170820,0xbfbfe0d0,0,0)
  1796 fwcontrol SCTL  "hw.ncpu"
  1796 fwcontrol RET   __sysctl 0
  1796 fwcontrol CALL  __sysctl(0xbfbfdbd8,0x2,0x2817f13c,0xbfbfdbe0,0,0)
  1796 fwcontrol SCTL  "hw.pagesize"
  1796 fwcontrol RET   __sysctl 0
  1796 fwcontrol CALL  __sysctl(0xbfbfdc28,0x2,0xbfbfdc34,0xbfbfdc38,0,0)
  1796 fwcontrol SCTL  "p1003_1b.pagesize"
  1796 fwcontrol RET   __sysctl 0
  1796 fwcontrol CALL  readlink(0x2815db67,0xbfbfdcbb,0x400)
  1796 fwcontrol NAMI  "/etc/malloc.conf"
  1796 fwcontrol RET   readlink -1 errno 2 No such file or directory
  1796 fwcontrol CALL  issetugid
  1796 fwcontrol RET   issetugid 0
  1796 fwcontrol CALL  break(0x8100000)
  1796 fwcontrol RET   break 0
  1796 fwcontrol CALL  __sysctl(0xbfbfdf64,0x2,0xbfbfdf6c,0xbfbfdf70,0,0)
  1796 fwcontrol SCTL  "kern.osreldate"
  1796 fwcontrol RET   __sysctl 0
  1796 fwcontrol CALL  mmap(0,0x100000,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,0xffffffff,0,0)
  1796 fwcontrol RET   mmap 672669696/0x28182000
  1796 fwcontrol CALL  mmap(0x28282000,0x7e000,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,0xffffffff,0,0)
  1796 fwcontrol RET   mmap 673718272/0x28282000
  1796 fwcontrol CALL  munmap(0x28182000,0x7e000)
  1796 fwcontrol RET   munmap 0
  1796 fwcontrol CALL  ioctl(0xffffffff,FW_SSTBUF,0xbfbfea74)
  1796 fwcontrol RET   ioctl -1 errno 9 Bad file descriptor
  1796 fwcontrol CALL  write(0x2,0xbfbfd9e0,0xb)
  1796 fwcontrol GIO   fd 2 wrote 11 bytes
       "fwcontrol: "
  1796 fwcontrol RET   write 11/0xb
  1796 fwcontrol CALL  write(0x2,0xbfbfda10,0x1f)
  1796 fwcontrol GIO   fd 2 wrote 31 bytes
       "detect_recv_fn: ioctl FW_SSTBUF"

==== listing of firewire special files ====
ls -l /dev/fw*
lrwxr-xr-x  1 root  wheel            5 Feb  6 19:33 /dev/fw0 -> fw0.0
crw-rw-rw-  1 root  operator    0,  49 Feb  6 19:33 /dev/fw0.0
lrwxr-xr-x  1 root  wheel            8 Feb  6 19:33 /dev/fwmem0 -> fwmem0.0
crw-rw----  1 root  operator    0,  50 Feb  6 19:33 /dev/fwmem0.0

==== sysctl -A|grep fw =====
debug.fwmem_debug: 0
debug.if_fwe_debug: 0
debug.if_fwip_debug: 0
hw.firewire.fwmem.speed: 2
hw.firewire.fwmem.eui64_lo: 0
hw.firewire.fwmem.eui64_hi: 0
hw.firewire.fwe.rx_queue_len: 128
hw.firewire.fwe.tx_speed: 2
hw.firewire.fwe.stream_ch: 1
hw.firewire.fwip.rx_queue_len: 128
hw.nvidia.agp.card.fw: supported
hw.nvidia.agp.status.fw: enabled
dev.fwohci.0.%desc: 1394 Open Host Controller Interface
dev.fwohci.0.%driver: fwohci
dev.fwohci.0.%location: slot=9 function=4
dev.fwohci.0.%pnpinfo: vendor=0x10b9 device=0x5253 subvendor=0x17fc subdevice=0x5253 class=0x0c0010
dev.fwohci.0.%parent: pci2
dev.firewire.0.%parent: fwohci0
dev.fwe.0.%desc: Ethernet over FireWire
dev.fwe.0.%driver: fwe
dev.fwe.0.%parent: firewire0
dev.fwip.0.%desc: IP over FireWire
dev.fwip.0.%driver: fwip
dev.fwip.0.%parent: firewire0

==== sysctl -A|grep firewire =====
debug.firewire_debug: 0
hw.firewire.hold_count: 3
hw.firewire.try_bmr: 1
hw.firewire.fwmem.speed: 2
hw.firewire.fwmem.eui64_lo: 0
hw.firewire.fwmem.eui64_hi: 0
hw.firewire.phydma_enable: 1
hw.firewire.nocyclemaster: 0
hw.firewire.fwe.rx_queue_len: 128
hw.firewire.fwe.tx_speed: 2
hw.firewire.fwe.stream_ch: 1
hw.firewire.fwip.rx_queue_len: 128
hw.firewire.sbp.tags: 0
hw.firewire.sbp.use_doorbell: 0
hw.firewire.sbp.scan_delay: 500
hw.firewire.sbp.login_delay: 1000
hw.firewire.sbp.exclusive_login: 1
hw.firewire.sbp.max_speed: 2
hw.firewire.sbp.auto_login: 1
dev.firewire.0.%desc: IEEE1394(FireWire) bus
dev.firewire.0.%driver: firewire
dev.firewire.0.%parent: fwohci0
dev.fwe.0.%parent: firewire0
dev.fwip.0.%parent: firewire0
dev.sbp.0.%parent: firewire0
dev.dcons_crom.0.%parent: firewire0

>How-To-Repeat:
Detach, reattach DV camera, and attempt to download DV stream.
>Fix:


>Release-Note:
>Audit-Trail:
>Unformatted:



Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?201002070206.o1726nju082477>