Media autochanger driver changed behavior.

Media autochanger driver changed behavior.

[Jesper Krogh]

Hi.

Upgrading the OS from an quite old kernel to a newer (2.6.24) changed
the behavior of the "ch" driver. Now it does a inventory to the changer
on load. This command makes the barcode-reader scan the entire library
at driver load time.

This process takes around 7.5 minutes in my installations.

[  211.903066] ch0: type #1 (mt): 0x0+1 [medium transport]
[  211.903074] ch0: type #2 (st): 0x100+94 [storage]
[  211.903076] ch0: type #3 (ie): 0x500+6 [import/export]
[  211.903078] ch0: type #4 (dt): 0x80+2 [data transfer]
[  211.924873] ch0: dt 0x80: ID 2, LUN 0, name: HP       Ultrium 3-SCSI 
   G36Z
[  211.946835] ch0: dt 0x81: ID 2, LUN 0, name: HP       Ultrium 3-SCSI 
   G36Z
[  211.946844] ch0: INITIALIZE ELEMENT STATUS, may take some time ...
[  220.610904] eth0: no IPv6 routers present
[  270.903214] st: Version 20070203, fixed bufsize 32768, s/g segs 256
[  270.903243] Driver 'st' needs updating - please use bus_type methods
[  519.926380] ch0: ... finished
[  519.926422] ch 5:0:0:0: Attached scsi changer ch0
[  519.924693] st 5:0:2:0: Attached scsi tape st0
[  519.924702] st 5:0:2:0: st0: try direct i/o: yes (alignment 512 B)
[  519.924818] st 6:0:2:0: Attached scsi tape st1
[  519.924821] st 6:0:2:0: st1: try direct i/o: yes (alignment 512 B)
[  519.942415] st1: Block limits 1 - 16777215 bytes.
[  520.368971] st0: Block limits 1 - 16777215 bytes.


Have I misconfigured something or has the default behavior of this
driver changed? (can I get the old one back)

Earlier the driver-load just took less than a few seconds for both st 
and ch.

Jesper
-- 
Jesper

Re: Media autochanger driver changed behavior.

[James Bottomley]

On Wed, 2008-07-09 at 22:51 +0200, Jesper Krogh wrote:
> Hi.
> 
> Upgrading the OS from an quite old kernel to a newer (2.6.24) changed
> the behavior of the "ch" driver. Now it does a inventory to the changer
> on load. This command makes the barcode-reader scan the entire library
> at driver load time.

Do I take it from this that your old kernel simply didn't auto load the
ch driver?  or that something has changed in the way the driver now
works?

I'm afraid ch.c is a bit of an orphan so tracking down the issue,
particularly if it's buried way back might take a while (on the brighter
side, there haven't been so many commits to the driver, so they can be
tested one by one).

James

Re: Media autochanger driver changed behavior.

[Jesper Krogh]

James Bottomley wrote:
> On Wed, 2008-07-09 at 22:51 +0200, Jesper Krogh wrote:
>> Hi.
>>
>> Upgrading the OS from an quite old kernel to a newer (2.6.24) changed
>> the behavior of the "ch" driver. Now it does a inventory to the changer
>> on load. This command makes the barcode-reader scan the entire library
>> at driver load time.
> 
> Do I take it from this that your old kernel simply didn't auto load the
> ch driver?  or that something has changed in the way the driver now
> works?

It sure did load the driver and it worked just fine. It just didnt make 
the library unit force scan the barcodes. (the library do that on bootup 
by itself, but it can be forced with mtx over the changer device).

mtx -f /dev/changer inventory => Force scans barcodes
mtx -f /dev/changer status => Reads out the barcodes labels and slots
from the changer device without forcing the library to scan.
(note I dont know if it is library specific).

> I'm afraid ch.c is a bit of an orphan so tracking down the issue,
> particularly if it's buried way back might take a while (on the brighter
> side, there haven't been so many commits to the driver, so they can be
> tested one by one).



-- 
Jesper

Re: Media autochanger driver changed behavior.

[James Bottomley]

