You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@spamassassin.apache.org by George Georgalis <ge...@galis.org> on 2005/03/03 22:40:23 UTC
a problem with linux 2.6.11 and sa
Is anyone successfully runing SA on a 2.6.11 linux kernel?
>On Thu, 3 Mar 2005 02:16:03 -0500, George Georgalis <ge...@galis.org> wrote:
>> I'm very defiantly seeing a problem with the 2.6.11
>> kernel and my spamassassin setup. However, it's not
>> clear exactly where the problem is, seems like sa
>> but it might be 2.6.11 with daemontools + qmail +
>> QMAIL_QUEUE.
>>
>> I don't really have time to break down an analysis,
>> but I'm fairly certain. If anyone is experiencing
>> the problem please contact me on or off the list.
>>
>> A sure sign of it is no logs (with debug) for remote
>> sa connections which score "0/0" and correct operation
>> with "cat spam.txt | spamc -R"; fix is to use the
>> older kernel.
Per request here are some logs, I will reboot into 2.6.11 if the
below dmesg doesn't give you details you need. These logs are from the
first sa failure I noticed. (The first timestamp colmn is my local
timezone, EST, it looks like SA logs in UTC)
This log entry indicates when I booted into 2.6.11:
2005-03-02 12:05:47.018334500 2005-03-02 17:05:47 [781] i: server killed by SIGTERM, shutting down
The following entry was a manual "cat spam.txt | spamc -R" the test
was done because sa stopped logging and startes scoring "0/0" for
everything, obviously the locat test worked:
2005-03-02 17:29:22.627607500 2005-03-02 22:29:22 [895] i: connection from sta.local [192.168.80.50] at port 36492
# connection to my QMAIL_QUEUE from tcpserver, spam is from 82.229.134.94:
2005-03-02 17:03:45.459533500 tcpserver: status: 0/4
2005-03-02 17:04:07.779403500 tcpserver: status: 1/4
2005-03-02 17:04:07.779409500 tcpserver: pid 4074 from 82.229.134.94
2005-03-02 17:04:09.373336500 tcpserver: ok 4074 sta.galis.org:192.168.80.50:25 facultes-4-82-229-134-94.fbx.proxad.net:82.229.134.94::3682
2005-03-02 17:04:51.556172500 tcpserver: status: 2/4
2005-03-02 17:04:51.556179500 tcpserver: pid 4075 from 209.61.182.217
2005-03-02 17:04:51.557168500 tcpserver: ok 4075 sta.galis.org:192.168.80.50:25 rince.africaninspace.com:209.61.182.217::41362
2005-03-02 17:04:51.959217500 tcpserver: end 4075 status 0
2005-03-02 17:04:51.959224500 tcpserver: status: 1/4
2005-03-02 17:05:43.461588500 tcpserver: end 4074 status 0
2005-03-02 17:05:43.461595500 tcpserver: status: 0/4
# logs from sa
2005-03-02 11:06:43.353479500 2005-03-02 16:06:43 [899] i: checking message <00...@Amos> for qmaild:1002.
2005-03-02 11:06:45.942978500 2005-03-02 16:06:45 [899] i: clean message (-0.8/4.0) for qmaild:1002 in 2.0 seconds, 3099 bytes.
2005-03-02 11:06:45.942987500 2005-03-02 16:06:45 [899] i: result: . 0 - GEO_TO scantime=2.0,size=3099,mid=<00...@Amos>,autolearn=disabled
2005-03-02 11:30:49.192464500 2005-03-02 16:30:49 [900] i: connection from localhost [127.0.0.1] at port 33218
2005-03-02 11:30:49.206473500 2005-03-02 16:30:49 [900] i: checking message <20...@radish.jmason.org> for qmaild:1002.
2005-03-02 11:30:51.826020500 2005-03-02 16:30:51 [900] i: clean message (0.1/4.0) for qmaild:1002 in 2.0 seconds, 4223 bytes.
2005-03-02 11:30:51.826030500 2005-03-02 16:30:51 [900] i: result: . 0 - TW_XM scantime=2.0,size=4223,mid=<20...@radish.jmason.org>,autolearn=disabled
2005-03-02 11:59:45.509284500 2005-03-02 16:59:45 [898] i: connection from localhost [127.0.0.1] at port 33227
2005-03-02 11:59:45.521365500 2005-03-02 16:59:45 [898] i: checking message <42...@ocsny.com> for qmaild:1002.
2005-03-02 11:59:49.097678500 2005-03-02 16:59:49 [898] i: clean message (-0.8/4.0) for qmaild:1002 in 4.0 seconds, 2652 bytes.
2005-03-02 11:59:49.097689500 2005-03-02 16:59:49 [898] i: result: . 0 - GEO_TO scantime=4.0,size=2652,mid=<42...@ocsny.com>,autolearn=disabled
2005-03-02 12:05:47.018334500 2005-03-02 17:05:47 [781] i: server killed by SIGTERM, shutting down
2005-03-02 12:09:24.358948500 2005-03-02 17:09:24 [810] i: server started on port 783/tcp (running version 3.0.2)
2005-03-02 12:09:24.380867500 2005-03-02 17:09:24 [810] i: server successfully spawned child process, pid 895
2005-03-02 12:09:24.380876500 2005-03-02 17:09:24 [810] i: server successfully spawned child process, pid 896
2005-03-02 12:09:24.381256500 2005-03-02 17:09:24 [810] i: server successfully spawned child process, pid 897
2005-03-02 17:29:22.627607500 2005-03-02 22:29:22 [895] i: connection from sta.local [192.168.80.50] at port 36492
2005-03-02 17:29:22.650336500 2005-03-02 22:29:22 [895] i: checking message <58...@huhmail.com> for geo:1002.
2005-03-02 17:29:26.252961500 2005-03-02 22:29:26 [895] i: identified spam (33.3/4.0) for geo:1002 in 4.0 seconds, 2371 bytes.
2005-03-02 17:29:26.252970500 2005-03-02 22:29:26 [895] i: result: Y 33 - GEO_BAD_TO,GEO_LIST_TO,HELO_DYNAMIC_IPADDR,MIME_BOUND_DD_DIGITS,RATWARE_RCVD_AT,SARE_HEAD_MIME_PROD,SARE_MSGID_DBL_AT,SARE_RAND_2,SARE_RAND_2W,UNRESOLVED_TEMPLATE,URIBL_SBL,X_MESSAGE_INFO scantime=4.0,size=2371,mid=<58...@huhmail.com>,autolearn=disabled
###### end of current at Wed Mar 2 20:34:51 EST 2005 #########
# log from qmail send
2005-03-02 17:04:51.863130500 new msg 7274
2005-03-02 17:04:51.863583500 info msg 7274: bytes 2907 from <ub...@lists.ubuntu.com> qp 4085 uid 1002
2005-03-02 17:04:51.873197500 starting delivery 289: msg 7274 to local geo-george@galis.org
2005-03-02 17:04:51.874024500 status: local 1/10 remote 0/20
2005-03-02 17:04:51.970617500 delivery 289: success: did_1+0+2/
2005-03-02 17:04:51.971849500 status: local 0/10 remote 0/20
2005-03-02 17:04:51.971855500 end msg 7274
2005-03-02 17:05:29.391984500 new msg 7274
2005-03-02 17:05:29.392434500 info msg 7274: bytes 2463 from <zs...@huhmail.com> qp 4103 uid 1002
2005-03-02 17:05:29.402267500 starting delivery 290: msg 7274 to local geo-3ageorgw@galis.org
2005-03-02 17:05:29.403089500 status: local 1/10 remote 0/20
2005-03-02 17:05:29.492484500 delivery 290: success: did_1+0+2/
2005-03-02 17:05:29.493667500 status: local 0/10 remote 0/20
2005-03-02 17:05:29.493672500 end msg 7274
# the referenced spam message, sanitized subject.
>From zszgdbpunmxipm@huhmail.com Wed Mar 2 17:05:29 2005
Return-Path: <zs...@huhmail.com>
Delivered-To: geo-3ageorgw@galis.org
Received: (qmail 4103 invoked from network); 2 Mar 2005 22:05:29 -0000
Received: from facultes-4-82-229-134-94.fbx.proxad.net (82.229.134.94)
by sta.galis.org with SMTP; 2 Mar 2005 22:05:06 -0000
X-Message-Info: HVI+uie/25+nr/OTE+9/81703120453
Received: from smtp-erie.mouton.zszgdbpunmxipm@huhmail.com ([82.229.134.94]) by ms02-e61.zszgdbpunmxipm@huhmail.com with Microsoft SMTPSVC(5.0.1636.4684);
Thu, 03 Mar 2005 01:03:41 +0300
Received: from asphalt94.lawgive.zszgdbpunmxipm@huhmail.com (ballad90.zszgdbpunmxipm@huhmail.com [82.229.134.94])
by smtp-airpark.coin.zszgdbpunmxipm@huhmail.com (Postfix) with SMTP id 776FJR388G32WTON
for <3a...@galis.org>; Wed, 02 Mar 2005 16:05:41 -0600
X-Message-Info: QTDYM+%ND_LC_CHAR[1-3]58+pz+NFY+892/4753447138988
Received: (qmail 48037 invoked by uid 298); Thu, 03 Mar 2005 01:59:41 +0400
Date: Wed, 02 Mar 2005 14:58:41 -0700
Message-Id: <58...@huhmail.com>
From: Winnie Mayo <zs...@huhmail.com>
To: 3ageorgw <3a...@galis.org>
Subject: Jack Rabbit xxxxxxxxxx Features:
MIME-Version: 1.0 (produced by paramagneticdrugstore 3.1)
Content-Type: multipart/alternative;
boundary="--782766396549570929"
X-spamc: 0/0 by sta.galis.org; Wed, 2 Mar 2005 17:05:29 -0500
X-tcpremoteip: 82.229.134.94
# dmesg from a 2.6.8.1 kernel, front lost in queue.
st 4:
697eaf0aca3a3aea3a75164746ffaa79
pass
test 5:
56461ef2342edc00f9bab995690efd4c
pass
test 6:
6b1ab7fe4bd7bf8f0b62e6ce61b9d0cd
pass
test 7:
6f630fad67cda0ee1fb1f562db3aa53e
pass
testing hmac_md5 across pages
test 1:
750c783e6ab0b503eaa86e310a5db738
pass
testing hmac_sha1
test 1:
b617318655057264e28bc0b6fb378c8ef146be00
pass
test 2:
effcdf6ae5eb2fa2d27416d5f184df9c259a7c79
pass
test 3:
125d7342b9ac11cd91a39af48aa17b4f63f175d3
pass
test 4:
4c9007f4026250c6bc8414f9bf50c86c2d7235da
pass
test 5:
4c1a03424b55e07fe7f27be1d58bb9324a9a5a04
pass
test 6:
aa4ae5e15272d00e95705637ce8a3b55ed402112
pass
test 7:
e8e99d0f45237d786d6bbaa7965c7808bbff1a91
pass
testing hmac_sha1 across pages
test 1:
effcdf6ae5eb2fa2d27416d5f184df9c259a7c79
pass
testing hmac_sha256
test 1:
a21b1f5d4cf4f73a4dd939750f7a066a7f98cc131cb16a6692759021cfab8181
pass
test 2:
104fdc1257328f08184ba73131c53caee698e36119421149ea8c712456697d30
pass
test 3:
470305fc7e40fe34d3eeb3e773d95aab73acf0fd060447a5eb4595bf33a9d1a3
pass
test 4:
198a607eb44bfbc69903a0f1cf2bbdc5ba0aa3f3d9ae3c1c7a3b1696a0b68cf7
pass
test 5:
5bdcc146bf60754e6a042426089575c75a003f089d2739839dec58b964ec3843
pass
test 6:
cdcb1220d1ecccea91e53aba3092f962e549fe6ce9ed7fdc43191fbde45c30b0
pass
test 7:
d4633c17f6fb8d744c66dee0f8f074556ec4af55ef07998541468eb49bd2e917
pass
test 8:
7546af01841fc09b1ab9c3749a5f1c17d4f589668a587b2700a9c97c1193cf42
pass
test 9:
6953025ed96f0c09f80a96f78e6538dbe2e7b820e3dd970e7ddd39091b32352f
pass
test 10:
6355ac22e890d0a3c8481a5ca4825bc884d3e7a1ff98a2fc2ac7d8e064c3b2e6
pass
testing hmac_sha256 across pages
test 1:
5bdcc146bf60754e6a042426089575c75a003f089d2739839dec58b964ec3843
pass
testing michael_mic
failed to load transform for michael_mic
ACPI: Power Button (FF) [PWRF]
ACPI: Processor [CPU0] (supports C1 C2, 2 throttling states)
lp: driver loaded but no devices found
Real Time Clock Driver v1.12
hw_random hardware driver 1.0.0 loaded
Linux agpgart interface v0.100 (c) Dave Jones
agpgart: Detected VIA CLE266 chipset
agpgart: Maximum main memory to use for agp memory: 816M
agpgart: AGP aperture is 64M @ 0xe0000000
Hangcheck: starting hangcheck timer 0.5.0 (tick is 180 seconds, margin is 60 seconds).
Serial: 8250/16550 driver $Revision: 1.90 $ 8 ports, IRQ sharing disabled
ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
ttyS1 at I/O 0x2f8 (irq = 3) is a 16550A
parport0: PC-style at 0x378 [PCSPP(,...)]
lp0: using parport0 (polling).
RAMDISK driver initialized: 16 RAM disks of 4096K size 1024 blocksize
loop: loaded (max 8 devices)
via-rhine.c:v1.10-LK1.1.20-2.6 May-23-2004 Written by Donald Becker
ACPI: PCI interrupt 0000:00:12.0[A] -> GSI 11 (level, low) -> IRQ 11
eth0: VIA Rhine II at 0xeb001000, 00:40:63:d7:ab:83, IRQ 11.
eth0: MII PHY found at address 1, status 0x786d advertising 05e1 Link 45e1.
Linux video capture interface: v1.00
Uniform Multi-Platform E-IDE driver Revision: 7.00alpha2
ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx
VP_IDE: IDE controller at PCI slot 0000:00:11.1
ACPI: PCI interrupt 0000:00:11.1[A] -> GSI 11 (level, low) -> IRQ 11
VP_IDE: chipset revision 6
VP_IDE: not 100% native mode: will probe irqs later
VP_IDE: VIA vt8235 (rev 00) IDE UDMA133 controller on pci0000:00:11.1
ide0: BM-DMA at 0xa000-0xa007, BIOS settings: hda:pio, hdb:pio
ide1: BM-DMA at 0xa008-0xa00f, BIOS settings: hdc:DMA, hdd:pio
hdc: CD-ROM 50X L, ATAPI CD/DVD-ROM drive
Using anticipatory io scheduler
ide1 at 0x170-0x177,0x376 on irq 15
hdc: ATAPI 50X CD-ROM drive, 128kB Cache, UDMA(33)
Uniform CD-ROM driver Revision: 3.20
libata version 1.02 loaded.
sata_sil version 0.54
ACPI: PCI interrupt 0000:00:14.0[A] -> GSI 10 (level, low) -> IRQ 10
ata1: SATA max UDMA/100 cmd 0xF8889080 ctl 0xF888908A bmdma 0xF8889000 irq 10
ata2: SATA max UDMA/100 cmd 0xF88890C0 ctl 0xF88890CA bmdma 0xF8889008 irq 10
ata1: dev 0 cfg 49:2f00 82:346b 83:7d01 84:4003 85:3469 86:3c01 87:4003 88:207f
ata1: dev 0 ATA, max UDMA/133, 312581808 sectors: lba48
ata1(0): applying Seagate errata fix
ata1: dev 0 configured for UDMA/100
scsi0 : sata_sil
ata2: no device found (phy stat 00000000)
scsi1 : sata_sil
Vendor: ATA Model: ST3160023AS Rev: 3.18
Type: Direct-Access ANSI SCSI revision: 05
SCSI device sda: 312581808 512-byte hdwr sectors (160042 MB)
SCSI device sda: drive cache: write back
sda: sda1 sda2 sda3 sda4
Attached scsi disk sda at scsi0, channel 0, id 0, lun 0
Attached scsi generic sg0 at scsi0, channel 0, id 0, lun 0, type 0
ohci1394: $Rev: 1223 $ Ben Collins <bc...@debian.org>
ACPI: PCI interrupt 0000:00:0d.0[A] -> GSI 10 (level, low) -> IRQ 10
ohci1394: fw-host0: OHCI-1394 1.0 (PCI): IRQ=[10] MMIO=[eb003000-eb0037ff] Max Packet=[2048]
video1394: Installed video1394 module
ehci_hcd: block sizes: qh 128 qtd 96 itd 192 sitd 96
ACPI: PCI interrupt 0000:00:10.3[D] -> GSI 5 (level, low) -> IRQ 5
ehci_hcd 0000:00:10.3: VIA Technologies, Inc. USB 2.0
ehci_hcd 0000:00:10.3: reset hcs_params 0x3206 dbg=0 cc=3 pcc=2 ordered !ppc ports=6
ehci_hcd 0000:00:10.3: reset hcc_params 6872 thresh 7 uframes 256/512/1024
ehci_hcd 0000:00:10.3: capability 0001 at 68
ehci_hcd 0000:00:10.3: irq 5, pci mem f889f000
ehci_hcd 0000:00:10.3: new USB bus registered, assigned bus number 1
ehci_hcd 0000:00:10.3: reset command 080002 (park)=0 ithresh=8 period=1024 Reset HALT
ehci_hcd 0000:00:10.3: init command 010009 (park)=0 ithresh=1 period=256 RUN
ehci_hcd 0000:00:10.3: USB 2.0 enabled, EHCI 1.00, driver 2004-May-10
ehci_hcd 0000:00:10.3: supports USB remote wakeup
usb usb1: new device strings: Mfr=3, Product=2, SerialNumber=1
usb usb1: default language 0x0409
usb usb1: Product: VIA Technologies, Inc. USB 2.0
usb usb1: Manufacturer: Linux 2.6.8.1-sta ehci_hcd
usb usb1: SerialNumber: 0000:00:10.3
usb usb1: hotplug
usb usb1: adding 1-0:1.0 (config #1, interface 0)
usb 1-0:1.0: hotplug
hub 1-0:1.0: usb_probe_interface
hub 1-0:1.0: usb_probe_interface - got id
hub 1-0:1.0: USB hub found
hub 1-0:1.0: 6 ports detected
hub 1-0:1.0: standalone hub
hub 1-0:1.0: ganged power switching
hub 1-0:1.0: individual port over-current protection
hub 1-0:1.0: Single TT
hub 1-0:1.0: TT requires at most 8 FS bit times
hub 1-0:1.0: power on to power good time: 20ms
hub 1-0:1.0: local power source is good
hub 1-0:1.0: enabling power on all ports
USB Universal Host Controller Interface driver v2.2
ACPI: PCI interrupt 0000:00:10.0[A] -> GSI 11 (level, low) -> IRQ 11
uhci_hcd 0000:00:10.0: VIA Technologies, Inc. VT82xxxxx UHCI USB 1.1 Controller
uhci_hcd 0000:00:10.0: irq 11, io base 00009400
uhci_hcd 0000:00:10.0: new USB bus registered, assigned bus number 2
uhci_hcd 0000:00:10.0: detected 2 ports
usb usb2: new device strings: Mfr=3, Product=2, SerialNumber=1
usb usb2: default language 0x0409
usb usb2: Product: VIA Technologies, Inc. VT82xxxxx UHCI USB 1.1 Controller
usb usb2: Manufacturer: Linux 2.6.8.1-sta uhci_hcd
usb usb2: SerialNumber: 0000:00:10.0
usb usb2: hotplug
usb usb2: adding 2-0:1.0 (config #1, interface 0)
usb 2-0:1.0: hotplug
hub 2-0:1.0: usb_probe_interface
hub 2-0:1.0: usb_probe_interface - got id
hub 2-0:1.0: USB hub found
hub 2-0:1.0: 2 ports detected
hub 2-0:1.0: standalone hub
hub 2-0:1.0: no power switching (usb 1.0)
hub 2-0:1.0: individual port over-current protection
hub 2-0:1.0: power on to power good time: 2ms
hub 2-0:1.0: local power source is good
ACPI: PCI interrupt 0000:00:10.1[B] -> GSI 10 (level, low) -> IRQ 10
uhci_hcd 0000:00:10.1: VIA Technologies, Inc. VT82xxxxx UHCI USB 1.1 Controller (#2)
uhci_hcd 0000:00:10.1: irq 10, io base 00009800
uhci_hcd 0000:00:10.1: new USB bus registered, assigned bus number 3
uhci_hcd 0000:00:10.1: detected 2 ports
usb usb3: new device strings: Mfr=3, Product=2, SerialNumber=1
usb usb3: default language 0x0409
usb usb3: Product: VIA Technologies, Inc. VT82xxxxx UHCI USB 1.1 Controller (#2)
usb usb3: Manufacturer: Linux 2.6.8.1-sta uhci_hcd
usb usb3: SerialNumber: 0000:00:10.1
usb usb3: hotplug
usb usb3: adding 3-0:1.0 (config #1, interface 0)
usb 3-0:1.0: hotplug
hub 3-0:1.0: usb_probe_interface
hub 3-0:1.0: usb_probe_interface - got id
hub 3-0:1.0: USB hub found
hub 3-0:1.0: 2 ports detected
hub 3-0:1.0: standalone hub
hub 3-0:1.0: no power switching (usb 1.0)
hub 3-0:1.0: individual port over-current protection
hub 3-0:1.0: power on to power good time: 2ms
hub 3-0:1.0: local power source is good
ACPI: PCI interrupt 0000:00:10.2[C] -> GSI 12 (level, low) -> IRQ 12
uhci_hcd 0000:00:10.2: VIA Technologies, Inc. VT82xxxxx UHCI USB 1.1 Controller (#3)
uhci_hcd 0000:00:10.2: irq 12, io base 00009c00
uhci_hcd 0000:00:10.2: new USB bus registered, assigned bus number 4
uhci_hcd 0000:00:10.2: detected 2 ports
usb usb4: new device strings: Mfr=3, Product=2, SerialNumber=1
usb usb4: default language 0x0409
usb usb4: Product: VIA Technologies, Inc. VT82xxxxx UHCI USB 1.1 Controller (#3)
usb usb4: Manufacturer: Linux 2.6.8.1-sta uhci_hcd
usb usb4: SerialNumber: 0000:00:10.2
usb usb4: hotplug
usb usb4: adding 4-0:1.0 (config #1, interface 0)
usb 4-0:1.0: hotplug
hub 4-0:1.0: usb_probe_interface
hub 4-0:1.0: usb_probe_interface - got id
hub 4-0:1.0: USB hub found
hub 4-0:1.0: 2 ports detected
hub 4-0:1.0: standalone hub
hub 4-0:1.0: no power switching (usb 1.0)
hub 4-0:1.0: individual port over-current protection
hub 4-0:1.0: power on to power good time: 2ms
hub 4-0:1.0: local power source is good
Initializing USB Mass Storage driver...
usbcore: registered new driver usb-storage
USB Mass Storage support registered.
usbcore: registered new driver usbhid
drivers/usb/input/hid-core.c: v2.0:USB HID core driver
mice: PS/2 mouse device common for all mice
input: PC Speaker
serio: i8042 AUX port at 0x60,0x64 irq 12
serio: i8042 KBD port at 0x60,0x64 irq 1
ehci_hcd 0000:00:10.3: GetStatus port 4 status 001803 POWER sig=j CSC CONNECT
hub 1-0:1.0: port 4, status 0501, change 0001, 480 Mb/s
input: AT Translated Set 2 keyboard on isa0060/serio0
I2O Core - (C) Copyright 1999 Red Hat Software
I2O: Event thread created as pid 188
i2o: Checking for PCI I2O controllers...
I2O configuration manager v 0.04.
(C) Copyright 1999 Red Hat Software
I2O Block Storage OSM v0.9
(c) Copyright 1999-2001 Red Hat Software.
i2o_block: Checking for Boot device...
i2o_block: Checking for I2O Block devices...
i2o_scsi.c: Version 0.1.2
chain_pool: 0 bytes @ f7df21c0
(512 byte buffers X 4 can_queue X 0 i2o controllers)
i2c /dev entries driver
md: raid1 personality registered as nr 3
md: md driver 0.90.0 MAX_MD_DEVS=256, MD_SB_DISKS=27
device-mapper: 4.1.0-ioctl (2003-12-10) initialised: dm@uk.sistina.com
Advanced Linux Sound Architecture Driver Version 1.0.4 (Mon May 17 14:31:44 2004 UTC).
ACPI: PCI interrupt 0000:00:11.5[C] -> GSI 12 (level, low) -> IRQ 12
PCI: Setting latency timer of device 0000:00:11.5 to 64
hub 1-0:1.0: debounce: port 4: total 100ms stable 100ms status 0x501
hub 1-0:1.0: port 4 not reset yet, waiting 50ms
ehci_hcd 0000:00:10.3: port 4 high speed
ehci_hcd 0000:00:10.3: GetStatus port 4 status 001005 POWER sig=se0 PE CONNECT
usb 1-4: new high speed USB device using address 2
ehci_hcd 0000:00:10.3: devpath 4 ep0out 3strikes
ehci_hcd 0000:00:10.3: devpath 4 ep0out 3strikes
usbcore: registered new driver snd-usb-audio
ALSA device list:
#0: VIA 8235 at 0xa400, irq 12
NET: Registered protocol family 2
IP: routing cache hash table of 8192 buckets, 64Kbytes
TCP: Hash tables configured (established 262144 bind 65536)
ip_conntrack version 2.1 (7168 buckets, 57344 max) - 296 bytes per conntrack
ip_tables: (C) 2000-2002 Netfilter core team
ipt_recent v0.3.1: Stephen Frost <sf...@snowman.net>. http://snowman.net/projects/ipt_recent/
IPVS: Registered protocols (TCP, UDP, AH, ESP)
IPVS: Connection hash table configured (size=4096, memory=32Kbytes)
usb 1-4: device not accepting address 2, error -71
IPVS: ipvs loaded.
IPVS: [rr] scheduler registered.
IPVS: [sed] scheduler registered.
Initializing IPsec netlink socket
NET: Registered protocol family 1
NET: Registered protocol family 17
NET: Registered protocol family 15
BIOS EDD facility v0.16 2004-Jun-25, 1 devices found
md: Autodetecting RAID arrays.
md: autorun ...
md: ... autorun DONE.
ReiserFS: sda1: found reiserfs format "3.6" with standard journal
ReiserFS: sda1: using ordered data mode
ReiserFS: sda1: journal params: device sda1, size 8192, journal first block 18, max trans len 1024, max batch 900, max commit age 30, max trans age 30
ReiserFS: sda1: checking transaction log (sda1)
ReiserFS: sda1: Using r5 hash to sort names
VFS: Mounted root (reiserfs filesystem) readonly.
Freeing unused kernel memory: 208k freed
hub 1-0:1.0: port 4 not reset yet, waiting 50ms
ehci_hcd 0000:00:10.3: port 4 high speed
ehci_hcd 0000:00:10.3: GetStatus port 4 status 001005 POWER sig=se0 PE CONNECT
usb 1-4: new high speed USB device using address 3
ehci_hcd 0000:00:10.3: devpath 4 ep0in 3strikes
ehci_hcd 0000:00:10.3: devpath 4 ep0out 3strikes
ieee1394: Host added: ID:BUS[0-00:1023] GUID[004063500001b505]
ehci_hcd 0000:00:10.3: devpath 4 ep0out 3strikes
usb 1-4: device not accepting address 3, error -71
ehci_hcd 0000:00:10.3: GetStatus port 5 status 001030 POWER sig=se0 OCC OC
hub 1-0:1.0: over-current change on port 5
hub 1-0:1.0: enabling power on all ports
ehci_hcd 0000:00:10.3: GetStatus port 6 status 001030 POWER sig=se0 OCC OC
hub 1-0:1.0: over-current change on port 6
hub 1-0:1.0: enabling power on all ports
uhci_hcd 0000:00:10.0: port 1 portsc 008a
hub 2-0:1.0: port 1, status 0100, change 0003, 12 Mb/s
Adding 1638620k swap on /dev/sda2. Priority:-1 extents:1
hub 2-0:1.0: debounce: port 1: total 100ms stable 100ms status 0x100
uhci_hcd 0000:00:10.0: port 2 portsc 008a
hub 2-0:1.0: port 2, status 0100, change 0003, 12 Mb/s
hub 2-0:1.0: debounce: port 2: total 100ms stable 100ms status 0x100
uhci_hcd 0000:00:10.1: port 1 portsc 008a
hub 3-0:1.0: port 1, status 0100, change 0003, 12 Mb/s
hub 3-0:1.0: debounce: port 1: total 100ms stable 100ms status 0x100
uhci_hcd 0000:00:10.1: port 2 portsc 009a
hub 3-0:1.0: port 2, status 0100, change 0003, 12 Mb/s
hub 3-0:1.0: debounce: port 2: total 100ms stable 100ms status 0x100
uhci_hcd 0000:00:10.2: port 1 portsc 048a
hub 4-0:1.0: port 1, status 0108, change 0003, 12 Mb/s
hub 4-0:1.0: debounce: port 1: total 100ms stable 100ms status 0x108
uhci_hcd 0000:00:10.2: port 2 portsc 048a
hub 4-0:1.0: port 2, status 0108, change 0003, 12 Mb/s
uhci_hcd 0000:00:10.0: suspend_hc
hub 4-0:1.0: debounce: port 2: total 100ms stable 100ms status 0x108
uhci_hcd 0000:00:10.1: suspend_hc
uhci_hcd 0000:00:10.2: suspend_hc
ReiserFS: sda3: found reiserfs format "3.6" with standard journal
ReiserFS: sda3: using ordered data mode
ReiserFS: sda3: journal params: device sda3, size 8192, journal first block 18, max trans len 1024, max batch 900, max commit age 30, max trans age 30
ReiserFS: sda3: checking transaction log (sda3)
ReiserFS: sda3: Using r5 hash to sort names
ReiserFS: sda4: found reiserfs format "3.6" with standard journal
ReiserFS: sda4: using ordered data mode
ReiserFS: sda4: journal params: device sda4, size 8192, journal first block 18, max trans len 1024, max batch 900, max commit age 30, max trans age 30
ReiserFS: sda4: checking transaction log (sda4)
ReiserFS: sda4: Using r5 hash to sort names
eth0: Setting full-duplex based on MII #1 link partner capability of 45e1.
The 2.6.11 config is nearly identical, and I can provide that dmesg if
this is insufficent info.
Thanks,
// George
--
George Georgalis, systems architect, administrator Linux BSD IXOYE
http://galis.org/george/ cell:646-331-2027 mailto:george@galis.org
Re: a problem with linux 2.6.11 and sa
Posted by George Georgalis <ge...@galis.org>.
On Tue, 8 Mar 2005 12:19:53 -0500, George Georgalis <ge...@galis.org> wrote:
> On Tue, Mar 08, 2005 at 11:58:14AM -0500, George Georgalis wrote:
> >On Tue, Mar 08, 2005 at 01:37:03PM +0000, Nix wrote:
> >>On Thu, 3 Mar 2005, George Georgalis uttered the following:
> >>> I recall a problem a while back with a pipe from
> >>> /proc/kmsg that was sent by root to a program with a
> >>> user uid. The fix was to run the logging program as
> >>> root. Has that protected pipe method been extended
> >>> since 2.6.8.1?
> >>
> >>The entire implementation of pipes has been radically revised between
> >>2.6.10 and 2.6.11: see, e.g., <http://lwn.net/Articles/118750/> and
> >><http://lwn.net/Articles/119682/>.
> >>
> >>Bugs have been spotted in this area in 2.6.10: this may be
> >>another one.
> >
> >Thanks, my issue is clearly between 2.6.10 and 2.6.11; though I won't be
> >able to drill down anything more specific, for a while. The links
> >do look relevant but I cannot say for sure.
Here is a problem with 2.6.10:
while read file; do mplayer $file ; done <mediafiles.txt
or
tail -n93 mediafiles.txt | while read file; do mplayer $file ; done
for each file path in that text file I get:
Failed to open /dev/rtc: Permission denied (it should be readable by the user.)
In addition the audio pcm level is set to zero (presumably by mplayer).
This does work:
for file in `cat mediafiles.txt`; do mplayer $file ; done
but discovering and fixing code now broke will be unpleasent.
What exactly is going on?
// George
--
George Georgalis, systems architect, administrator Linux BSD IXOYE
http://galis.org/george/ cell:646-331-2027 mailto:george@galis.org
Re: a problem with linux 2.6.11 and sa
Posted by George Georgalis <ge...@galis.org>.
On Tue, Mar 08, 2005 at 11:58:14AM -0500, George Georgalis wrote:
>On Tue, Mar 08, 2005 at 01:37:03PM +0000, Nix wrote:
>>On Thu, 3 Mar 2005, George Georgalis uttered the following:
>>> I recall a problem a while back with a pipe from
>>> /proc/kmsg that was sent by root to a program with a
>>> user uid. The fix was to run the logging program as
>>> root. Has that protected pipe method been extended
>>> since 2.6.8.1?
>>
>>The entire implementation of pipes has been radically revised between
>>2.6.10 and 2.6.11: see, e.g., <http://lwn.net/Articles/118750/> and
>><http://lwn.net/Articles/119682/>.
>>
>>Bugs have been spotted in this area in 2.6.10: this may be
>>another one.
>
>Thanks, my issue is clearly between 2.6.10 and 2.6.11; though I won't be
>able to drill down anything more specific, for a while. The links
>do look relevant but I cannot say for sure.
My last post didn't actually describe what the problem is, which is
spamassassin always scores 0/0 under 2.6.11 but functions properly
(scoring x/5) under 2.6.10.
More details are in the thread of this post.
http://lkml.org/lkml/2005/3/3/513
// George
--
George Georgalis, systems architect, administrator Linux BSD IXOYE
http://galis.org/george/ cell:646-331-2027 mailto:george@galis.org
Re: a problem with linux 2.6.11 and sa
Posted by George Georgalis <ge...@galis.org>.
On Wed, Mar 09, 2005 at 01:06:11PM +0000, Nix wrote:
>> An interesting technique that allows a program (such as a log writer)
>> to run as an unprivileged user, while receiving privileged data. (taken
>> almost verbatim from Gerrit Pape's socklog)
>>
>> #!/bin/sh
>> exec </proc/kmsg
>> exec 2>&1
>> exec softlimit -m 2000000 setuidgid nobody socklog ucspi
>>
>> This script, run by root takes its stdin from /proc/kmsg then combines
>> its stdout and stderr, and exec-switches to the socklog program run
>> as an ucspi application listening to the domain stream socket, as
>> nobody:nogroup, with memory consumption limited to 2Mb. (and sends
>> log to stdout)
>
>This is definitely redirection, not piping. As far as I know the
>implementation of redirection in the kernel remains unchanged: certainly
>the need to buffer piped data doesn't exist in this case, and since the
>redesign was of the buffering, this is probably not your problem :)
>
>> It worked flawlessly until several kernel revs back when the kernel
>> started protecting kmsg and wouldn't allow the user program to receive
>> it,
>
>Indeed.
>
>> result: nothing sent to the logging program and no error. The fix
>> was to run socklog as root instead of nobody.
>
>You should be able to open it as root and read from it as another user:
>i.e., your technique above shouldn't break. (I'd hope.)
Here is a nice proof that kmsg did become a problem around 2.6.0
http://article.gmane.org/gmane.comp.misc.pape.general/595
http://thread.gmane.org/gmane.comp.misc.pape.general/590
It (Gerrit Pape's technique) very defiantly stopped working a few revs
back (2.6.7?). I'm seeing a similar failed read from /dev/rtc and
mplayer with 2.6.10, now too.
http://lkml.org/lkml/2005/3/8/226
while read file; do mplayer $file ; done <mediafiles.txt
Failed to open /dev/rtc: Permission denied
for file in `cat mediafiles.txt`; do mplayer $file ; done
works.
// George
--
George Georgalis, systems architect, administrator Linux BSD IXOYE
http://galis.org/george/ cell:646-331-2027 mailto:george@galis.org
Re: a problem with linux 2.6.11 and sa
Posted by Nix <ni...@esperi.org.uk>.
On Tue, 8 Mar 2005, George Georgalis announced authoritatively:
> Here's what I'm doing that is broken. I use tcpserver (functionally
> similar to inetd) to receive an incoming smtp connection. While the
> smtp session is still open, the message is piped to a temp file which
> is then scanned for spam, if it passes the temp file is piped to my
Both of these sound like redirection, not piping.
>>(I don't see what you mean by `a pipe rom /proc/kmsg', though:
>>pipes connect processes, not files. File redirections are
>>quite different and should work unchanged in 2.6.11.)
>
> An interesting technique that allows a program (such as a log writer)
> to run as an unprivileged user, while receiving privileged data. (taken
> almost verbatim from Gerrit Pape's socklog)
>
> #!/bin/sh
> exec </proc/kmsg
> exec 2>&1
> exec softlimit -m 2000000 setuidgid nobody socklog ucspi
>
> This script, run by root takes its stdin from /proc/kmsg then combines
> its stdout and stderr, and exec-switches to the socklog program run
> as an ucspi application listening to the domain stream socket, as
> nobody:nogroup, with memory consumption limited to 2Mb. (and sends
> log to stdout)
This is definitely redirection, not piping. As far as I know the
implementation of redirection in the kernel remains unchanged: certainly
the need to buffer piped data doesn't exist in this case, and since the
redesign was of the buffering, this is probably not your problem :)
> It worked flawlessly until several kernel revs back when the kernel
> started protecting kmsg and wouldn't allow the user program to receive
> it,
Indeed.
> result: nothing sent to the logging program and no error. The fix
> was to run socklog as root instead of nobody.
You should be able to open it as root and read from it as another user:
i.e., your technique above shouldn't break. (I'd hope.)
--
> ...Hires Root Beer...
What we need these days is a stable, fast, anti-aliased root beer
with dynamic shading. Not that you can let just anybody have root.
--- John M. Ford
Re: a problem with linux 2.6.11 and sa
Posted by George Georgalis <ge...@galis.org>.
On Tue, Mar 08, 2005 at 01:37:03PM +0000, Nix wrote:
>On Thu, 3 Mar 2005, George Georgalis uttered the following:
>> I recall a problem a while back with a pipe from
>> /proc/kmsg that was sent by root to a program with a
>> user uid. The fix was to run the logging program as
>> root. Has that protected pipe method been extended
>> since 2.6.8.1?
>
>The entire implementation of pipes has been radically revised between
>2.6.10 and 2.6.11: see, e.g., <http://lwn.net/Articles/118750/> and
><http://lwn.net/Articles/119682/>.
>
>Bugs have been spotted in this area in 2.6.10: this may be
>another one.
Thanks, my issue is clearly between 2.6.10 and 2.6.11; though I won't be
able to drill down anything more specific, for a while. The links
do look relevant but I cannot say for sure.
Here's what I'm doing that is broken. I use tcpserver (functionally
similar to inetd) to receive an incoming smtp connection. While the
smtp session is still open, the message is piped to a temp file which
is then scanned for spam, if it passes the temp file is piped to my
local delivery program. If it doesn't pass the spam test or the delivery
program fails (disk full etc), the respective error code, if any,
is passed to tcpserver. The corresponding accepted, temporary reject or
permanently reject signal is passed to the remote sender.
The temp file is then removed or, for spam, it is cataloged for
statistics and/or abuse reporting. An additional copy is kept in a
traditional maildir to check for false positives.
#!/bin/bash
# exit 31 = permanently refuse
# exit 71 = temporarily refuse
# pwd is /var/qmail
echo $0 # for the logs
scq="spamc-queue" # a maildir with qmaild write perms
tmp="${scq}/`safecat "${scq}/tmp" "${scq}" </dev/stdin`" \
|| { echo "Error $?"; exit 71; } # put the pipeline to disk, if possible
# ${scq}/tmp is a temp for this function ${scq} is temp for this program
score=`spamc -x -c <"$tmp"` # score it with spamd
sce=$?
echo $score # for the logs
case $sce in
0) # ham
host=`cat control/me`
formail -f -A "X-spamc: ${score} by ${host}; `date -R`" \
-A "X-tcpremoteip: $TCPREMOTEIP" <"$tmp" \
| bin/qmail-queue # mark it and pass to the regular queue
qqe=$?
rm "$tmp"
exit $qqe # return whatever qmail-queue exits as
;;
1) # spam
sipd="$scq/IP/`echo $TCPREMOTEIP | sed 's|\.|/|g'`"
mkdir -p $sipd/{new,cur,tmp} # make a spam ip maildir, if needed
printf "$TCPREMOTEIP\t`date`\n" >>$sipd/date # keep track of when they came
maildir "${sipd}" >/dev/null <"$tmp" # keep a copy for reporting
maildir "${scq}" >/dev/null <"$tmp" # save it to verify no falseys
rm "$tmp"
exit 31
;;
*) # spamc error,
echo "$0 error, spamc exit $sce"
exit 71
esac
exit 81 # Internal bug
>If you can reproduce it consistently, *please* report
>this to the linux-kernel list!
I did, but have had no response to my followup:
Date: Fri, 4 Mar 2005 15:58:43 -0500
Subject: Re: problem with linux 2.6.11 and sa
>(I don't see what you mean by `a pipe rom /proc/kmsg', though:
>pipes connect processes, not files. File redirections are
>quite different and should work unchanged in 2.6.11.)
An interesting technique that allows a program (such as a log writer)
to run as an unprivileged user, while receiving privileged data. (taken
almost verbatim from Gerrit Pape's socklog)
#!/bin/sh
exec </proc/kmsg
exec 2>&1
exec softlimit -m 2000000 setuidgid nobody socklog ucspi
This script, run by root takes its stdin from /proc/kmsg then combines
its stdout and stderr, and exec-switches to the socklog program run
as an ucspi application listening to the domain stream socket, as
nobody:nogroup, with memory consumption limited to 2Mb. (and sends
log to stdout)
It worked flawlessly until several kernel revs back when the kernel
started protecting kmsg and wouldn't allow the user program to receive
it, result: nothing sent to the logging program and no error. The fix
was to run socklog as root instead of nobody.
// George
--
George Georgalis, systems architect, administrator Linux BSD IXOYE
http://galis.org/george/ cell:646-331-2027 mailto:george@galis.org
Re: a problem with linux 2.6.11 and sa
Posted by Nix <ni...@esperi.org.uk>.
On Thu, 3 Mar 2005, George Georgalis uttered the following:
> I recall a problem a while back with a pipe from
> /proc/kmsg that was sent by root to a program with a
> user uid. The fix was to run the logging program as
> root. Has that protected pipe method been extended
> since 2.6.8.1?
The entire implementation of pipes has been radically revised between
2.6.10 and 2.6.11: see, e.g., <http://lwn.net/Articles/118750/> and
<http://lwn.net/Articles/119682/>.
Bugs have been spotted in this area in 2.6.10: this may be
another one.
If you can reproduce it consistently, *please* report
this to the linux-kernel list!
(I don't see what you mean by `a pipe rom /proc/kmsg', though:
pipes connect processes, not files. File redirections are
quite different and should work unchanged in 2.6.11.)
--
> ...Hires Root Beer...
What we need these days is a stable, fast, anti-aliased root beer
with dynamic shading. Not that you can let just anybody have root.
--- John M. Ford
Re: a problem with linux 2.6.11 and sa
Posted by George Georgalis <ge...@galis.org>.
On Thu, Mar 03, 2005 at 04:53:58PM -0500, Matt Kettler wrote:
>At 04:40 PM 3/3/2005, George Georgalis wrote:
>>This log entry indicates when I booted into 2.6.11:
>>2005-03-02 12:05:47.018334500 2005-03-02 17:05:47 [781] i: server killed
>>by SIGTERM, shutting down
>
>Is there any chance you're running out of memory and the OOM killer is
>kicking in and sending SIGTERM's to spamd's?
>
No. There is 1Gb of memory on a very lightly loaded box, and no memory
intensive SA rules.
That SIGTERM was immedatly prior to the first time I booted 2.6.11,
where SA does not work (once) for remote connections (scores 0/0). The
problem is resolved running 2.6.8.1, where SA has been flawless for a
while.
Just occured to me the big gaint lock (new between the versions) has
been enabled, could it be related? Below is a post to LKML from today.
I recall a problem a while back with a pipe from
/proc/kmsg that was sent by root to a program with a
user uid. The fix was to run the logging program as
root. Has that protected pipe method been extended
since 2.6.8.1?
...
SA has stopped stdout logging completely with 2.6.11
in addition to the all pass score. But the message
seems to go through my temp queue (for testing) and
sent on to my local MDA. I'm not sure if it's a sa
problem with the kernel or the new kernel doing
something new with pipes from tcp connections.
Maybe the new kernel is not making files available
(eg 0 bytes), until the writing pipe is closed?
That would make my SA test a zero byte file, which
would pass, close, become full, and the file piped
to local MDA is full? ...humm then I'd get a score
of "0/5"... this sounds like a SA problem with the
new kernel, ideas?
// George
--
George Georgalis, systems architect, administrator Linux BSD IXOYE
http://galis.org/george/ cell:646-331-2027 mailto:george@galis.org
Re: a problem with linux 2.6.11 and sa
Posted by Matt Kettler <mk...@evi-inc.com>.
At 04:40 PM 3/3/2005, George Georgalis wrote:
>This log entry indicates when I booted into 2.6.11:
>2005-03-02 12:05:47.018334500 2005-03-02 17:05:47 [781] i: server killed
>by SIGTERM, shutting down
Is there any chance you're running out of memory and the OOM killer is
kicking in and sending SIGTERM's to spamd's?