On Wed, 2008-07-09 at 23:56 +0200, Jesper Krogh wrote:
> James Bottomley wrote:
> > On Wed, 2008-07-09 at 22:51 +0200, Jesper Krogh wrote:
> >> Hi.
> >>
> >> Upgrading the OS from an quite old kernel to a newer (2.6.24) changed
> >> the behavior of the "ch" driver. Now it does a inventory to the changer
> >> on load. This command makes the barcode-reader scan the entire library
> >> at driver load time.
> > 
> > Do I take it from this that your old kernel simply didn't auto load the
> > ch driver?  or that something has changed in the way the driver now
> > works?
> 
> It sure did load the driver and it worked just fine. It just didnt make 
> the library unit force scan the barcodes. (the library do that on bootup 
> by itself, but it can be forced with mtx over the changer device).
> 
> mtx -f /dev/changer inventory => Force scans barcodes
> mtx -f /dev/changer status => Reads out the barcodes labels and slots
> from the changer device without forcing the library to scan.
> (note I dont know if it is library specific).

OK, so it's not the autoloading code which I thought it might be.

Which is the latest version of the kernel that works? ... that will at
least give me the set of changes to look at.

James


> > I'm afraid ch.c is a bit of an orphan so tracking down the issue,
> > particularly if it's buried way back might take a while (on the brighter
> > side, there haven't been so many commits to the driver, so they can be
> > tested one by one).
> 
> 
> 

Re: Media autochanger driver changed behavior.

[Jesper Krogh]

James Bottomley wrote:
> On Wed, 2008-07-09 at 23:56 +0200, Jesper Krogh wrote:
>> James Bottomley wrote:
>>> On Wed, 2008-07-09 at 22:51 +0200, Jesper Krogh wrote:
>>>> Hi.
>>>>
>>>> Upgrading the OS from an quite old kernel to a newer (2.6.24) changed
>>>> the behavior of the "ch" driver. Now it does a inventory to the changer
>>>> on load. This command makes the barcode-reader scan the entire library
>>>> at driver load time.
>>> Do I take it from this that your old kernel simply didn't auto load the
>>> ch driver?  or that something has changed in the way the driver now
>>> works?
>> It sure did load the driver and it worked just fine. It just didnt make 
>> the library unit force scan the barcodes. (the library do that on bootup 
>> by itself, but it can be forced with mtx over the changer device).
>>
>> mtx -f /dev/changer inventory => Force scans barcodes
>> mtx -f /dev/changer status => Reads out the barcodes labels and slots
>> from the changer device without forcing the library to scan.
>> (note I dont know if it is library specific).
> 
> OK, so it's not the autoloading code which I thought it might be.
> 
> Which is the latest version of the kernel that works? ... that will at
> least give me the set of changes to look at.

I cant give you that, since I havent testet all, but I'm quite sure 
2.6.20 worked,
completely sure that 2.6.15 was Ok.

I know this is a large timespan, sorry.

-- 
Jesper

Re: Media autochanger driver changed behavior.

[James Bottomley]

On Thu, 2008-07-10 at 07:59 +0200, Jesper Krogh wrote:
> James Bottomley wrote:
> > On Wed, 2008-07-09 at 23:56 +0200, Jesper Krogh wrote:
> >> James Bottomley wrote:
> >>> On Wed, 2008-07-09 at 22:51 +0200, Jesper Krogh wrote:
> >>>> Hi.
> >>>>
> >>>> Upgrading the OS from an quite old kernel to a newer (2.6.24) changed
> >>>> the behavior of the "ch" driver. Now it does a inventory to the changer
> >>>> on load. This command makes the barcode-reader scan the entire library
> >>>> at driver load time.
> >>> Do I take it from this that your old kernel simply didn't auto load the
> >>> ch driver?  or that something has changed in the way the driver now
> >>> works?
> >> It sure did load the driver and it worked just fine. It just didnt make 
> >> the library unit force scan the barcodes. (the library do that on bootup 
> >> by itself, but it can be forced with mtx over the changer device).
> >>
> >> mtx -f /dev/changer inventory => Force scans barcodes
> >> mtx -f /dev/changer status => Reads out the barcodes labels and slots
> >> from the changer device without forcing the library to scan.
> >> (note I dont know if it is library specific).
> > 
> > OK, so it's not the autoloading code which I thought it might be.
> > 
> > Which is the latest version of the kernel that works? ... that will at
> > least give me the set of changes to look at.
> 
> I cant give you that, since I havent testet all, but I'm quite sure 
> 2.6.20 worked,
> completely sure that 2.6.15 was Ok.
> 
> I know this is a large timespan, sorry.

It would be enormously helpful if you could boot 2.6.20 and confirm.
There are 3 changes to ch between 2.6.20 and 2.6.24.  There are 8
between 2.6.15 and 2.6.24.

Thanks,

James

Re: Media autochanger driver changed behavior.

[Jesper Krogh]

James Bottomley wrote:
> On Thu, 2008-07-10 at 07:59 +0200, Jesper Krogh wrote:
>> James Bottomley wrote:
>>> On Wed, 2008-07-09 at 23:56 +0200, Jesper Krogh wrote:
>>>> James Bottomley wrote:
>>>>> On Wed, 2008-07-09 at 22:51 +0200, Jesper Krogh wrote:
>>>>>> Hi.
>>>>>>
>>>>>> Upgrading the OS from an quite old kernel to a newer (2.6.24) changed
>>>>>> the behavior of the "ch" driver. Now it does a inventory to the changer
>>>>>> on load. This command makes the barcode-reader scan the entire library
>>>>>> at driver load time.
>>>>> Do I take it from this that your old kernel simply didn't auto load the
>>>>> ch driver?  or that something has changed in the way the driver now
>>>>> works?
>>>> It sure did load the driver and it worked just fine. It just didnt make 
>>>> the library unit force scan the barcodes. (the library do that on bootup 
>>>> by itself, but it can be forced with mtx over the changer device).
>>>>
>>>> mtx -f /dev/changer inventory => Force scans barcodes
>>>> mtx -f /dev/changer status => Reads out the barcodes labels and slots
>>>> from the changer device without forcing the library to scan.
>>>> (note I dont know if it is library specific).
>>> OK, so it's not the autoloading code which I thought it might be.
>>>
>>> Which is the latest version of the kernel that works? ... that will at
>>> least give me the set of changes to look at.
>> I cant give you that, since I havent testet all, but I'm quite sure 
>> 2.6.20 worked,
>> completely sure that 2.6.15 was Ok.
>>
>> I know this is a large timespan, sorry.
> 
> It would be enormously helpful if you could boot 2.6.20 and confirm.
> There are 3 changes to ch between 2.6.20 and 2.6.24.  There are 8
> between 2.6.15 and 2.6.24.

I'll get it done and report but, but we're a bit behind on the 
backup-schedules. So when the system has catched up I'll do some testing.

-- 
Jesper

Re: Media autochanger driver changed behavior.

[Jesper Krogh]

Jesper Krogh wrote:
> James Bottomley wrote:
>> On Thu, 2008-07-10 at 07:59 +0200, Jesper Krogh wrote:
>>> James Bottomley wrote:
>>>> On Wed, 2008-07-09 at 23:56 +0200, Jesper Krogh wrote:
>>>>> James Bottomley wrote:
>>>>>> On Wed, 2008-07-09 at 22:51 +0200, Jesper Krogh wrote:
>>>>>>> Hi.
>>>>>>>
>>>>>>> Upgrading the OS from an quite old kernel to a newer (2.6.24) 
>>>>>>> changed
>>>>>>> the behavior of the "ch" driver. Now it does a inventory to the 
>>>>>>> changer
>>>>>>> on load. This command makes the barcode-reader scan the entire 
>>>>>>> library
>>>>>>> at driver load time.
>>>>>> Do I take it from this that your old kernel simply didn't auto 
>>>>>> load the
>>>>>> ch driver?  or that something has changed in the way the driver now
>>>>>> works?
>>>>> It sure did load the driver and it worked just fine. It just didnt 
>>>>> make the library unit force scan the barcodes. (the library do that 
>>>>> on bootup by itself, but it can be forced with mtx over the changer 
>>>>> device).
>>>>>
>>>>> mtx -f /dev/changer inventory => Force scans barcodes
>>>>> mtx -f /dev/changer status => Reads out the barcodes labels and slots
>>>>> from the changer device without forcing the library to scan.
>>>>> (note I dont know if it is library specific).
>>>> OK, so it's not the autoloading code which I thought it might be.
>>>>
>>>> Which is the latest version of the kernel that works? ... that will at
>>>> least give me the set of changes to look at.
>>> I cant give you that, since I havent testet all, but I'm quite sure 
>>> 2.6.20 worked,
>>> completely sure that 2.6.15 was Ok.
>>>
>>> I know this is a large timespan, sorry.
>>
>> It would be enormously helpful if you could boot 2.6.20 and confirm.
>> There are 3 changes to ch between 2.6.20 and 2.6.24.  There are 8
>> between 2.6.15 and 2.6.24.
> 
> I'll get it done and report but, but we're a bit behind on the 
> backup-schedules. So when the system has catched up I'll do some testing.
> 

It troubled med to get back to "that old" a kernel. I have a fresh dmesg 
  here from a 2.6.26.1 kernel. New stuff is that I get the 120 seconds 
message.

[   28.475059] ch0: type #1 (mt): 0x0+1 [medium transport]
[   28.475111] ch0: type #2 (st): 0x100+100 [storage]
[   28.475157] ch0: type #3 (ie): 0x500+0 [import/export]
[   28.475203] ch0: type #4 (dt): 0x80+1 [data transfer]
[   28.496792] ch0: dt 0x80: ID 3, LUN 0, name: HP       Ultrium 3-SCSI 
   G39Z
[   28.496812] ch0: INITIALIZE ELEMENT STATUS, may take some time ...
[   29.561479] e1000: eth0: e1000_watchdog: NIC Link is Up 1000 Mbps 
Full Duplex, Flow Control: RX
[   29.965913] pci_hotplug: PCI Hot Plug PCI Core version: 0.5
[   30.009427] shpchp: HPC vendor_id 1022 device_id 7458 ss_vid 0 ss_did 0
[   30.009427] shpchp: shpc_init: cannot reserve MMIO region
[   30.009427] shpchp: HPC vendor_id 1022 device_id 7458 ss_vid 0 ss_did 0
[   30.009427] shpchp: shpc_init: cannot reserve MMIO region
[   30.013471] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4
[   30.208019] i2c-adapter i2c-0: nForce2 SMBus adapter at 0x6000
[   30.208096] i2c-adapter i2c-1: nForce2 SMBus adapter at 0x6040
[   30.354692] input: Power Button (FF) as /class/input/input4
[   30.412413] input: PC Speaker as /class/input/input5
[   30.431263] ACPI: Power Button (FF) [PWRF]
[   30.431416] input: Power Button (CM) as /class/input/input6
[   30.497468] ACPI: Power Button (CM) [PWRB]
[   30.613129] NET: Registered protocol family 10
[   30.613706] lo: Disabled Privacy Extensions
[   31.140157] warning: `ntpd' uses 32-bit capabilities (legacy support 
in use)
[   41.121412] eth0: no IPv6 routers present
[  157.841224] INFO: task modprobe:3924 blocked for more than 120 seconds.
[  157.841280] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" 
disables this message.
[  157.841629] modprobe      D ffff810001044280     0  3924      1
[  157.842550]  ffff8102fe4a7918 0000000000000086 0000000000000000 
ffff8102fe4d2280
[  157.842711]  ffffffff8061e280 ffffffff8061e280 ffffffff8061a4e0 
ffffffff8061e280
[  157.842869]  ffff8102fb1b0dc8 ffff8102fe4a78e4 ffff8102fe4a78d8 
ffff8102fe4a78c8
[  157.842990] Call Trace:
[  157.843089]  [<ffffffffa01084eb>] :mptscsih:mptscsih_qcmd+0x22b/0x5c0
[  157.843146]  [<ffffffff8044d175>] schedule_timeout+0x95/0xd0
[  157.843198]  [<ffffffff8031fd8b>] elv_next_request+0x5b/0x250
[  157.843271]  [<ffffffffa006cf2f>] :scsi_mod:scsi_dispatch_cmd+0x12f/0x2e0
[  157.843323]  [<ffffffff8044cec5>] wait_for_common+0xa5/0x160
[  157.843374]  [<ffffffff8022a9b0>] default_wake_function+0x0/0x10
[  157.843428]  [<ffffffff8032553f>] blk_execute_rq+0x9f/0x110
[  157.843477]  [<ffffffff803227b1>] get_request_wait+0x21/0x180
[  157.843539]  [<ffffffffa007367c>] :scsi_mod:scsi_execute+0xec/0x150
[  157.843597]  [<ffffffffa0073771>] :scsi_mod:scsi_execute_req+0x91/0x100
[  157.843653]  [<ffffffffa01ad12b>] :ch:ch_do_scsi+0x7b/0x1b0
[  157.843705]  [<ffffffffa01ad425>] :ch:ch_read_element_status+0x135/0x1a0
[  157.843758]  [<ffffffffa01ad2a8>] :ch:ch_init_elem+0x48/0x90
[  157.843808]  [<ffffffffa01ae80c>] :ch:ch_probe+0x4bc/0x760
[  157.843864]  [<ffffffff803a0e56>] driver_probe_device+0x96/0x190
[  157.843915]  [<ffffffff803a0fd9>] __driver_attach+0x89/0x90
[  157.843964]  [<ffffffff803a0f50>] __driver_attach+0x0/0x90
[  157.844013]  [<ffffffff803a046d>] bus_for_each_dev+0x4d/0x80
[  157.844064]  [<ffffffff80293a15>] kmem_cache_alloc+0x65/0xa0
[  157.844114]  [<ffffffff803a0ab5>] bus_add_driver+0x1f5/0x270
[  157.844165]  [<ffffffff803a1265>] driver_register+0x55/0x140
[  157.844216]  [<ffffffffa005b05d>] :ch:init_ch_module+0x5d/0xa6
[  157.844266]  [<ffffffff80257a2a>] sys_init_module+0x17a/0x1d00
[  157.844333]  [<ffffffff8020c2ab>] system_call_after_swapgs+0x7b/0x80
[  157.844386]
[  157.844427] INFO: task modprobe:3939 blocked for more than 120 seconds.
[  157.844478] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" 
disables this message.
[  157.844544] modprobe      D ffff810001044280     0  3939   3938
[  157.844641]  ffff8105fb6bbbf8 0000000000000086 0000000000000000 
0000000000000000
[  157.844800]  ffffffff8061e280 ffffffff8061e280 ffffffff8061a4e0 
ffffffff8061e280
[  157.844956]  ffff8105fb4eef88 ffff8105fb6bbbc4 ffff8105fb6bbbb8 
ffff8105fb6bbba8
[  157.845078] Call Trace:
[  157.845164]  [<ffffffff802ef36b>] create_dir+0x6b/0xb0
[  157.845214]  [<ffffffff8044d175>] schedule_timeout+0x95/0xd0
[  157.845265]  [<ffffffff80331bcf>] kobject_add_internal+0xdf/0x1c0
[  157.846597]  [<ffffffff80331e3e>] kobject_init_and_add+0x6e/0x90
[  157.846647]  [<ffffffff8044da46>] __down+0x56/0x90
[  157.846696]  [<ffffffff8024cf07>] down+0x47/0x50
[  157.846744]  [<ffffffff803a0f80>] __driver_attach+0x30/0x90
[  157.846792]  [<ffffffff803a0f50>] __driver_attach+0x0/0x90
[  157.846841]  [<ffffffff803a046d>] bus_for_each_dev+0x4d/0x80
[  157.846891]  [<ffffffff80293a15>] kmem_cache_alloc+0x65/0xa0
[  157.846940]  [<ffffffff803a0ab5>] bus_add_driver+0x1f5/0x270
[  157.846991]  [<ffffffff803a1265>] driver_register+0x55/0x140
[  157.847044]  [<ffffffffa00610bc>] :st:init_st+0xbc/0x1be
[  157.847092]  [<ffffffff80257a2a>] sys_init_module+0x17a/0x1d00
[  157.847150]  [<ffffffff8028bb30>] alloc_pages_current+0x0/0xe0
[  157.847205]  [<ffffffff8020c2ab>] system_call_after_swapgs+0x7b/0x80
[  157.847258]
[  210.928038] loop: module loaded
[  210.985319] lp: driver loaded but no devices found
[  286.691381] INFO: task modprobe:3924 blocked for more than 120 seconds.
[  286.691436] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" 
disables this message.
[  286.692482] modprobe      D ffff810001044280     0  3924      1
[  286.692580]  ffff8102fe4a7918 0000000000000086 0000000000000000 
ffff8102fe4d2280
[  286.693507]  ffffffff8061e280 ffffffff8061e280 ffffffff8061a4e0 
ffffffff8061e280
[  286.693665]  ffff8102fb1b0dc8 ffff8102fe4a78e4 ffff8102fe4a78d8 
ffff8102fe4a78c8
[  286.693787] Call Trace:
[  286.693883]  [<ffffffffa01084eb>] :mptscsih:mptscsih_qcmd+0x22b/0x5c0
[  286.693939]  [<ffffffff8044d175>] schedule_timeout+0x95/0xd0
[  286.693991]  [<ffffffff8031fd8b>] elv_next_request+0x5b/0x250
[  286.694063]  [<ffffffffa006cf2f>] :scsi_mod:scsi_dispatch_cmd+0x12f/0x2e0
[  286.694116]  [<ffffffff8044cec5>] wait_for_common+0xa5/0x160
[  286.694167]  [<ffffffff8022a9b0>] default_wake_function+0x0/0x10
[  286.694220]  [<ffffffff8032553f>] blk_execute_rq+0x9f/0x110
[  286.694270]  [<ffffffff803227b1>] get_request_wait+0x21/0x180
[  286.694332]  [<ffffffffa007367c>] :scsi_mod:scsi_execute+0xec/0x150
[  286.694391]  [<ffffffffa0073771>] :scsi_mod:scsi_execute_req+0x91/0x100
[  286.694447]  [<ffffffffa01ad12b>] :ch:ch_do_scsi+0x7b/0x1b0
[  286.694498]  [<ffffffffa01ad425>] :ch:ch_read_element_status+0x135/0x1a0
[  286.694551]  [<ffffffffa01ad2a8>] :ch:ch_init_elem+0x48/0x90
[  286.694604]  [<ffffffffa01ae80c>] :ch:ch_probe+0x4bc/0x760
[  286.694660]  [<ffffffff803a0e56>] driver_probe_device+0x96/0x190
[  286.694712]  [<ffffffff803a0fd9>] __driver_attach+0x89/0x90
[  286.694761]  [<ffffffff803a0f50>] __driver_attach+0x0/0x90
[  286.694810]  [<ffffffff803a046d>] bus_for_each_dev+0x4d/0x80
[  286.694861]  [<ffffffff80293a15>] kmem_cache_alloc+0x65/0xa0
[  286.694913]  [<ffffffff803a0ab5>] bus_add_driver+0x1f5/0x270
[  286.694964]  [<ffffffff803a1265>] driver_register+0x55/0x140
[  286.695017]  [<ffffffffa005b05d>] :ch:init_ch_module+0x5d/0xa6
[  286.695067]  [<ffffffff80257a2a>] sys_init_module+0x17a/0x1d00
[  286.695135]  [<ffffffff8020c2ab>] system_call_after_swapgs+0x7b/0x80
[  286.695188]
[  286.695229] INFO: task modprobe:3939 blocked for more than 120 seconds.
[  286.695279] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" 
disables this message.
[  286.695345] modprobe      D ffff810001044280     0  3939   3938
[  286.695440]  ffff8105fb6bbbf8 0000000000000086 0000000000000000 
0000000000000000
[  286.695600]  ffffffff8061e280 ffffffff8061e280 ffffffff8061a4e0 
ffffffff8061e280
[  286.695759]  ffff8105fb4eef88 ffff8105fb6bbbc4 ffff8105fb6bbbb8 
ffff8105fb6bbba8
[  286.695880] Call Trace:
[  286.695966]  [<ffffffff802ef36b>] create_dir+0x6b/0xb0
[  286.696016]  [<ffffffff8044d175>] schedule_timeout+0x95/0xd0
[  286.696067]  [<ffffffff80331bcf>] kobject_add_internal+0xdf/0x1c0
[  286.696117]  [<ffffffff80331e3e>] kobject_init_and_add+0x6e/0x90
[  286.696168]  [<ffffffff8044da46>] __down+0x56/0x90
[  286.696218]  [<ffffffff8024cf07>] down+0x47/0x50
[  286.696266]  [<ffffffff803a0f80>] __driver_attach+0x30/0x90
[  286.696316]  [<ffffffff803a0f50>] __driver_attach+0x0/0x90
[  286.696364]  [<ffffffff803a046d>] bus_for_each_dev+0x4d/0x80
[  286.696413]  [<ffffffff80293a15>] kmem_cache_alloc+0x65/0xa0
[  286.696463]  [<ffffffff803a0ab5>] bus_add_driver+0x1f5/0x270
[  286.696514]  [<ffffffff803a1265>] driver_register+0x55/0x140
[  286.696567]  [<ffffffffa00610bc>] :st:init_st+0xbc/0x1be
[  286.696616]  [<ffffffff80257a2a>] sys_init_module+0x17a/0x1d00
[  286.696676]  [<ffffffff8028bb30>] alloc_pages_current+0x0/0xe0
[  286.696731]  [<ffffffff8020c2ab>] system_call_after_swapgs+0x7b/0x80
[  286.696784]
[  320.909411] ch0: ... finished
[  320.909411] ch 3:0:0:0: Attached scsi changer ch0
[  320.909858] st 3:0:3:0: Attached scsi tape st0
[  320.909905] st 3:0:3:0: st0: try direct i/o: yes (alignment 4 B)
[  321.183325] Adding 5831552k swap on /dev/sdc5.  Priority:-1 extents:1 
across:5831552k
[  321.352153] st0: Block limits 1 - 16777215 bytes.


I also get:

jk@bacula:~$ dmesg | grep bus_type
[   13.252144] Driver 'sd' needs updating - please use bus_type methods
[   13.253901] Driver 'sr' needs updating - please use bus_type methods
[   27.670335] Driver 'ch' needs updating - please use bus_type methods
[   27.680156] Driver 'st' needs updating - please use bus_type methods
jk@bacula:~$

Should I be worried about that?

-- 
Jesper

Re: Media autochanger driver changed behavior.

[Jesper Krogh]

> I'll get it done and report but, but we're a bit behind on the 
> backup-schedules. So when the system has catched up I'll do some testing.

On 2.6.26.1 I also get quite strange behavior .. sometimes the changer 
id discovered as a "sgX" device and sometimes it is discovered as a 
"schX".. the schX doesnt work:


$ lsscsi
[0:0:0:0]    cd/dvd  AMI      Virtual CDROM    1.00  /dev/scd0
[1:0:0:0]    disk    AMI      Virtual Floppy   1.00  /dev/sda
[2:0:0:0]    disk    HITACHI  H101414SCSUN146G SA23  -
[2:0:1:0]    disk    HITACHI  H101414SCSUN146G SA23  -
[2:0:2:0]    disk    FUJITSU  MBB2147RCSUN146G 0505  -
[2:0:3:0]    disk    FUJITSU  MBB2147RCSUN146G 0505  -
[2:1:0:0]    disk    LSILOGIC Logical Volume   3000  /dev/sdc
[2:1:2:0]    disk    LSILOGIC Logical Volume   3000  /dev/sdb
[3:0:0:0]    mediumx QUANTUM  PX500            002A  /dev/sch0
[3:0:3:0]    tape    HP       Ultrium 3-SCSI   G39Z  /dev/st0

When it works.. I dont have any device put onto the mediumx-thing in 
this list. And none of the sgX devices actually works. Rebooting the 
system "might" bring it correcly up.

Full dmesg: http://krogh.cc/~jesper/dmesg-broken.txt

/dev/changer is made by this udev rule:

/etc/udev/rules.d/60-symlinks.rules:SYSFS{vendor}=="QUANTUM", 
SYSFS{model}=="PX500"         SYMLINK+="changer"

jk@bacula:~$ sudo mtx -f /dev/sch0 status
/dev/sch0 is not an sg device, or old sg driver

$ sudo strace mtx -f /dev/sch0 status
execve("/usr/sbin/mtx", ["mtx", "-f", "/dev/sch0", "status"], [/* 16 
vars */]) = 0
brk(0)                                  = 0x60b000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) 
= 0x7f049f174000
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or 
directory)
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) 
= 0x7f049f172000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or 
directory)
open("/etc/ld.so.cache", O_RDONLY)      = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=38937, ...}) = 0
mmap(NULL, 38937, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f049f168000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or 
directory)
open("/lib/libc.so.6", O_RDONLY)        = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\340\342"..., 
832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=1436976, ...}) = 0
mmap(NULL, 3543672, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 
0) = 0x7f049ebf6000
mprotect(0x7f049ed4e000, 2097152, PROT_NONE) = 0
mmap(0x7f049ef4e000, 20480, PROT_READ|PROT_WRITE, 
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x158000) = 0x7f049ef4e000
mmap(0x7f049ef53000, 17016, PROT_READ|PROT_WRITE, 
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f049ef53000
close(3)                                = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) 
= 0x7f049f167000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) 
= 0x7f049f166000
arch_prctl(ARCH_SET_FS, 0x7f049f1666e0) = 0
mprotect(0x7f049ef4e000, 12288, PROT_READ) = 0
munmap(0x7f049f168000, 38937)           = 0
open("/dev/sch0", O_RDWR)               = 3
ioctl(3, SG_GET_VERSION_NUM, 0x7fffa7175b30) = -1 EINVAL (Invalid argument)
write(2, "/dev/sch0 is not an sg device, o"..., 48/dev/sch0 is not an sg 
device, or old sg driver
) = 48
exit_group(1)                           = ?
Process 8139 detached
jk@bacula:~$

-- 
Jesper