When printing using hplip 3.9.8 on ubuntu I get a hpbackend null print error in syslog

Asked by Simon k

I have Ubuntu 8.0.4.3 LTS installed along with HPLIP 3.9.8. When I run HPLIP it detects my HP deskjet all-in-one F4280 as the F4200 series.

When I run sudo hp-check I get no errs or warnings and HPLIP connects to the USB printer ok. The issue is the Print Job goes to HOLD status and I get a 'prnt/backend/hp.c 802: ERROR: null print job total = 0'. I cannot print from any application even text editor.

when I print a popup appears stating that the print job is printing, then after 10 seconds another popup states that the print job has completed, however upon looking at the print queue in HPLIP you can see the job on HOLD.

Why would this be?

Many thanks

Simon

Question information

Language:
English Edit question
Status:
Solved
For:
HPLIP Edit question
Assignee:
No assignee Edit question
Solved by:
Simon k
Solved:
Last query:
Last reply:
Revision history for this message
Aaron Albright (albrigha-deactivatedaccount) said :
#1

Hey Simon,

Please run hp-check -t and post the output.

Thanks!

Aaron

Revision history for this message
Simon k (swkelso) said :
#2

Here you go Aaron
Thanks !

HP Linux Imaging and Printing System (ver. 3.9.8)
Dependency/Version Check Utility ver. 14.3

Copyright (c) 2001-9 Hewlett-Packard Development Company, LP
This software comes with ABSOLUTELY NO WARRANTY.
This is free software, and you are welcome to distribute it
under certain conditions. See COPYING file for more details.

Note: hp-check can be run in three modes:
1. Compile-time check mode (-c or --compile): Use this mode before compiling the
HPLIP supplied tarball (.tar.gz or .run) to determine if the proper dependencies
are installed to successfully compile HPLIP.
2. Run-time check mode (-r or --run): Use this mode to determine if a distro
supplied package (.deb, .rpm, etc) or an already built HPLIP supplied tarball
has the proper dependencies installed to successfully run.
3. Both compile- and run-time check mode (-b or --both) (Default): This mode
will check both of the above cases (both compile- and run-time dependencies).

Saving output in log file: hp-check.log

Initializing. Please wait...

---------------
| SYSTEM INFO |
---------------

Basic system information:
Linux neil-desktop 2.6.24-24-generic #1 SMP Sat Aug 22 01:06:14 UTC 2009 i686 GNU/Linux

Distribution:
ubuntu 8.04

Checking Python version...
OK, version 2.5.2 installed

Checking PyQt 4.x version...
OK, version 4.3.3 installed.

Checking for CUPS...
Status: scheduler is running
Version: 1.3.7
error_log is set to level: warn

Checking for dbus/python-dbus...
dbus daemon is running.
python-dbus version: 0.82.4

------------------------------------
| COMPILE AND RUNTIME DEPENDENCIES |
------------------------------------

Checking for dependency: CUPS - Common Unix Printing System...
OK, found.

Checking for dependency: CUPS DDK - CUPS driver development kit...
OK, found.

Checking for dependency: CUPS devel- Common Unix Printing System development files...
OK, found.

Checking for dependency: CUPS image - CUPS image development files...
OK, found.

Checking for dependency: DBus - Message bus system...
OK, found.

Checking for dependency: gcc - GNU Project C and C++ Compiler...
OK, found.

Checking for dependency: GhostScript - PostScript and PDF language interpreter and previewer...
OK, found.

Checking for dependency: libcrypto - OpenSSL cryptographic library...
OK, found.

Checking for dependency: libjpeg - JPEG library...
OK, found.

Checking for dependency: libnetsnmp-devel - SNMP networking library development files...
OK, found.

Checking for dependency: libpthread - POSIX threads library...
OK, found.

Checking for dependency: libtool - Library building support services...
OK, found.

Checking for dependency: libusb - USB library...
OK, found.

Checking for dependency: make - GNU make utility to maintain groups of programs...
OK, found.

Checking for dependency: PIL - Python Imaging Library (required for commandline scanning with hp-scan)...
OK, found.

Checking for dependency: PolicyKit - Administrative policy framework...
OK, found.

Checking for dependency: PyQt 4 DBus - DBus Support for PyQt4...
OK, found.

Checking for dependency: Python DBus - Python bindings for DBus...
OK, found.

Checking for dependency: Python devel - Python development files...
OK, found.

Checking for dependency: Python libnotify - Python bindings for the libnotify Desktop notifications...
OK, found.

Checking for dependency: Python XML libraries...
OK, found.

Checking for dependency: Python 2.3 or greater - Required for fax functionality...
OK, found.

Checking for dependency: Python 2.2 or greater - Python programming language...
OK, found.

Checking for dependency: Reportlab - PDF library for Python...
OK, found.

Checking for dependency: SANE - Scanning library...
OK, found.

Checking for dependency: SANE - Scanning library development files...
OK, found.

Checking for dependency: scanimage - Shell scanning program...
OK, found.

Checking for dependency: xsane - Graphical scanner frontend for SANE...
OK, found.

----------------------
| HPLIP INSTALLATION |
----------------------

Currently installed HPLIP version...
HPLIP 3.9.8 currently installed in '/usr/share/hplip'.

Current contents of '/etc/hp/hplip.conf' file:
# hplip.conf. Generated from hplip.conf.in by configure.

[hplip]
version=3.9.8

[dirs]
home=/usr/share/hplip
run=/var/run
ppd=/usr/share/ppd/HP
ppdbase=/usr/share/ppd
doc=/usr/share/doc/hplip-3.9.8
icon=/usr/share/applications
cupsbackend=/usr/lib/cups/backend
cupsfilter=/usr/lib/cups/filter
drv=/usr/share/cups/drv/hp

# Following values are determined at configure time and cannot be changed.
[configure]
network-build=yes
pp-build=no
gui-build=yes
scanner-build=yes
fax-build=yes
dbus-build=yes
cups11-build=no
doc-build=yes
shadow-build=no
hpijs-install=no
foomatic-drv-install=no
foomatic-ppd-install=no
foomatic-rip-hplip-install=no
hpcups-install=yes
cups-drv-install=no
cups-ppd-install=yes
internal-tag=3.9.8.36
restricted-build=no
ui-toolkit=qt4
qt3=no
qt4=yes
policy-kit=yes
hpijs-only-build=no
lite-build=no
udev-acl-rules=no

Current contents of '/var/lib/hp/hplip.state' file:
# hplip.state - HPLIP runtime persistent variables.

[plugin]
installed=0
eula=0

Current contents of '~/.hplip/hplip.conf' file:
[commands]
scan=/usr/bin/xsane -V %SANE_URI%

[fax]
email_address=
voice_phone=

[installation]
date_time=21/09/09 20:52:58
version=3.9.8

[last_used]
device_uri="hp:/usb/Deskjet_F4200_series?serial=CN89A2B05G05BR"
printer_name=
working_dir=.

[polling]
device_list=
enable=false
interval=5

[refresh]
enable=false
rate=30
type=1

[settings]
systray_messages=0
systray_visible=0

--------------------------
| DISCOVERED USB DEVICES |
--------------------------

  Device URI Model
  -------------------------------- -----------------------
  hp:/usb/Deskjet_F4200_series?ser HP Deskjet F4200 series
  ial=CN89A2B05G05BR

---------------------------------
| INSTALLED CUPS PRINTER QUEUES |
---------------------------------

Deskjet_F4200_series
--------------------
Type: Printer
Device URI: hp:/usb/Deskjet_F4200_series?serial=CN89A2B05G05BR
PPD: /etc/cups/ppd/Deskjet_F4200_series.ppd
PPD Description: HP DeskJet F4100 Foomatic/hpijs, hpijs 2.8.2
Printer status: printer Deskjet_F4200_series is idle. enabled since Tue 15 Sep 2009 20:46:51 BST

Communication status: Good

----------------------
| SANE CONFIGURATION |
----------------------

'hpaio' in '/etc/sane.d/dll.conf'...
OK, found. SANE backend 'hpaio' is properly set up.

Checking output of 'scanimage -L'...
device `hpaio:/usb/Deskjet_F4200_series?serial=CN89A2B05G05BR' is a Hewlett-Packard Deskjet_F4200_series all-in-one

---------------------
| PYTHON EXTENSIONS |
---------------------

Checking 'cupsext' CUPS extension...
OK, found.

Checking 'pcardext' Photocard extension...
OK, found.

Checking 'hpmudext' I/O extension...
OK, found.

Checking 'scanext' SANE scanning extension...
OK, found.

-----------------
| USB I/O SETUP |
-----------------

Checking for permissions of USB attached printers...

HP Device 0x2504 at 001:002:
    Device URI: hp:/usb/Deskjet_F4200_series?serial=CN89A2B05G05BR
    Device node: /dev/bus/usb/001/002
    Mode: 0660
getfacl: Removing leading '/' from absolute path names

# file: dev/bus/usb/001/002

# owner: lp

# group: lp

user::rw-

user:neil:rw-

group::rw-

mask::rw-

other::---

---------------
| USER GROUPS |
---------------

root

-----------
| SUMMARY |
-----------

No errors or warnings.

Done.

Revision history for this message
Aaron Albright (albrigha-deactivatedaccount) said :
#3

Can you post the errors you are seeing from the syslog?

Thanks!

Aaron

Revision history for this message
Simon k (swkelso) said :
#4

Here you go Aaron. Sorry for the delay I was on vacation and away from PC.

Thanks

Sep 28 11:17:25 neil-desktop syslogd 1.5.0#1ubuntu1: restart.
Sep 28 11:17:25 neil-desktop anacron[5064]: Job `cron.daily' terminated
Sep 28 11:17:25 neil-desktop anacron[5064]: Normal exit (1 job run)
Sep 28 11:29:37 neil-desktop -- MARK --
Sep 28 11:49:37 neil-desktop -- MARK --
Sep 28 12:09:37 neil-desktop -- MARK --
Sep 28 12:17:01 neil-desktop /USR/SBIN/CRON[5840]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)
Sep 28 12:29:37 neil-desktop -- MARK --
Sep 28 12:49:37 neil-desktop -- MARK --
Sep 28 20:11:17 neil-desktop syslogd 1.5.0#1ubuntu1: restart.
Sep 28 20:11:17 neil-desktop kernel: Inspecting /boot/System.map-2.6.24-24-generic
Sep 28 20:11:17 neil-desktop kernel: Loaded 27921 symbols from /boot/System.map-2.6.24-24-generic.
Sep 28 20:11:17 neil-desktop kernel: Symbols match kernel version 2.6.24.
Sep 28 20:11:18 neil-desktop kernel: Loaded 14106 symbols from 76 modules.
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] Initializing cgroup subsys cpuset
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] Initializing cgroup subsys cpu
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] Linux version 2.6.24-24-generic (buildd@palmer) (gcc version 4.2.4 (Ubuntu 4.2.4-1ubuntu4)) #1 SMP Sat Aug 22 01:06:14 UTC 2009 (Ubuntu 2.6.24-24.60-generic)
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] BIOS-provided physical RAM map:
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] BIOS-e820: 0000000000000000 - 000000000009f800 (usable)
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] BIOS-e820: 000000000009f800 - 00000000000a0000 (reserved)
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] BIOS-e820: 00000000000e0000 - 0000000000100000 (reserved)
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] BIOS-e820: 0000000000100000 - 000000000feb0000 (usable)
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] BIOS-e820: 000000000feb0000 - 000000000fefc000 (ACPI data)
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] BIOS-e820: 000000000fefc000 - 000000000fefd000 (ACPI NVS)
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] BIOS-e820: 000000000fefd000 - 000000000ff00000 (reserved)
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] BIOS-e820: 000000000ff00000 - 000000000ff80000 (usable)
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] BIOS-e820: 000000000ff80000 - 0000000010000000 (reserved)
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] BIOS-e820: 00000000fec00000 - 00000000fec10000 (reserved)
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] BIOS-e820: 00000000fee00000 - 00000000fee01000 (reserved)
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] BIOS-e820: 00000000ff800000 - 00000000ffc00000 (reserved)
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] BIOS-e820: 00000000fff00000 - 0000000100000000 (reserved)
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] 0MB HIGHMEM available.
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] 255MB LOWMEM available.
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] found SMP MP-table at 000f5f70
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] Entering add_active_range(0, 0, 65408) 0 entries of 256 used
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] Zone PFN ranges:
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] DMA 0 -> 4096
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] Normal 4096 -> 65408
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] HighMem 65408 -> 65408
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] Movable zone start PFN for each node
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] early_node_map[1] active PFN ranges
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] 0: 0 -> 65408
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] On node 0 totalpages: 65408
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] DMA zone: 32 pages used for memmap
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] DMA zone: 0 pages reserved
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] DMA zone: 4064 pages, LIFO batch:0
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] Normal zone: 479 pages used for memmap
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] Normal zone: 60833 pages, LIFO batch:15
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] HighMem zone: 0 pages used for memmap
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] Movable zone: 0 pages used for memmap
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] DMI present.
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] ACPI: RSDP signature @ 0xC00F5FC0 checksum 0
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] ACPI: RSDP 000F5FC0, 0014 (r0 PTLTD )
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] ACPI: RSDT 0FEF87F8, 0030 (r1 PTLTD RSDT 60400D0 LTP 0)
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] ACPI: FACP 0FEFBF0A, 0074 (r1 IBM MARLIN 60400D0 PTL 1)
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] ACPI: DSDT 0FEF8828, 36E2 (r1 IBM Marlin 60400D0 MSFT 100000D)
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] ACPI: FACS 0FEFCFC0, 0040
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] ACPI: APIC 0FEFBF7E, 005A (r1 PTLTD ^I APIC 60400D0 LTP 0)
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] ACPI: BOOT 0FEFBFD8, 0028 (r1 PTLTD $SBFTBL$ 60400D0 LTP 1)
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] ACPI: PM-Timer IO Port: 0x1008
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] ACPI: Local APIC address 0xfee00000
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] ACPI: LAPIC (acpi_id[0x00] lapic_id[0x00] enabled)
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] Processor #0 15:1 APIC version 20
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0x00] high edge lint[0x1])
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] ACPI: IOAPIC (id[0x01] address[0xfec00000] gsi_base[0])
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] IOAPIC[0]: apic_id 1, version 32, address 0xfec00000, GSI 0-23
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 high edge)
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] ACPI: IRQ0 used by override.
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] ACPI: IRQ2 used by override.
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] ACPI: IRQ9 used by override.
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] Enabling APIC mode: Flat. Using 1 I/O APICs
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] Using ACPI (MADT) for SMP configuration information
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] Allocating PCI resources starting at 20000000 (gap: 10000000:eec00000)
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] swsusp: Registered nosave memory region: 000000000009f000 - 00000000000a0000
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] swsusp: Registered nosave memory region: 00000000000a0000 - 00000000000e0000
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] swsusp: Registered nosave memory region: 00000000000e0000 - 0000000000100000
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] swsusp: Registered nosave memory region: 000000000feb0000 - 000000000fefc000
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] swsusp: Registered nosave memory region: 000000000fefc000 - 000000000fefd000
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] swsusp: Registered nosave memory region: 000000000fefd000 - 000000000ff00000
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 64897
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] Kernel command line: root=UUID=e6ba84f8-7c2f-4a37-b3ad-71c438249737 ro quiet splash
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] mapped APIC to ffffb000 (fee00000)
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] mapped IOAPIC to ffffa000 (fec00000)
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] Enabling fast FPU save and restore... done.
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] Enabling unmasked SIMD FPU exception support... done.
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] Initializing CPU#0
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] PID hash table entries: 1024 (order: 10, 4096 bytes)
Sep 28 20:11:18 neil-desktop kernel: [ 0.000000] Detected 1794.218 MHz processor.
Sep 28 20:11:18 neil-desktop kernel: [ 16.481198] Console: colour VGA+ 80x25
Sep 28 20:11:18 neil-desktop kernel: [ 16.481204] console [tty0] enabled
Sep 28 20:11:18 neil-desktop kernel: [ 16.481485] Dentry cache hash table entries: 32768 (order: 5, 131072 bytes)
Sep 28 20:11:18 neil-desktop kernel: [ 16.481733] Inode-cache hash table entries: 16384 (order: 4, 65536 bytes)
Sep 28 20:11:18 neil-desktop kernel: [ 16.491851] Memory: 247036k/261632k available (2181k kernel code, 13708k reserved, 1006k data, 368k init, 0k highmem)
Sep 28 20:11:18 neil-desktop kernel: [ 16.491864] virtual kernel memory layout:
Sep 28 20:11:18 neil-desktop kernel: [ 16.491865] fixmap : 0xfff4b000 - 0xfffff000 ( 720 kB)
Sep 28 20:11:18 neil-desktop kernel: [ 16.491867] pkmap : 0xff800000 - 0xffc00000 (4096 kB)
Sep 28 20:11:18 neil-desktop kernel: [ 16.491869] vmalloc : 0xd0800000 - 0xff7fe000 ( 751 MB)
Sep 28 20:11:18 neil-desktop kernel: [ 16.491870] lowmem : 0xc0000000 - 0xcff80000 ( 255 MB)
Sep 28 20:11:18 neil-desktop kernel: [ 16.491871] .init : 0xc0423000 - 0xc047f000 ( 368 kB)
Sep 28 20:11:18 neil-desktop kernel: [ 16.491873] .data : 0xc0321578 - 0xc041cdc4 (1006 kB)
Sep 28 20:11:18 neil-desktop kernel: [ 16.491874] .text : 0xc0100000 - 0xc0321578 (2181 kB)
Sep 28 20:11:18 neil-desktop kernel: [ 16.491879] Checking if this processor honours the WP bit even in supervisor mode... Ok.
Sep 28 20:11:18 neil-desktop kernel: [ 16.491937] SLUB: Genslabs=11, HWalign=64, Order=0-1, MinObjects=4, CPUs=1, Nodes=1
Sep 28 20:11:18 neil-desktop kernel: [ 16.571870] Calibrating delay using timer specific routine.. 3592.47 BogoMIPS (lpj=7184956)
Sep 28 20:11:18 neil-desktop kernel: [ 16.571912] Security Framework initialized
Sep 28 20:11:18 neil-desktop kernel: [ 16.571924] SELinux: Disabled at boot.
Sep 28 20:11:18 neil-desktop kernel: [ 16.571947] AppArmor: AppArmor initialized
Sep 28 20:11:18 neil-desktop kernel: [ 16.571954] Failure registering capabilities with primary security module.
Sep 28 20:11:18 neil-desktop kernel: [ 16.571967] Mount-cache hash table entries: 512
Sep 28 20:11:18 neil-desktop kernel: [ 16.572200] Initializing cgroup subsys ns
Sep 28 20:11:18 neil-desktop kernel: [ 16.572208] Initializing cgroup subsys cpuacct
Sep 28 20:11:18 neil-desktop kernel: [ 16.572228] CPU: After generic identify, caps: 3febfbff 00000000 00000000 00000000 00000000 00000000 00000000 00000000
Sep 28 20:11:18 neil-desktop kernel: [ 16.572248] CPU: Trace cache: 12K uops, L1 D cache: 8K
Sep 28 20:11:18 neil-desktop kernel: [ 16.572252] CPU: L2 cache: 256K
Sep 28 20:11:18 neil-desktop kernel: [ 16.572256] CPU: Hyper-Threading is disabled
Sep 28 20:11:18 neil-desktop kernel: [ 16.572262] CPU: After all inits, caps: 3febfbff 00000000 00000000 00043080 00000000 00000000 00000000 00000000
Sep 28 20:11:18 neil-desktop kernel: [ 16.572283] Compat vDSO mapped to ffffe000.
Sep 28 20:11:18 neil-desktop kernel: [ 16.572308] Checking 'hlt' instruction... OK.
Sep 28 20:11:18 neil-desktop kernel: [ 16.588493] SMP alternatives: switching to UP code
Sep 28 20:11:18 neil-desktop kernel: [ 16.591110] Freeing SMP alternatives: 11k freed
Sep 28 20:11:18 neil-desktop kernel: [ 16.591364] Early unpacking initramfs... done
Sep 28 20:11:18 neil-desktop kernel: [ 17.097213] ACPI: Core revision 20070126
Sep 28 20:11:18 neil-desktop kernel: [ 17.097322] ACPI: Looking for DSDT in initramfs... error, file /DSDT.aml not found.
Sep 28 20:11:18 neil-desktop kernel: [ 17.102277] CPU0: Intel(R) Pentium(R) 4 CPU 1.80GHz stepping 02
Sep 28 20:11:18 neil-desktop kernel: [ 17.102333] Total of 1 processors activated (3592.47 BogoMIPS).
Sep 28 20:11:18 neil-desktop kernel: [ 17.102486] ENABLING IO-APIC IRQs
Sep 28 20:11:18 neil-desktop kernel: [ 17.102683] ..TIMER: vector=0x31 apic1=0 pin1=2 apic2=-1 pin2=-1
Sep 28 20:11:18 neil-desktop kernel: [ 17.247188] Brought up 1 CPUs
Sep 28 20:11:18 neil-desktop kernel: [ 17.247229] CPU0 attaching sched-domain:
Sep 28 20:11:18 neil-desktop kernel: [ 17.247235] domain 0: span 01
Sep 28 20:11:18 neil-desktop kernel: [ 17.247238] groups: 01
Sep 28 20:11:18 neil-desktop kernel: [ 17.247624] net_namespace: 64 bytes
Sep 28 20:11:18 neil-desktop kernel: [ 17.247637] Booting paravirtualized kernel on bare hardware
Sep 28 20:11:18 neil-desktop kernel: [ 17.248546] Time: 19:10:47 Date: 09/28/09
Sep 28 20:11:18 neil-desktop kernel: [ 17.248603] NET: Registered protocol family 16
Sep 28 20:11:18 neil-desktop kernel: [ 17.249033] EISA bus registered
Sep 28 20:11:18 neil-desktop kernel: [ 17.249075] ACPI: bus type pci registered
Sep 28 20:11:18 neil-desktop kernel: [ 17.249861] PCI: PCI BIOS revision 2.10 entry at 0xfd933, last bus=2
Sep 28 20:11:18 neil-desktop kernel: [ 17.249866] PCI: Using configuration type 1
Sep 28 20:11:18 neil-desktop kernel: [ 17.249875] Setting up standard PCI resources
Sep 28 20:11:18 neil-desktop kernel: [ 17.265322] ACPI: EC: Look up EC in DSDT
Sep 28 20:11:18 neil-desktop kernel: [ 17.285302] ACPI: Interpreter enabled
Sep 28 20:11:18 neil-desktop kernel: [ 17.285312] ACPI: (supports S0 S1 S3 S4 S5)
Sep 28 20:11:18 neil-desktop kernel: [ 17.285340] ACPI: Using IOAPIC for interrupt routing
Sep 28 20:11:18 neil-desktop kernel: [ 17.328288] ACPI: PCI Root Bridge [PCI0] (0000:00)
Sep 28 20:11:18 neil-desktop kernel: [ 17.328620] PCI quirk: region 1000-107f claimed by ICH4 ACPI/GPIO/TCO
Sep 28 20:11:18 neil-desktop kernel: [ 17.328626] PCI quirk: region 1180-11bf claimed by ICH4 GPIO
Sep 28 20:11:18 neil-desktop kernel: [ 17.329325] PCI: Transparent bridge - 0000:00:1e.0
Sep 28 20:11:18 neil-desktop kernel: [ 17.329363] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0._PRT]
Sep 28 20:11:18 neil-desktop kernel: [ 17.329577] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.AGP_._PRT]
Sep 28 20:11:18 neil-desktop kernel: [ 17.329694] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.SLOT._PRT]
Sep 28 20:11:18 neil-desktop kernel: [ 17.353771] ACPI: PCI Interrupt Link [LNKA] (IRQs 3 4 *5 7 9 10 11 12 14 15)
Sep 28 20:11:18 neil-desktop kernel: [ 17.353891] ACPI: PCI Interrupt Link [LNKB] (IRQs 3 4 5 7 9 10 *11 12 14 15)
Sep 28 20:11:18 neil-desktop kernel: [ 17.354001] ACPI: PCI Interrupt Link [LNKC] (IRQs 3 4 5 7 9 10 11 12 14 15) *0, disabled.
Sep 28 20:11:18 neil-desktop kernel: [ 17.354113] ACPI: PCI Interrupt Link [LNKD] (IRQs 3 4 5 7 9 10 *11 12 14 15)
Sep 28 20:11:18 neil-desktop kernel: [ 17.354227] ACPI: PCI Interrupt Link [LNKE] (IRQs 3 4 5 7 9 10 *11 12 14 15)
Sep 28 20:11:18 neil-desktop kernel: [ 17.354342] ACPI: PCI Interrupt Link [LNKF] (IRQs 3 4 5 7 9 10 11 12 14 15) *0, disabled.
Sep 28 20:11:18 neil-desktop kernel: [ 17.354460] ACPI: PCI Interrupt Link [LNKG] (IRQs 3 4 5 7 9 10 11 12 14 15) *0, disabled.
Sep 28 20:11:18 neil-desktop kernel: [ 17.354577] ACPI: PCI Interrupt Link [LNKH] (IRQs 3 4 5 7 9 *10 11 12 14 15)
Sep 28 20:11:18 neil-desktop kernel: [ 17.354867] Linux Plug and Play Support v0.97 (c) Adam Belay
Sep 28 20:11:18 neil-desktop kernel: [ 17.354956] pnp: PnP ACPI init
Sep 28 20:11:18 neil-desktop kernel: [ 17.354976] ACPI: bus type pnp registered
Sep 28 20:11:18 neil-desktop kernel: [ 17.420108] pnp: PnP ACPI: found 15 devices
Sep 28 20:11:18 neil-desktop kernel: [ 17.420119] ACPI: ACPI bus type pnp unregistered
Sep 28 20:11:18 neil-desktop kernel: [ 17.420126] PnPBIOS: Disabled by ACPI PNP
Sep 28 20:11:18 neil-desktop kernel: [ 17.420723] PCI: Using ACPI for IRQ routing
Sep 28 20:11:18 neil-desktop kernel: [ 17.420732] PCI: If a device doesn't work, try "pci=routeirq". If it helps, post a report
Sep 28 20:11:18 neil-desktop kernel: [ 17.438838] NET: Registered protocol family 8
Sep 28 20:11:18 neil-desktop kernel: [ 17.438843] NET: Registered protocol family 20
Sep 28 20:11:18 neil-desktop kernel: [ 17.439009] AppArmor: AppArmor Filesystem Enabled
Sep 28 20:11:18 neil-desktop kernel: [ 17.442815] Time: tsc clocksource has been installed.
Sep 28 20:11:18 neil-desktop kernel: [ 17.450919] system 00:01: ioport range 0x4d0-0x4d1 has been reserved
Sep 28 20:11:18 neil-desktop kernel: [ 17.450926] system 00:01: ioport range 0xfe00-0xfe00 has been reserved
Sep 28 20:11:18 neil-desktop kernel: [ 17.450930] system 00:01: ioport range 0x800-0x84f has been reserved
Sep 28 20:11:18 neil-desktop kernel: [ 17.450936] system 00:01: ioport range 0x1000-0x107f has been reserved
Sep 28 20:11:18 neil-desktop kernel: [ 17.450941] system 00:01: ioport range 0x1180-0x11bf has been reserved
Sep 28 20:11:18 neil-desktop kernel: [ 17.450949] system 00:01: iomem range 0xfec00000-0xfec000ff could not be reserved
Sep 28 20:11:18 neil-desktop kernel: [ 17.481827] PCI: Bridge: 0000:00:01.0
Sep 28 20:11:18 neil-desktop kernel: [ 17.481832] IO window: disabled.
Sep 28 20:11:18 neil-desktop kernel: [ 17.481840] MEM window: f0000000-f1ffffff
Sep 28 20:11:18 neil-desktop kernel: [ 17.481845] PREFETCH window: f8000000-faffffff
Sep 28 20:11:18 neil-desktop kernel: [ 17.481852] PCI: Bridge: 0000:00:1e.0
Sep 28 20:11:18 neil-desktop kernel: [ 17.481856] IO window: 2000-2fff
Sep 28 20:11:18 neil-desktop kernel: [ 17.481863] MEM window: f2000000-f20fffff
Sep 28 20:11:18 neil-desktop kernel: [ 17.481868] PREFETCH window: disabled.
Sep 28 20:11:18 neil-desktop kernel: [ 17.481892] PCI: Setting latency timer of device 0000:00:1e.0 to 64
Sep 28 20:11:18 neil-desktop kernel: [ 17.481920] NET: Registered protocol family 2
Sep 28 20:11:18 neil-desktop kernel: [ 17.518880] IP route cache hash table entries: 2048 (order: 1, 8192 bytes)
Sep 28 20:11:18 neil-desktop kernel: [ 17.519279] TCP established hash table entries: 8192 (order: 4, 65536 bytes)
Sep 28 20:11:18 neil-desktop kernel: [ 17.519368] TCP bind hash table entries: 8192 (order: 4, 65536 bytes)
Sep 28 20:11:18 neil-desktop kernel: [ 17.519460] TCP: Hash tables configured (established 8192 bind 8192)
Sep 28 20:11:18 neil-desktop kernel: [ 17.519464] TCP reno registered
Sep 28 20:11:18 neil-desktop kernel: [ 17.530986] checking if image is initramfs...<7>Switched to high resolution mode on CPU 0
Sep 28 20:11:18 neil-desktop kernel: [ 17.989952] it is
Sep 28 20:11:18 neil-desktop kernel: [ 18.512801] Freeing initrd memory: 7311k freed
Sep 28 20:11:18 neil-desktop kernel: [ 18.513168] Simple Boot Flag at 0x72 set to 0x1
Sep 28 20:11:18 neil-desktop kernel: [ 18.514008] audit: initializing netlink socket (disabled)
Sep 28 20:11:18 neil-desktop kernel: [ 18.514036] audit(1254165047.920:1): initialized
Sep 28 20:11:18 neil-desktop kernel: [ 18.517953] VFS: Disk quotas dquot_6.5.1
Sep 28 20:11:18 neil-desktop kernel: [ 18.518125] Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
Sep 28 20:11:18 neil-desktop kernel: [ 18.518422] io scheduler noop registered
Sep 28 20:11:18 neil-desktop kernel: [ 18.518427] io scheduler anticipatory registered
Sep 28 20:11:18 neil-desktop kernel: [ 18.518430] io scheduler deadline registered
Sep 28 20:11:18 neil-desktop kernel: [ 18.518460] io scheduler cfq registered (default)
Sep 28 20:11:18 neil-desktop kernel: [ 18.518538] Boot video device is 0000:01:00.0
Sep 28 20:11:18 neil-desktop kernel: [ 18.518549] PCI: Firmware left 0000:02:08.0 e100 interrupts enabled, disabling
Sep 28 20:11:18 neil-desktop kernel: [ 18.519153] isapnp: Scanning for PnP cards...
Sep 28 20:11:18 neil-desktop kernel: [ 18.873068] isapnp: No Plug & Play device found
Sep 28 20:11:18 neil-desktop kernel: [ 18.987725] Real Time Clock Driver v1.12ac
Sep 28 20:11:18 neil-desktop kernel: [ 18.987911] Serial: 8250/16550 driver $Revision: 1.90 $ 4 ports, IRQ sharing enabled
Sep 28 20:11:18 neil-desktop kernel: [ 18.988111] serial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
Sep 28 20:11:18 neil-desktop kernel: [ 18.988475] serial8250: ttyS1 at I/O 0x2f8 (irq = 3) is a 16550A
Sep 28 20:11:18 neil-desktop kernel: [ 18.990304] 00:0c: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
Sep 28 20:11:18 neil-desktop kernel: [ 18.991183] 00:0d: ttyS1 at I/O 0x2f8 (irq = 3) is a 16550A
Sep 28 20:11:18 neil-desktop kernel: [ 18.992866] RAMDISK driver initialized: 16 RAM disks of 65536K size 1024 blocksize
Sep 28 20:11:18 neil-desktop kernel: [ 18.993020] input: Macintosh mouse button emulation as /devices/virtual/input/input0
Sep 28 20:11:18 neil-desktop kernel: [ 18.993245] PNP: PS/2 Controller [PNP0303:KBC,PNP0f13:PSM] at 0x60,0x64 irq 1,12
Sep 28 20:11:18 neil-desktop kernel: [ 18.994903] serio: i8042 KBD port at 0x60,0x64 irq 1
Sep 28 20:11:18 neil-desktop kernel: [ 18.994913] serio: i8042 AUX port at 0x60,0x64 irq 12
Sep 28 20:11:18 neil-desktop kernel: [ 18.997125] mice: PS/2 mouse device common for all mice
Sep 28 20:11:18 neil-desktop kernel: [ 18.997392] EISA: Probing bus 0 at eisa.0
Sep 28 20:11:18 neil-desktop kernel: [ 18.997405] Cannot allocate resource for EISA slot 1
Sep 28 20:11:18 neil-desktop kernel: [ 18.997409] Cannot allocate resource for EISA slot 2
Sep 28 20:11:18 neil-desktop kernel: [ 18.997437] EISA: Detected 0 cards.
Sep 28 20:11:18 neil-desktop kernel: [ 18.997443] cpuidle: using governor ladder
Sep 28 20:11:18 neil-desktop kernel: [ 18.997447] cpuidle: using governor menu
Sep 28 20:11:18 neil-desktop kernel: [ 18.997624] NET: Registered protocol family 1
Sep 28 20:11:18 neil-desktop kernel: [ 18.997678] Using IPI No-Shortcut mode
Sep 28 20:11:18 neil-desktop kernel: [ 18.997745] registered taskstats version 1
Sep 28 20:11:18 neil-desktop kernel: [ 18.997875] Magic number: 9:754:193
Sep 28 20:11:18 neil-desktop kernel: [ 18.997941] hash matches device ttys5
Sep 28 20:11:18 neil-desktop kernel: [ 18.998073] BIOS EDD facility v0.16 2004-Jun-25, 0 devices found
Sep 28 20:11:18 neil-desktop kernel: [ 18.998076] EDD information not available.
Sep 28 20:11:18 neil-desktop kernel: [ 18.998910] Freeing unused kernel memory: 368k freed
Sep 28 20:11:18 neil-desktop kernel: [ 18.998957] Write protecting the kernel read-only data: 802k
Sep 28 20:11:18 neil-desktop kernel: [ 19.018823] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1
Sep 28 20:11:18 neil-desktop kernel: [ 20.465492] fuse init (API version 7.9)
Sep 28 20:11:18 neil-desktop kernel: [ 20.510579] ACPI: Processor [CPU0] (supports 8 throttling states)
Sep 28 20:11:18 neil-desktop kernel: [ 20.514043] ACPI: Thermal Zone [THM0] (19 C)
Sep 28 20:11:18 neil-desktop kernel: [ 21.443299] e100: Intel(R) PRO/100 Network Driver, 3.5.23-k4-NAPI
Sep 28 20:11:18 neil-desktop kernel: [ 21.443306] e100: Copyright(c) 1999-2006 Intel Corporation
Sep 28 20:11:18 neil-desktop kernel: [ 21.443420] ACPI: PCI Interrupt 0000:02:08.0[A] -> GSI 20 (level, low) -> IRQ 16
Sep 28 20:11:18 neil-desktop kernel: [ 21.570634] SCSI subsystem initialized
Sep 28 20:11:18 neil-desktop kernel: [ 21.579742] e100: eth0: e100_probe: addr 0xf2000000, irq 16, MAC addr 00:09:6b:54:0e:f7
Sep 28 20:11:18 neil-desktop kernel: [ 21.615462] usbcore: registered new interface driver usbfs
Sep 28 20:11:18 neil-desktop kernel: [ 21.615505] usbcore: registered new interface driver hub
Sep 28 20:11:18 neil-desktop kernel: [ 21.621481] usbcore: registered new device driver usb
Sep 28 20:11:18 neil-desktop kernel: [ 21.648682] USB Universal Host Controller Interface driver v3.0
Sep 28 20:11:18 neil-desktop kernel: [ 21.648835] ACPI: PCI Interrupt 0000:00:1f.2[D] -> GSI 19 (level, low) -> IRQ 17
Sep 28 20:11:18 neil-desktop kernel: [ 21.648856] PCI: Setting latency timer of device 0000:00:1f.2 to 64
Sep 28 20:11:18 neil-desktop kernel: [ 21.648862] uhci_hcd 0000:00:1f.2: UHCI Host Controller
Sep 28 20:11:18 neil-desktop kernel: [ 21.649661] uhci_hcd 0000:00:1f.2: new USB bus registered, assigned bus number 1
Sep 28 20:11:18 neil-desktop kernel: [ 21.649712] uhci_hcd 0000:00:1f.2: irq 17, io base 0x00001820
Sep 28 20:11:18 neil-desktop kernel: [ 21.650014] usb usb1: configuration #1 chosen from 1 choice
Sep 28 20:11:18 neil-desktop kernel: [ 21.650057] hub 1-0:1.0: USB hub found
Sep 28 20:11:18 neil-desktop kernel: [ 21.650068] hub 1-0:1.0: 2 ports detected
Sep 28 20:11:18 neil-desktop kernel: [ 21.669894] libata version 3.00 loaded.
Sep 28 20:11:18 neil-desktop kernel: [ 21.753411] ACPI: PCI Interrupt 0000:00:1f.4[C] -> GSI 23 (level, low) -> IRQ 18
Sep 28 20:11:18 neil-desktop kernel: [ 21.753434] PCI: Setting latency timer of device 0000:00:1f.4 to 64
Sep 28 20:11:18 neil-desktop kernel: [ 21.753441] uhci_hcd 0000:00:1f.4: UHCI Host Controller
Sep 28 20:11:18 neil-desktop kernel: [ 21.753486] uhci_hcd 0000:00:1f.4: new USB bus registered, assigned bus number 2
Sep 28 20:11:18 neil-desktop kernel: [ 21.753526] uhci_hcd 0000:00:1f.4: irq 18, io base 0x00001840
Sep 28 20:11:18 neil-desktop kernel: [ 21.753737] usb usb2: configuration #1 chosen from 1 choice
Sep 28 20:11:18 neil-desktop kernel: [ 21.753778] hub 2-0:1.0: USB hub found
Sep 28 20:11:18 neil-desktop kernel: [ 21.753789] hub 2-0:1.0: 2 ports detected
Sep 28 20:11:18 neil-desktop kernel: [ 21.857250] ata_piix 0000:00:1f.1: version 2.12
Sep 28 20:11:18 neil-desktop kernel: [ 21.857363] PCI: Setting latency timer of device 0000:00:1f.1 to 64
Sep 28 20:11:18 neil-desktop kernel: [ 21.859114] Floppy drive(s): fd0 is 1.44M
Sep 28 20:11:18 neil-desktop kernel: [ 21.876622] FDC 0 is a National Semiconductor PC87306
Sep 28 20:11:18 neil-desktop kernel: [ 21.876916] scsi0 : ata_piix
Sep 28 20:11:18 neil-desktop kernel: [ 21.894460] scsi1 : ata_piix
Sep 28 20:11:18 neil-desktop kernel: [ 21.895646] ata1: PATA max UDMA/100 cmd 0x1f0 ctl 0x3f6 bmdma 0x1800 irq 14
Sep 28 20:11:18 neil-desktop kernel: [ 21.895652] ata2: PATA max UDMA/100 cmd 0x170 ctl 0x376 bmdma 0x1808 irq 15
Sep 28 20:11:18 neil-desktop kernel: [ 22.065480] ata1.00: ATA-5: IC35L040AVVN07-0, VA2OAF1A, max UDMA/100
Sep 28 20:11:18 neil-desktop kernel: [ 22.065489] ata1.00: 78156288 sectors, multi 16: LBA
Sep 28 20:11:18 neil-desktop kernel: [ 22.089355] ata1.00: configured for UDMA/100
Sep 28 20:11:18 neil-desktop kernel: [ 22.400467] ata2.01: NODEV after polling detection
Sep 28 20:11:18 neil-desktop kernel: [ 22.564673] ata2.00: ATAPI: SONY DVD RW DRU-810A, 1.0a, max UDMA/33
Sep 28 20:11:18 neil-desktop kernel: [ 22.736415] ata2.00: configured for UDMA/33
Sep 28 20:11:18 neil-desktop kernel: [ 22.736685] scsi 0:0:0:0: Direct-Access ATA IC35L040AVVN07-0 VA2O PQ: 0 ANSI: 5
Sep 28 20:11:18 neil-desktop kernel: [ 22.739114] scsi 1:0:0:0: CD-ROM SONY DVD RW DRU-810A 1.0a PQ: 0 ANSI: 5
Sep 28 20:11:18 neil-desktop kernel: [ 23.167131] Driver 'sd' needs updating - please use bus_type methods
Sep 28 20:11:18 neil-desktop kernel: [ 23.167351] sd 0:0:0:0: [sda] 78156288 512-byte hardware sectors (40016 MB)
Sep 28 20:11:18 neil-desktop kernel: [ 23.167377] sd 0:0:0:0: [sda] Write Protect is off
Sep 28 20:11:18 neil-desktop kernel: [ 23.167382] sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
Sep 28 20:11:18 neil-desktop kernel: [ 23.167417] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Sep 28 20:11:18 neil-desktop kernel: [ 23.167518] sd 0:0:0:0: [sda] 78156288 512-byte hardware sectors (40016 MB)
Sep 28 20:11:18 neil-desktop kernel: [ 23.167539] sd 0:0:0:0: [sda] Write Protect is off
Sep 28 20:11:18 neil-desktop kernel: [ 23.167543] sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
Sep 28 20:11:18 neil-desktop kernel: [ 23.167576] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Sep 28 20:11:18 neil-desktop kernel: [ 23.167584] sda:<4>Driver 'sr' needs updating - please use bus_type methods
Sep 28 20:11:18 neil-desktop kernel: [ 23.181343] sda1 sda2 < sda5 >
Sep 28 20:11:18 neil-desktop kernel: [ 23.197548] sd 0:0:0:0: [sda] Attached SCSI disk
Sep 28 20:11:18 neil-desktop kernel: [ 23.211096] sd 0:0:0:0: Attached scsi generic sg0 type 0
Sep 28 20:11:18 neil-desktop kernel: [ 23.211136] sr 1:0:0:0: Attached scsi generic sg1 type 5
Sep 28 20:11:18 neil-desktop kernel: [ 23.218018] sr0: scsi3-mmc drive: 40x/40x writer cd/rw xa/form2 cdda tray
Sep 28 20:11:18 neil-desktop kernel: [ 23.218029] Uniform CD-ROM driver Revision: 3.20
Sep 28 20:11:18 neil-desktop kernel: [ 23.218139] sr 1:0:0:0: Attached scsi CD-ROM sr0
Sep 28 20:11:18 neil-desktop kernel: [ 23.623226] Attempting manual resume
Sep 28 20:11:18 neil-desktop kernel: [ 23.623233] swsusp: Resume From Partition 8:5
Sep 28 20:11:18 neil-desktop kernel: [ 23.623236] PM: Checking swsusp image.
Sep 28 20:11:18 neil-desktop kernel: [ 23.623498] PM: Resume from disk failed.
Sep 28 20:11:18 neil-desktop kernel: [ 23.659366] EXT3-fs: INFO: recovery required on readonly filesystem.
Sep 28 20:11:18 neil-desktop kernel: [ 23.659374] EXT3-fs: write access will be enabled during recovery.
Sep 28 20:11:18 neil-desktop kernel: [ 28.176450] kjournald starting. Commit interval 5 seconds
Sep 28 20:11:18 neil-desktop kernel: [ 28.176493] EXT3-fs: sda1: orphan cleanup on readonly fs
Sep 28 20:11:18 neil-desktop kernel: [ 28.176506] ext3_orphan_cleanup: deleting unreferenced inode 697075
Sep 28 20:11:18 neil-desktop kernel: [ 28.176556] EXT3-fs: sda1: 1 orphan inode deleted
Sep 28 20:11:18 neil-desktop kernel: [ 28.176560] EXT3-fs: recovery complete.
Sep 28 20:11:18 neil-desktop kernel: [ 28.191598] EXT3-fs: mounted filesystem with ordered data mode.
Sep 28 20:11:18 neil-desktop kernel: [ 37.216698] Linux agpgart interface v0.102
Sep 28 20:11:18 neil-desktop kernel: [ 37.274415] pci_hotplug: PCI Hot Plug PCI Core version: 0.5
Sep 28 20:11:18 neil-desktop kernel: [ 37.324872] intel_rng: Firmware space is locked read-only. If you can't or
Sep 28 20:11:18 neil-desktop kernel: [ 37.324878] intel_rng: don't want to disable this in firmware setup, and if
Sep 28 20:11:18 neil-desktop kernel: [ 37.324880] intel_rng: you are certain that your system has a functional
Sep 28 20:11:18 neil-desktop kernel: [ 37.324882] intel_rng: RNG, try using the 'no_fwh_detect' option.
Sep 28 20:11:18 neil-desktop kernel: [ 37.468771] agpgart: Detected an Intel 845G Chipset.
Sep 28 20:11:18 neil-desktop kernel: [ 37.472928] agpgart: AGP aperture is 64M @ 0xf4000000
Sep 28 20:11:18 neil-desktop kernel: [ 37.540423] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4
Sep 28 20:11:18 neil-desktop kernel: [ 37.821471] iTCO_vendor_support: vendor-support=0
Sep 28 20:11:18 neil-desktop kernel: [ 37.858772] iTCO_wdt: Intel TCO WatchDog Timer Driver v1.02 (26-Jul-2007)
Sep 28 20:11:18 neil-desktop kernel: [ 37.858942] iTCO_wdt: Found a ICH2 TCO device (Version=1, TCOBASE=0x1060)
Sep 28 20:11:18 neil-desktop kernel: [ 37.858992] iTCO_wdt: initialized. heartbeat=30 sec (nowayout=0)
Sep 28 20:11:18 neil-desktop kernel: [ 37.907964] input: PC Speaker as /devices/platform/pcspkr/input/input2
Sep 28 20:11:18 neil-desktop kernel: [ 37.940024] input: Power Button (FF) as /devices/virtual/input/input3
Sep 28 20:11:18 neil-desktop kernel: [ 37.951726] ACPI: Power Button (FF) [PWRF]
Sep 28 20:11:18 neil-desktop kernel: [ 37.951989] input: Power Button (CM) as /devices/virtual/input/input4
Sep 28 20:11:18 neil-desktop kernel: [ 37.963657] ACPI: Power Button (CM) [PWRB]
Sep 28 20:11:18 neil-desktop kernel: [ 38.688244] input: PS/2 Logitech Mouse as /devices/platform/i8042/serio1/input/input5
Sep 28 20:11:18 neil-desktop kernel: [ 40.185034] ACPI: PCI Interrupt 0000:00:1f.5[B] -> GSI 17 (level, low) -> IRQ 19
Sep 28 20:11:18 neil-desktop kernel: [ 40.185066] PCI: Setting latency timer of device 0000:00:1f.5 to 64
Sep 28 20:11:18 neil-desktop kernel: [ 40.720372] parport_pc 00:0e: reported by Plug and Play ACPI
Sep 28 20:11:18 neil-desktop kernel: [ 40.720461] parport0: PC-style at 0x378 (0x778), irq 7, dma 3 [PCSPP,TRISTATE,COMPAT,ECP,DMA]
Sep 28 20:11:18 neil-desktop kernel: [ 40.800189] intel8x0_measure_ac97_clock: measured 53927 usecs
Sep 28 20:11:18 neil-desktop kernel: [ 40.800197] intel8x0: clocking to 41142
Sep 28 20:11:18 neil-desktop kernel: [ 43.900982] lp0: using parport0 (interrupt-driven).
Sep 28 20:11:18 neil-desktop kernel: [ 44.005408] Adding 746980k swap on /dev/sda5. Priority:-1 extents:1 across:746980k
Sep 28 20:11:18 neil-desktop kernel: [ 44.610898] EXT3 FS on sda1, internal journal
Sep 28 20:11:18 neil-desktop kernel: [ 45.939793] ip_tables: (C) 2000-2006 Netfilter Core Team
Sep 28 20:11:18 neil-desktop kernel: [ 46.634244] No dock devices found.
Sep 28 20:11:18 neil-desktop NetworkManager: <info> starting...
Sep 28 20:11:18 neil-desktop avahi-daemon[4682]: Found user 'avahi' (UID 109) and group 'avahi' (GID 120).
Sep 28 20:11:18 neil-desktop avahi-daemon[4682]: Successfully dropped root privileges.
Sep 28 20:11:18 neil-desktop avahi-daemon[4682]: avahi-daemon 0.6.22 starting up.
Sep 28 20:11:18 neil-desktop avahi-daemon[4682]: Successfully called chroot().
Sep 28 20:11:18 neil-desktop avahi-daemon[4682]: Successfully dropped remaining capabilities.
Sep 28 20:11:18 neil-desktop avahi-daemon[4682]: No service file found in /etc/avahi/services.
Sep 28 20:11:18 neil-desktop avahi-daemon[4682]: Network interface enumeration completed.
Sep 28 20:11:18 neil-desktop avahi-daemon[4682]: Registering HINFO record with values 'I686'/'LINUX'.
Sep 28 20:11:18 neil-desktop avahi-daemon[4682]: Server startup complete. Host name is neil-desktop.local. Local service cookie is 511159513.
Sep 28 20:11:18 neil-desktop kernel: [ 48.248294] IBM machine detected. Enabling interrupts during APM calls.
Sep 28 20:11:18 neil-desktop kernel: [ 48.248305] apm: BIOS version 1.2 Flags 0x03 (Driver version 1.16ac)
Sep 28 20:11:18 neil-desktop kernel: [ 48.248310] apm: overridden by ACPI.
Sep 28 20:11:18 neil-desktop kernel: [ 48.375361] ppdev: user-space parallel port driver
Sep 28 20:11:18 neil-desktop kernel: [ 48.497825] audit(1254165078.773:2): type=1503 operation="inode_permission" requested_mask="a::" denied_mask="a::" name="/dev/tty" pid=4721 profile="/usr/sbin/cupsd" namespace="default"
Sep 28 20:11:18 neil-desktop dhcdbd: Started up.
Sep 28 20:11:19 neil-desktop kernel: [ 49.648308] e100: eth0: e100_watchdog: link up, 100Mbps, full-duplex
Sep 28 20:11:19 neil-desktop NetworkManager: <info> eth0: Device is fully-supported using driver 'e100'.
Sep 28 20:11:19 neil-desktop NetworkManager: <info> nm_device_init(): waiting for device's worker thread to start
Sep 28 20:11:19 neil-desktop NetworkManager: <info> nm_device_init(): device's worker thread started, continuing.
Sep 28 20:11:19 neil-desktop NetworkManager: <info> Now managing wired Ethernet (802.3) device 'eth0'.
Sep 28 20:11:19 neil-desktop NetworkManager: <info> Deactivating device eth0.
Sep 28 20:11:19 neil-desktop NetworkManager: <info> Will activate wired connection 'eth0' because it now has a link.
Sep 28 20:11:19 neil-desktop NetworkManager: <info> Will activate wired connection 'eth0' because it now has a link.
Sep 28 20:11:19 neil-desktop NetworkManager: <debug> [1254165079.946993] nm_hal_device_added(): New device added (hal udi is '/org/freedesktop/Hal/devices/storage_model_DVD_RW_DRU_810A').
Sep 28 20:11:19 neil-desktop NetworkManager: <info> SWITCH: no current connection, found better connection 'eth0'.
Sep 28 20:11:20 neil-desktop hcid[4960]: Bluetooth HCI daemon
Sep 28 20:11:20 neil-desktop kernel: [ 49.863862] Bluetooth: Core ver 2.11
Sep 28 20:11:20 neil-desktop kernel: [ 49.865296] NET: Registered protocol family 31
Sep 28 20:11:20 neil-desktop kernel: [ 49.865305] Bluetooth: HCI device and connection manager initialized
Sep 28 20:11:20 neil-desktop kernel: [ 49.865312] Bluetooth: HCI socket layer initialized
Sep 28 20:11:20 neil-desktop hcid[4960]: Starting SDP server
Sep 28 20:11:20 neil-desktop kernel: [ 49.928400] Bluetooth: L2CAP ver 2.9
Sep 28 20:11:20 neil-desktop kernel: [ 49.928409] Bluetooth: L2CAP socket layer initialized
Sep 28 20:11:20 neil-desktop hcid[4960]: Created local server at unix:abstract=/var/run/dbus-eIYjHhIA3P,guid=e2941555aa8691ddf73383c84ac10a58
Sep 28 20:11:20 neil-desktop audio[4981]: Bluetooth Audio daemon
Sep 28 20:11:20 neil-desktop audio[4981]: Unix socket created: 5
Sep 28 20:11:20 neil-desktop audio[4981]: audio.conf: Key file does not have key 'Enable'
Sep 28 20:11:20 neil-desktop audio[4981]: audio.conf: Key file does not have key 'Disable'
Sep 28 20:11:20 neil-desktop input[4984]: Bluetooth Input daemon
Sep 28 20:11:20 neil-desktop input[4984]: Registered input manager path:/org/bluez/input
Sep 28 20:11:20 neil-desktop kernel: [ 50.002225] Bluetooth: RFCOMM socket layer initialized
Sep 28 20:11:20 neil-desktop kernel: [ 50.002264] Bluetooth: RFCOMM TTY layer initialized
Sep 28 20:11:20 neil-desktop kernel: [ 50.002267] Bluetooth: RFCOMM ver 1.8
Sep 28 20:11:20 neil-desktop audio[4981]: add_service_record: got record id 0x10000
Sep 28 20:11:20 neil-desktop audio[4981]: audio.conf: Key file does not have key 'Disable'
Sep 28 20:11:20 neil-desktop audio[4981]: audio.conf: Key file does not have group 'A2DP'
Sep 28 20:11:20 neil-desktop last message repeated 3 times
Sep 28 20:11:20 neil-desktop audio[4981]: SEP 0x806d348 registered: type:0 codec:0 seid:1
Sep 28 20:11:20 neil-desktop audio[4981]: add_service_record: got record id 0x10001
Sep 28 20:11:20 neil-desktop audio[4981]: add_service_record: got record id 0x10002
Sep 28 20:11:20 neil-desktop audio[4981]: add_service_record: got record id 0x10003
Sep 28 20:11:20 neil-desktop audio[4981]: Registered manager path:/org/bluez/audio
Sep 28 20:11:21 neil-desktop anacron[5057]: Anacron 2.3 started on 2009-09-28
Sep 28 20:11:21 neil-desktop anacron[5057]: Normal exit (0 jobs run)
Sep 28 20:11:21 neil-desktop /usr/sbin/cron[5084]: (CRON) INFO (pidfile fd = 3)
Sep 28 20:11:21 neil-desktop /usr/sbin/cron[5085]: (CRON) STARTUP (fork ok)
Sep 28 20:11:21 neil-desktop /usr/sbin/cron[5085]: (CRON) INFO (Running @reboot jobs)
Sep 28 20:11:21 neil-desktop dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/eth0 for sub-path eth0.dbus.get.reason
Sep 28 20:11:21 neil-desktop NetworkManager: <info> Will activate connection 'eth0'.
Sep 28 20:11:21 neil-desktop NetworkManager: <info> Device eth0 activation scheduled...
Sep 28 20:11:21 neil-desktop NetworkManager: <debug> [1254165081.967431] nm_hal_device_added(): New device added (hal udi is '/org/freedesktop/Hal/devices/platform_bluetooth').
Sep 28 20:11:21 neil-desktop NetworkManager: <info> Activation (eth0) started...
Sep 28 20:11:21 neil-desktop NetworkManager: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) scheduled...
Sep 28 20:11:21 neil-desktop NetworkManager: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) started...
Sep 28 20:11:21 neil-desktop NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) scheduled...
Sep 28 20:11:21 neil-desktop NetworkManager: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) complete.
Sep 28 20:11:21 neil-desktop NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) starting...
Sep 28 20:11:21 neil-desktop NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) successful.
Sep 28 20:11:21 neil-desktop NetworkManager: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) scheduled.
Sep 28 20:11:21 neil-desktop NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) complete.
Sep 28 20:11:21 neil-desktop NetworkManager: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) started...
Sep 28 20:11:22 neil-desktop NetworkManager: <info> Activation (eth0) Beginning DHCP transaction.
Sep 28 20:11:22 neil-desktop NetworkManager: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) complete.
Sep 28 20:11:22 neil-desktop NetworkManager: <info> DHCP daemon state is now 12 (successfully started) for interface eth0
Sep 28 20:11:24 neil-desktop NetworkManager: <info> DHCP daemon state is now 1 (starting) for interface eth0
Sep 28 20:11:24 neil-desktop kernel: [ 53.861590] NET: Registered protocol family 17
Sep 28 20:11:24 neil-desktop dhclient: DHCPREQUEST of 192.168.1.101 on eth0 to 255.255.255.255 port 67
Sep 28 20:11:24 neil-desktop dhclient: DHCPACK of 0.0.0.0 from 192.168.1.1
Sep 28 20:11:24 neil-desktop NetworkManager: <info> DHCP daemon state is now 4 (reboot) for interface eth0
Sep 28 20:11:24 neil-desktop NetworkManager: <info> Activation (eth0) Stage 4 of 5 (IP Configure Get) scheduled...
Sep 28 20:11:24 neil-desktop NetworkManager: <info> Activation (eth0) Stage 4 of 5 (IP Configure Get) started...
Sep 28 20:11:24 neil-desktop dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/eth0 for sub-path eth0.dbus.get.host_name
Sep 28 20:11:24 neil-desktop dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/eth0 for sub-path eth0.dbus.get.nis_domain
Sep 28 20:11:24 neil-desktop dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/eth0 for sub-path eth0.dbus.get.nis_servers
Sep 28 20:11:24 neil-desktop NetworkManager: <info> Retrieved the following IP4 configuration from the DHCP daemon:
Sep 28 20:11:24 neil-desktop NetworkManager: <info> address 0.0.0.0
Sep 28 20:11:24 neil-desktop NetworkManager: <info> netmask 255.255.255.0
Sep 28 20:11:24 neil-desktop NetworkManager: <info> broadcast 0.0.0.255
Sep 28 20:11:24 neil-desktop NetworkManager: <info> gateway 192.168.1.1
Sep 28 20:11:24 neil-desktop NetworkManager: <info> nameserver 192.168.1.1
Sep 28 20:11:24 neil-desktop NetworkManager: <info> domain name 'home'
Sep 28 20:11:24 neil-desktop dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/eth0 for sub-path eth0.dbus.get.interface_mtu
Sep 28 20:11:24 neil-desktop NetworkManager: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) scheduled...
Sep 28 20:11:24 neil-desktop NetworkManager: <info> Activation (eth0) Stage 4 of 5 (IP Configure Get) complete.
Sep 28 20:11:24 neil-desktop NetworkManager: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) started...
Sep 28 20:11:24 neil-desktop NetworkManager: <info> not touching eth0 configuration, was configured externally
Sep 28 20:11:24 neil-desktop NetworkManager: <info> Activation (eth0) Finish handler scheduled.
Sep 28 20:11:24 neil-desktop NetworkManager: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) complete.
Sep 28 20:11:24 neil-desktop NetworkManager: <info> Activation (eth0) successful, device activated.
Sep 28 20:11:24 neil-desktop dhclient: bound to 0.0.0.0 -- renewal in 42386 seconds.
Sep 28 20:11:24 neil-desktop kernel: [ 54.517410] NET: Registered protocol family 10
Sep 28 20:11:24 neil-desktop kernel: [ 54.518457] lo: Disabled Privacy Extensions
Sep 28 20:11:24 neil-desktop ntpdate[5244]: can't find host ntp.ubuntu.com
Sep 28 20:11:24 neil-desktop ntpdate[5244]: no servers can be used, exiting
Sep 28 20:11:26 neil-desktop avahi-daemon[4682]: Registering new address record for fe80::209:6bff:fe54:ef7 on eth0.*.
Sep 28 20:11:35 neil-desktop kernel: [ 64.860020] eth0: no IPv6 routers present
Sep 28 20:11:40 neil-desktop hcid[4960]: Default passkey agent (:1.21, /org/bluez/passkey) registered
Sep 28 20:11:40 neil-desktop hcid[4960]: Default authorization agent (:1.21, /org/bluez/auth) registered
Sep 28 20:11:48 neil-desktop NetworkManager: <info> Updating allowed wireless network lists.
Sep 28 20:11:49 neil-desktop NetworkManager: <WARN> nm_dbus_get_networks_cb(): error received: org.freedesktop.NetworkManagerInfo.NoNetworks - There are no wireless networks stored..
Sep 28 20:14:12 neil-desktop kernel: [ 222.140090] e100: eth0: e100_watchdog: link down
Sep 28 20:14:12 neil-desktop NetworkManager: <info> SWITCH: terminating current connection 'eth0' because it's no longer valid.
Sep 28 20:14:12 neil-desktop NetworkManager: <info> Deactivating device eth0.
Sep 28 20:14:12 neil-desktop dhclient: There is already a pid file /var/run/dhclient.eth0.pid with pid 5181
Sep 28 20:14:12 neil-desktop dhclient: killed old client process, removed PID file
Sep 28 20:14:13 neil-desktop dhclient: DHCPRELEASE on eth0 to 192.168.1.1 port 67
Sep 28 20:14:13 neil-desktop dhclient: send_packet: Network is unreachable
Sep 28 20:14:13 neil-desktop dhclient: send_packet: please consult README file regarding broadcast address.
Sep 28 20:14:13 neil-desktop NetworkManager: nm_device_is_802_3_ethernet: assertion `dev != NULL' failed
Sep 28 20:14:13 neil-desktop NetworkManager: nm_device_is_802_11_wireless: assertion `dev != NULL' failed
Sep 28 20:14:13 neil-desktop avahi-daemon[4682]: Withdrawing address record for fe80::209:6bff:fe54:ef7 on eth0.
Sep 28 20:14:22 neil-desktop kernel: [ 232.126671] e100: eth0: e100_watchdog: link up, 100Mbps, full-duplex
Sep 28 20:14:22 neil-desktop NetworkManager: <info> Will activate wired connection 'eth0' because it now has a link.
Sep 28 20:14:22 neil-desktop kernel: [ 232.127512] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Sep 28 20:14:22 neil-desktop NetworkManager: <info> SWITCH: no current connection, found better connection 'eth0'.
Sep 28 20:14:22 neil-desktop NetworkManager: <info> Will activate connection 'eth0'.
Sep 28 20:14:22 neil-desktop NetworkManager: <info> Device eth0 activation scheduled...
Sep 28 20:14:22 neil-desktop NetworkManager: <info> Activation (eth0) started...
Sep 28 20:14:22 neil-desktop NetworkManager: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) scheduled...
Sep 28 20:14:22 neil-desktop NetworkManager: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) started...
Sep 28 20:14:22 neil-desktop NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) scheduled...
Sep 28 20:14:22 neil-desktop NetworkManager: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) complete.
Sep 28 20:14:22 neil-desktop NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) starting...
Sep 28 20:14:22 neil-desktop NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) successful.
Sep 28 20:14:22 neil-desktop NetworkManager: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) scheduled.
Sep 28 20:14:22 neil-desktop NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) complete.
Sep 28 20:14:22 neil-desktop NetworkManager: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) started...
Sep 28 20:14:23 neil-desktop NetworkManager: <info> Activation (eth0) Beginning DHCP transaction.
Sep 28 20:14:23 neil-desktop dhclient: There is already a pid file /var/run/dhclient.eth0.pid with pid 134519072
Sep 28 20:14:23 neil-desktop NetworkManager: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) complete.
Sep 28 20:14:23 neil-desktop NetworkManager: <info> DHCP daemon state is now 12 (successfully started) for interface eth0
Sep 28 20:14:23 neil-desktop avahi-daemon[4682]: Registering new address record for fe80::209:6bff:fe54:ef7 on eth0.*.
Sep 28 20:14:24 neil-desktop NetworkManager: <info> DHCP daemon state is now 1 (starting) for interface eth0
Sep 28 20:14:27 neil-desktop dhclient: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 3
Sep 28 20:14:28 neil-desktop kernel: [ 238.118941] e100: eth0: e100_watchdog: link down
Sep 28 20:14:28 neil-desktop NetworkManager: <info> SWITCH: terminating current connection 'eth0' because it's no longer valid.
Sep 28 20:14:28 neil-desktop NetworkManager: <info> Deactivating device eth0.
Sep 28 20:14:28 neil-desktop NetworkManager: <info> Activation (eth0): cancelling...
Sep 28 20:14:28 neil-desktop NetworkManager: <info> Activation (eth0) cancellation handler scheduled...
Sep 28 20:14:28 neil-desktop NetworkManager: <info> Activation (eth0): waiting for device to cancel activation.
Sep 28 20:14:28 neil-desktop dhclient: There is already a pid file /var/run/dhclient.eth0.pid with pid 5620
Sep 28 20:14:28 neil-desktop dhclient: killed old client process, removed PID file
Sep 28 20:14:28 neil-desktop dhclient: DHCPRELEASE on eth0 to 192.168.1.1 port 67
Sep 28 20:14:28 neil-desktop dhclient: send_packet: Network is unreachable
Sep 28 20:14:28 neil-desktop dhclient: send_packet: please consult README file regarding broadcast address.
Sep 28 20:14:29 neil-desktop NetworkManager: <info> Activation (eth0): waiting for device to cancel activation.
Sep 28 20:14:29 neil-desktop NetworkManager: <info> Activation (eth0) cancellation handled.
Sep 28 20:14:29 neil-desktop NetworkManager: <info> Activation (eth0): cancelled.
Sep 28 20:14:29 neil-desktop avahi-daemon[4682]: Withdrawing address record for fe80::209:6bff:fe54:ef7 on eth0.
Sep 28 20:14:29 neil-desktop NetworkManager: nm_device_is_802_3_ethernet: assertion `dev != NULL' failed
Sep 28 20:14:29 neil-desktop NetworkManager: nm_device_is_802_11_wireless: assertion `dev != NULL' failed
Sep 28 20:14:30 neil-desktop kernel: [ 240.116095] e100: eth0: e100_watchdog: link up, 100Mbps, full-duplex
Sep 28 20:14:30 neil-desktop NetworkManager: <info> Will activate wired connection 'eth0' because it now has a link.
Sep 28 20:14:30 neil-desktop kernel: [ 240.116932] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Sep 28 20:14:30 neil-desktop NetworkManager: <info> SWITCH: no current connection, found better connection 'eth0'.
Sep 28 20:14:30 neil-desktop NetworkManager: <info> Will activate connection 'eth0'.
Sep 28 20:14:30 neil-desktop NetworkManager: <info> Device eth0 activation scheduled...
Sep 28 20:14:30 neil-desktop NetworkManager: <info> Activation (eth0) started...
Sep 28 20:14:30 neil-desktop NetworkManager: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) scheduled...
Sep 28 20:14:30 neil-desktop NetworkManager: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) started...
Sep 28 20:14:30 neil-desktop NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) scheduled...
Sep 28 20:14:30 neil-desktop NetworkManager: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) complete.
Sep 28 20:14:30 neil-desktop NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) starting...
Sep 28 20:14:30 neil-desktop NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) successful.
Sep 28 20:14:30 neil-desktop NetworkManager: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) scheduled.
Sep 28 20:14:30 neil-desktop NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) complete.
Sep 28 20:14:30 neil-desktop NetworkManager: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) started...
Sep 28 20:14:31 neil-desktop NetworkManager: <info> Activation (eth0) Beginning DHCP transaction.
Sep 28 20:14:31 neil-desktop dhclient: There is already a pid file /var/run/dhclient.eth0.pid with pid 134519072
Sep 28 20:14:31 neil-desktop NetworkManager: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) complete.
Sep 28 20:14:31 neil-desktop NetworkManager: <info> DHCP daemon state is now 12 (successfully started) for interface eth0
Sep 28 20:14:32 neil-desktop avahi-daemon[4682]: Registering new address record for fe80::209:6bff:fe54:ef7 on eth0.*.
Sep 28 20:14:32 neil-desktop NetworkManager: <info> DHCP daemon state is now 1 (starting) for interface eth0
Sep 28 20:14:35 neil-desktop dhclient: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 7
Sep 28 20:14:37 neil-desktop dhclient: DHCPOFFER of 192.168.1.2 from 192.168.1.1
Sep 28 20:14:37 neil-desktop dhclient: DHCPREQUEST of 192.168.1.2 on eth0 to 255.255.255.255 port 67
Sep 28 20:14:41 neil-desktop kernel: [ 250.642056] eth0: no IPv6 routers present
Sep 28 20:14:45 neil-desktop dhclient: DHCPREQUEST of 192.168.1.2 on eth0 to 255.255.255.255 port 67
Sep 28 20:14:45 neil-desktop dhclient: DHCPACK of 192.168.1.2 from 192.168.1.1
Sep 28 20:14:45 neil-desktop avahi-daemon[4682]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.2.
Sep 28 20:14:45 neil-desktop avahi-daemon[4682]: New relevant interface eth0.IPv4 for mDNS.
Sep 28 20:14:45 neil-desktop avahi-daemon[4682]: Registering new address record for 192.168.1.2 on eth0.IPv4.
Sep 28 20:14:45 neil-desktop NetworkManager: <info> DHCP daemon state is now 2 (bound) for interface eth0
Sep 28 20:14:45 neil-desktop NetworkManager: <info> Activation (eth0) Stage 4 of 5 (IP Configure Get) scheduled...
Sep 28 20:14:45 neil-desktop NetworkManager: <info> Activation (eth0) Stage 4 of 5 (IP Configure Get) started...
Sep 28 20:14:45 neil-desktop dhclient: bound to 192.168.1.2 -- renewal in 33183 seconds.
Sep 28 20:14:45 neil-desktop dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/eth0 for sub-path eth0.dbus.get.host_name
Sep 28 20:14:45 neil-desktop dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/eth0 for sub-path eth0.dbus.get.nis_domain
Sep 28 20:14:45 neil-desktop dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/eth0 for sub-path eth0.dbus.get.nis_servers
Sep 28 20:14:45 neil-desktop NetworkManager: <info> Retrieved the following IP4 configuration from the DHCP daemon:
Sep 28 20:14:45 neil-desktop NetworkManager: <info> address 192.168.1.2
Sep 28 20:14:45 neil-desktop NetworkManager: <info> netmask 255.255.255.0
Sep 28 20:14:45 neil-desktop NetworkManager: <info> broadcast 192.168.1.255
Sep 28 20:14:45 neil-desktop NetworkManager: <info> gateway 192.168.1.1
Sep 28 20:14:45 neil-desktop NetworkManager: <info> nameserver 192.168.1.1
Sep 28 20:14:45 neil-desktop NetworkManager: <info> domain name 'home'
Sep 28 20:14:45 neil-desktop dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/eth0 for sub-path eth0.dbus.get.interface_mtu
Sep 28 20:14:45 neil-desktop NetworkManager: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) scheduled...
Sep 28 20:14:45 neil-desktop NetworkManager: <info> Activation (eth0) Stage 4 of 5 (IP Configure Get) complete.
Sep 28 20:14:45 neil-desktop NetworkManager: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) started...
Sep 28 20:14:45 neil-desktop avahi-daemon[4682]: Withdrawing address record for 192.168.1.2 on eth0.
Sep 28 20:14:45 neil-desktop avahi-daemon[4682]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.1.2.
Sep 28 20:14:45 neil-desktop avahi-daemon[4682]: Interface eth0.IPv4 no longer relevant for mDNS.
Sep 28 20:14:45 neil-desktop avahi-daemon[4682]: Withdrawing address record for fe80::209:6bff:fe54:ef7 on eth0.
Sep 28 20:14:45 neil-desktop avahi-daemon[4682]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.2.
Sep 28 20:14:45 neil-desktop avahi-daemon[4682]: New relevant interface eth0.IPv4 for mDNS.
Sep 28 20:14:45 neil-desktop avahi-daemon[4682]: Registering new address record for 192.168.1.2 on eth0.IPv4.
Sep 28 20:14:46 neil-desktop NetworkManager: <info> Clearing nscd hosts cache.
Sep 28 20:14:46 neil-desktop NetworkManager: <WARN> nm_spawn_process(): nm_spawn_process('/usr/sbin/nscd -i hosts'): could not spawn process. (Failed to execute child process "/usr/sbin/nscd" (No such file or directory))
Sep 28 20:14:46 neil-desktop NetworkManager: <info> Activation (eth0) successful, device activated.
Sep 28 20:14:46 neil-desktop NetworkManager: <info> Activation (eth0) Finish handler scheduled.
Sep 28 20:14:46 neil-desktop NetworkManager: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) complete.
Sep 28 20:14:47 neil-desktop avahi-daemon[4682]: Registering new address record for fe80::209:6bff:fe54:ef7 on eth0.*.
Sep 28 20:14:56 neil-desktop kernel: [ 266.185461] eth0: no IPv6 routers present
Sep 28 20:15:01 neil-desktop ntpdate[5731]: can't find host ntp.ubuntu.com
Sep 28 20:15:01 neil-desktop ntpdate[5731]: no servers can be used, exiting
Sep 28 20:15:09 neil-desktop kernel: [ 278.465208] usb 1-2: new full speed USB device using uhci_hcd and address 2
Sep 28 20:15:09 neil-desktop kernel: [ 278.634150] usb 1-2: configuration #1 chosen from 1 choice
Sep 28 20:15:09 neil-desktop NetworkManager: <debug> [1254165309.483596] nm_hal_device_added(): New device added (hal udi is '/org/freedesktop/Hal/devices/usb_device_3f0_2504_CN89A2B05G05BR').
Sep 28 20:15:09 neil-desktop kernel: [ 279.219259] usblp0: USB Bidirectional printer dev 2 if 1 alt 0 proto 2 vid 0x03F0 pid 0x2504
Sep 28 20:15:09 neil-desktop kernel: [ 279.219304] usbcore: registered new interface driver usblp
Sep 28 20:15:10 neil-desktop NetworkManager: <debug> [1254165310.058447] nm_hal_device_added(): New device added (hal udi is '/org/freedesktop/Hal/devices/usb_device_3f0_2504_CN89A2B05G05BR_if0').
Sep 28 20:15:10 neil-desktop NetworkManager: <debug> [1254165310.145910] nm_hal_device_added(): New device added (hal udi is '/org/freedesktop/Hal/devices/usb_device_3f0_2504_CN89A2B05G05BR_if2').
Sep 28 20:15:10 neil-desktop NetworkManager: <debug> [1254165310.240398] nm_hal_device_added(): New device added (hal udi is '/org/freedesktop/Hal/devices/usb_device_3f0_2504_CN89A2B05G05BR_if1').
Sep 28 20:15:11 neil-desktop hal_lpadmin: add
Sep 28 20:15:12 neil-desktop hal_lpadmin: URIs: ['hp:/usb/Deskjet_F4200_series?serial=CN89A2B05G05BR', 'usb://HP/Deskjet%20F4200%20series?serial=CN89A2B05G05BR', 'hal:///org/freedesktop/Hal/devices/usb_device_3f0_2504_CN89A2B05G05BR_if1_printer_CN89A2B05G05BR']
Sep 28 20:15:13 neil-desktop hal_lpadmin: HPLIP Fax URIs: None
Sep 28 20:15:13 neil-desktop hal_lpadmin: Not adding printer: Deskjet_F4200_series already exists
Sep 28 20:15:13 neil-desktop NetworkManager: <debug> [1254165313.555904] nm_hal_device_added(): New device added (hal udi is '/org/freedesktop/Hal/devices/usb_device_3f0_2504_CN89A2B05G05BR_if1_printer_CN89A2B05G05BR').
Sep 28 20:17:02 neil-desktop /USR/SBIN/CRON[5817]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)
Sep 28 20:18:24 neil-desktop kernel: [ 473.289280] audit(1254165504.125:3): type=1503 operation="inode_permission" requested_mask="::rw" denied_mask="::rw" name="/dev/tty" pid=5832 profile="/usr/sbin/cupsd" namespace="default"
Sep 28 20:18:42 neil-desktop hp[5826]: prnt/backend/hp.c 802: ERROR: null print job total=0
Sep 28 20:19:27 neil-desktop kernel: [ 536.744354] usblp0: removed
Sep 28 20:19:29 neil-desktop hal_lpadmin: remove
Sep 28 20:19:29 neil-desktop hal_lpadmin: Found configured printer: Deskjet_F4200_series
Sep 28 20:19:30 neil-desktop NetworkManager: <debug> [1254165570.174604] nm_hal_device_removed(): Device removed (hal udi is '/org/freedesktop/Hal/devices/usb_device_3f0_2504_CN89A2B05G05BR_if1_printer_CN89A2B05G05BR').
Sep 28 20:23:46 neil-desktop kernel: [ 795.559997] audit(1254165826.821:4): type=1503 operation="inode_permission" requested_mask="::rw" denied_mask="::rw" name="/dev/tty" pid=5869 profile="/usr/sbin/cupsd" namespace="default"
Sep 28 20:23:58 neil-desktop hp[5863]: prnt/backend/hp.c 802: ERROR: null print job total=0

Revision history for this message
Simon k (swkelso) said :
#5

Aaron, please see syslog in last post. Also I have pasted in the cups debug info below:

E [28/Sep/2009:20:18:42 +0100] PID 5825 (/usr/lib/cups/filter/foomatic-rip) stop
ped with status 3!
E [28/Sep/2009:20:18:42 +0100] PID 5826 (/usr/lib/cups/backend/hp) stopped with
status 1!
E [28/Sep/2009:20:23:58 +0100] PID 5862 (/usr/lib/cups/filter/foomatic-rip) stop
ped with status 3!
E [28/Sep/2009:20:23:58 +0100] PID 5863 (/usr/lib/cups/backend/hp) stopped with
status 1!
E [28/Sep/2009:20:29:07 +0100] PID 5882 (/usr/lib/cups/backend/hp) stopped with
status 1!
I [28/Sep/2009:20:37:26 +0100] Listening to 127.0.0.1:631 (IPv4)
I [28/Sep/2009:20:37:26 +0100] Listening to /var/run/cups/cups.sock (Domain)
I [28/Sep/2009:20:37:26 +0100] Loaded configuration file "/etc/cups/cupsd.conf"
I [28/Sep/2009:20:37:26 +0100] Using default TempDir of /var/spool/cups/tmp...
I [28/Sep/2009:20:37:26 +0100] Configured for up to 100 clients.
I [28/Sep/2009:20:37:26 +0100] Allowing up to 100 client connections per host.
I [28/Sep/2009:20:37:26 +0100] Using policy "default" as the default!
I [28/Sep/2009:20:37:26 +0100] Full reload is required.
I [28/Sep/2009:20:37:26 +0100] Loaded MIME database from '/etc/cups': 36 types,
39 filters...
D [28/Sep/2009:20:37:26 +0100] Loading printer Deskjet_F4200_series...
D [28/Sep/2009:20:37:26 +0100] Loading printer PDF...
D [28/Sep/2009:20:37:26 +0100] cupsdLoadRemoteCache: Not loading remote cache.
I [28/Sep/2009:20:37:26 +0100] Loading job cache file "/var/cache/cups/job.cache
"...
D [28/Sep/2009:20:37:26 +0100] [Job 15] Loading from cache...
D [28/Sep/2009:20:37:26 +0100] [Job 16] Loading from cache...
D [28/Sep/2009:20:37:26 +0100] [Job 17] Loading from cache...
D [28/Sep/2009:20:37:26 +0100] [Job 18] Loading from cache...
D [28/Sep/2009:20:37:26 +0100] [Job 19] Loading from cache...
D [28/Sep/2009:20:37:26 +0100] [Job 20] Loading from cache...
D [28/Sep/2009:20:37:26 +0100] [Job 21] Loading from cache...
D [28/Sep/2009:20:37:26 +0100] [Job 22] Loading from cache...
D [28/Sep/2009:20:37:26 +0100] [Job 23] Loading from cache...
D [28/Sep/2009:20:37:26 +0100] [Job 24] Loading from cache...
D [28/Sep/2009:20:37:26 +0100] [Job 25] Loading from cache...
D [28/Sep/2009:20:37:26 +0100] [Job 26] Loading from cache...
D [28/Sep/2009:20:37:26 +0100] [Job 27] Loading from cache...
D [28/Sep/2009:20:37:26 +0100] [Job 28] Loading from cache...
D [28/Sep/2009:20:37:26 +0100] [Job 29] Loading from cache...
D [28/Sep/2009:20:37:26 +0100] [Job 30] Loading from cache...
D [28/Sep/2009:20:37:26 +0100] [Job 31] Loading from cache...
D [28/Sep/2009:20:37:26 +0100] [Job 32] Loading from cache...
I [28/Sep/2009:20:37:26 +0100] Full reload complete.
I [28/Sep/2009:20:37:26 +0100] Cleaning out old temporary files in "/var/spool/c
ups/tmp"...
D [28/Sep/2009:20:37:26 +0100] Removed temporary file "/var/spool/cups/tmp/gs_jI
54I7"...
D [28/Sep/2009:20:37:26 +0100] Removed temporary file "/var/spool/cups/tmp/gs_gd
MTlp"...
D [28/Sep/2009:20:37:26 +0100] Removed temporary file "/var/spool/cups/tmp/gs_3n
dNxS"...
D [28/Sep/2009:20:37:26 +0100] Removed temporary file "/var/spool/cups/tmp/gs_qy
UzDE"...
I [28/Sep/2009:20:37:26 +0100] Listening to 127.0.0.1:631 on fd 3...
I [28/Sep/2009:20:37:26 +0100] Listening to /var/run/cups/cups.sock on fd 4...
I [28/Sep/2009:20:37:26 +0100] Resuming new connection processing...
D [28/Sep/2009:20:37:27 +0100] Report: clients=0
D [28/Sep/2009:20:37:27 +0100] Report: jobs=18
D [28/Sep/2009:20:37:27 +0100] Report: jobs-active=0
D [28/Sep/2009:20:37:27 +0100] Report: printers=2
D [28/Sep/2009:20:37:27 +0100] Report: printers-implicit=0
D [28/Sep/2009:20:37:27 +0100] Report: stringpool-string-count=492
D [28/Sep/2009:20:37:27 +0100] Report: stringpool-alloc-bytes=8136
D [28/Sep/2009:20:37:27 +0100] Report: stringpool-total-bytes=9368
D [28/Sep/2009:20:37:51 +0100] cupsdAcceptClient: 7 from localhost (Domain)
D [28/Sep/2009:20:37:52 +0100] cupsdReadClient: 7 POST / HTTP/1.1
D [28/Sep/2009:20:37:52 +0100] cupsdAuthorize: No authentication data provided.
D [28/Sep/2009:20:37:52 +0100] CUPS-Get-Printers
D [28/Sep/2009:20:37:52 +0100] cupsdProcessIPPRequest: 7 status_code=0 (successf
ul-ok)
D [28/Sep/2009:20:37:52 +0100] cupsdAcceptClient: 8 from localhost:631 (IPv4)
D [28/Sep/2009:20:37:52 +0100] cupsdCloseClient: 7
D [28/Sep/2009:20:37:52 +0100] cupsdReadClient: 8 GET /printers/Deskjet_F4200_se
ries.ppd HTTP/1.1
D [28/Sep/2009:20:37:52 +0100] cupsdAuthorize: No authentication data provided.
D [28/Sep/2009:20:37:52 +0100] cupsdCloseClient: 8
D [28/Sep/2009:20:37:54 +0100] cupsdAcceptClient: 7 from localhost (Domain)
D [28/Sep/2009:20:37:54 +0100] cupsdReadClient: 7 POST / HTTP/1.1
D [28/Sep/2009:20:37:54 +0100] cupsdAuthorize: No authentication data provided.
D [28/Sep/2009:20:37:54 +0100] CUPS-Get-Printers
D [28/Sep/2009:20:37:54 +0100] cupsdProcessIPPRequest: 7 status_code=0 (successf
ul-ok)
D [28/Sep/2009:20:37:54 +0100] cupsdCloseClient: 7
D [28/Sep/2009:20:37:55 +0100] cupsdAcceptClient: 7 from localhost (Domain)
D [28/Sep/2009:20:37:55 +0100] cupsdReadClient: 7 POST /printers/Deskjet_F4200_s
eries HTTP/1.1
D [28/Sep/2009:20:37:55 +0100] cupsdAuthorize: No authentication data provided.
D [28/Sep/2009:20:37:55 +0100] Print-Job ipp://localhost:631/printers/Deskjet_F4
200_series
D [28/Sep/2009:20:37:55 +0100] print_job: auto-typing file...
D [28/Sep/2009:20:37:55 +0100] add_job: requesting-user-name="neil"
I [28/Sep/2009:20:37:55 +0100] [Job 33] Adding start banner page "none".
D [28/Sep/2009:20:37:55 +0100] Discarding unused job-created event...
I [28/Sep/2009:20:37:55 +0100] [Job 33] Adding job file of type application/post
script.
I [28/Sep/2009:20:37:55 +0100] [Job 33] Adding end banner page "none".
I [28/Sep/2009:20:37:55 +0100] [Job 33] Queued on "Deskjet_F4200_series" by "nei
l".
D [28/Sep/2009:20:37:55 +0100] [Job 33] hold_until = 0
D [28/Sep/2009:20:37:55 +0100] Discarding unused printer-state-changed event...
D [28/Sep/2009:20:37:55 +0100] [Job 33] job-sheets=none,none
D [28/Sep/2009:20:37:55 +0100] [Job 33] banner_page = 0
D [28/Sep/2009:20:37:55 +0100] [Job 33] argv[0]="Deskjet_F4200_series"
D [28/Sep/2009:20:37:55 +0100] [Job 33] argv[1]="33"
D [28/Sep/2009:20:37:55 +0100] [Job 33] argv[2]="neil"
D [28/Sep/2009:20:37:55 +0100] [Job 33] argv[3]="Unsaved Document 1"
D [28/Sep/2009:20:37:55 +0100] [Job 33] argv[4]="1"
D [28/Sep/2009:20:37:55 +0100] [Job 33] argv[5]="PrintoutMode=Normal PageSize=A4
 Quality=FromPrintoutMode number-up=1 job-uuid=urn:uuid:50feeeb6-272e-3696-72ec-
cd4c784e79c4"
D [28/Sep/2009:20:37:55 +0100] [Job 33] argv[6]="/var/spool/cups/d00033-001"
D [28/Sep/2009:20:37:55 +0100] [Job 33] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [28/Sep/2009:20:37:55 +0100] [Job 33] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [28/Sep/2009:20:37:55 +0100] [Job 33] envp[2]="CUPS_DOCROOT=/usr/share/cups/do
c-root"
D [28/Sep/2009:20:37:55 +0100] [Job 33] envp[3]="CUPS_FONTPATH=/usr/share/cups/f
onts"
D [28/Sep/2009:20:37:55 +0100] [Job 33] envp[4]="CUPS_REQUESTROOT=/var/spool/cup
s"
D [28/Sep/2009:20:37:55 +0100] [Job 33] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [28/Sep/2009:20:37:55 +0100] [Job 33] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [28/Sep/2009:20:37:55 +0100] [Job 33] envp[7]="CUPS_STATEDIR=/var/run/cups"
D [28/Sep/2009:20:37:55 +0100] [Job 33] envp[8]="PATH=/usr/lib/cups/filter:/usr/
bin:/usr/sbin:/bin:/usr/bin"
D [28/Sep/2009:20:37:55 +0100] [Job 33] envp[9]="SERVER_ADMIN=root@neil-desktop"
D [28/Sep/2009:20:37:55 +0100] [Job 33] envp[10]="SOFTWARE=CUPS/1.3.7"
D [28/Sep/2009:20:37:55 +0100] [Job 33] envp[11]="TMPDIR=/var/spool/cups/tmp"
D [28/Sep/2009:20:37:55 +0100] [Job 33] envp[12]="TZ=Europe/London"
D [28/Sep/2009:20:37:55 +0100] [Job 33] envp[13]="USER=root"
D [28/Sep/2009:20:37:55 +0100] [Job 33] envp[14]="CUPS_SERVER=/var/run/cups/cups
.sock"
D [28/Sep/2009:20:37:55 +0100] [Job 33] envp[15]="CUPS_ENCRYPTION=IfRequested"
D [28/Sep/2009:20:37:55 +0100] [Job 33] envp[16]="IPP_PORT=631"
D [28/Sep/2009:20:37:55 +0100] [Job 33] envp[17]="CHARSET=utf-8"
D [28/Sep/2009:20:37:55 +0100] [Job 33] envp[18]="LANG=en_GB.UTF8"
D [28/Sep/2009:20:37:55 +0100] [Job 33] envp[19]="PPD=/etc/cups/ppd/Deskjet_F420
0_series.ppd"
D [28/Sep/2009:20:37:55 +0100] [Job 33] envp[20]="RIP_MAX_CACHE=8m"
D [28/Sep/2009:20:37:55 +0100] [Job 33] envp[21]="CONTENT_TYPE=application/posts
cript"
D [28/Sep/2009:20:37:55 +0100] [Job 33] envp[22]="DEVICE_URI=hp:/usb/Deskjet_F42
00_series?serial=CN89A2B05G05BR"
D [28/Sep/2009:20:37:55 +0100] [Job 33] envp[23]="PRINTER=Deskjet_F4200_series"
D [28/Sep/2009:20:37:55 +0100] [Job 33] envp[24]="FINAL_CONTENT_TYPE=printer/Des
kjet_F4200_series"
I [28/Sep/2009:20:37:55 +0100] [Job 33] Started filter /usr/lib/cups/filter/psto
ps (PID 5922)
I [28/Sep/2009:20:37:55 +0100] [Job 33] Started filter /usr/lib/cups/filter/foom
atic-rip (PID 5923)
I [28/Sep/2009:20:37:55 +0100] [Job 33] Started backend /usr/lib/cups/backend/hp
 (PID 5924)
D [28/Sep/2009:20:37:55 +0100] Discarding unused job-state-changed event...
D [28/Sep/2009:20:37:55 +0100] cupsdProcessIPPRequest: 7 status_code=0 (successf
ul-ok)
D [28/Sep/2009:20:37:55 +0100] PID 5922 (/usr/lib/cups/filter/pstops) exited wit
h no errors.
D [28/Sep/2009:20:37:55 +0100] cupsdAcceptClient: 10 from localhost (Domain)
D [28/Sep/2009:20:37:55 +0100] [Job 33] Page = 595x842; 10,36 to 585,833
D [28/Sep/2009:20:37:55 +0100] [Job 33] slow_collate=0, slow_duplex=0, slow_orde
r=0
D [28/Sep/2009:20:37:55 +0100] [Job 33] Before copy_comments - %!PS-Adobe-3.0
D [28/Sep/2009:20:37:55 +0100] [Job 33] %!PS-Adobe-3.0
D [28/Sep/2009:20:37:55 +0100] [Job 33] %%Creator: cairo 1.6.0 (http://cairograp
hics.org)
D [28/Sep/2009:20:37:55 +0100] [Job 33] %%CreationDate: Mon Sep 28 20:37:55 2009
D [28/Sep/2009:20:37:55 +0100] [Job 33] %%Pages: 1
D [28/Sep/2009:20:37:55 +0100] [Job 33] %%BoundingBox: 0 0 596 842
D [28/Sep/2009:20:37:55 +0100] [Job 33] %%DocumentData: Clean7Bit
D [28/Sep/2009:20:37:55 +0100] [Job 33] %%LanguageLevel: 2
D [28/Sep/2009:20:37:55 +0100] [Job 33] %%EndComments
D [28/Sep/2009:20:37:55 +0100] [Job 33] Before copy_prolog - %%BeginProlog
D [28/Sep/2009:20:37:55 +0100] [Job 33] Before copy_setup - 11 dict begin
D [28/Sep/2009:20:37:55 +0100] [Job 33] Before page loop - %%Page: 1 1
D [28/Sep/2009:20:37:55 +0100] [Job 33] Copying page 1...
D [28/Sep/2009:20:37:55 +0100] [Job 33] pagew = 575.6, pagel = 797.0
D [28/Sep/2009:20:37:55 +0100] [Job 33] bboxx = 0, bboxy = 0, bboxw = 595, bboxl
 = 842
D [28/Sep/2009:20:37:55 +0100] [Job 33] PageLeft = 9.7, PageRight = 585.3
D [28/Sep/2009:20:37:55 +0100] [Job 33] PageTop = 833.0, PageBottom = 36.0
D [28/Sep/2009:20:37:55 +0100] [Job 33] PageWidth = 595.0, PageLength = 842.0
D [28/Sep/2009:20:37:55 +0100] [Job 33] Wrote 1 pages...
D [28/Sep/2009:20:37:55 +0100] cupsdReadClient: 10 POST / HTTP/1.1
D [28/Sep/2009:20:37:55 +0100] cupsdAuthorize: No authentication data provided.
D [28/Sep/2009:20:37:55 +0100] Get-Jobs ipp://localhost/jobs/
D [28/Sep/2009:20:37:55 +0100] cupsdProcessIPPRequest: 10 status_code=0 (success
ful-ok)
D [28/Sep/2009:20:37:55 +0100] cupsdCloseClient: 7
D [28/Sep/2009:20:37:55 +0100] cupsdAcceptClient: 7 from localhost (Domain)
D [28/Sep/2009:20:37:55 +0100] cupsdReadClient: 7 POST / HTTP/1.1
D [28/Sep/2009:20:37:55 +0100] cupsdAuthorize: No authentication data provided.
D [28/Sep/2009:20:37:55 +0100] CUPS-Get-Printers
D [28/Sep/2009:20:37:55 +0100] cupsdProcessIPPRequest: 7 status_code=0 (successf
ul-ok)
D [28/Sep/2009:20:37:55 +0100] cupsdReadClient: 10 POST / HTTP/1.1
D [28/Sep/2009:20:37:55 +0100] cupsdAuthorize: No authentication data provided.
D [28/Sep/2009:20:37:55 +0100] CUPS-Get-Printers
D [28/Sep/2009:20:37:55 +0100] cupsdProcessIPPRequest: 10 status_code=0 (success
ful-ok)
D [28/Sep/2009:20:37:55 +0100] cupsdCloseClient: 10
D [28/Sep/2009:20:37:56 +0100] [Job 33] foomatic-rip version $Revision$ running.
..
D [28/Sep/2009:20:37:56 +0100] [Job 33] Parsing PPD file ...
D [28/Sep/2009:20:37:56 +0100] [Job 33] Added option ColorSpace
D [28/Sep/2009:20:37:56 +0100] [Job 33] Added option PageSize
D [28/Sep/2009:20:37:56 +0100] [Job 33] Added option Model
D [28/Sep/2009:20:37:56 +0100] [Job 33] Added option PrintoutMode
D [28/Sep/2009:20:37:56 +0100] [Job 33] Added option Quality
D [28/Sep/2009:20:37:56 +0100] [Job 33] *cupsFilter: "application/vnd.cups-posts
cript 0 foomatic-rip"
D [28/Sep/2009:20:37:56 +0100] [Job 33] Added option PageRegion
D [28/Sep/2009:20:37:56 +0100] [Job 33] Added option ImageableArea
D [28/Sep/2009:20:37:56 +0100] [Job 33] Added option PaperDimension
D [28/Sep/2009:20:37:56 +0100] [Job 33] Added option Font
D [28/Sep/2009:20:37:56 +0100] [Job 33]
D [28/Sep/2009:20:37:56 +0100] [Job 33] Parameter Summary
D [28/Sep/2009:20:37:56 +0100] [Job 33] -----------------
D [28/Sep/2009:20:37:56 +0100] [Job 33]
D [28/Sep/2009:20:37:56 +0100] [Job 33] Spooler: cups
D [28/Sep/2009:20:37:56 +0100] [Job 33] Printer: Deskjet_F4200_series
D [28/Sep/2009:20:37:56 +0100] [Job 33] Shell: /bin/bash
D [28/Sep/2009:20:37:56 +0100] [Job 33] PPD file: /etc/cups/ppd/Deskjet_F4200_se
ries.ppd
D [28/Sep/2009:20:37:56 +0100] [Job 33] ATTR file:
D [28/Sep/2009:20:37:56 +0100] [Job 33] Printer model: HP DeskJet F4100 Foomatic
/hpijs, hpijs 2.8.2
D [28/Sep/2009:20:37:56 +0100] [Job 33] Job title: Unsaved Document 1
D [28/Sep/2009:20:37:56 +0100] [Job 33] File(s) to be printed:
D [28/Sep/2009:20:37:56 +0100] [Job 33] <STDIN>
D [28/Sep/2009:20:37:56 +0100] [Job 33]
D [28/Sep/2009:20:37:56 +0100] [Job 33] GhostScript extra search path ('GS_LIB')
: /usr/share/cups/fonts
D [28/Sep/2009:20:37:56 +0100] [Job 33] Pondering option 'PrintoutMode=Normal'
D [28/Sep/2009:20:37:56 +0100] [Job 33] Pondering option 'PageSize=A4'
D [28/Sep/2009:20:37:56 +0100] [Job 33] Pondering option 'Quality=FromPrintoutMo
de'
D [28/Sep/2009:20:37:56 +0100] [Job 33] Pondering option 'number-up=1'
D [28/Sep/2009:20:37:56 +0100] [Job 33] Unknown option number-up=1.
D [28/Sep/2009:20:37:56 +0100] [Job 33] Pondering option 'job-uuid=urn:uuid:50fe
eeb6-272e-3696-72ec-cd4c784e79c4'
D [28/Sep/2009:20:37:56 +0100] [Job 33] Unknown option job-uuid=urn:uuid:50feeeb
6-272e-3696-72ec-cd4c784e79c4.
D [28/Sep/2009:20:37:56 +0100] [Job 33]
D [28/Sep/2009:20:37:56 +0100] [Job 33] ========================================
========
D [28/Sep/2009:20:37:56 +0100] [Job 33]
D [28/Sep/2009:20:37:56 +0100] [Job 33] File: <STDIN>
D [28/Sep/2009:20:37:56 +0100] [Job 33]
D [28/Sep/2009:20:37:56 +0100] [Job 33] ========================================
========
D [28/Sep/2009:20:37:56 +0100] [Job 33]
D [28/Sep/2009:20:37:56 +0100] [Job 33] Reading PostScript input ...
D [28/Sep/2009:20:37:56 +0100] [Job 33] --> This document is DSC-conforming!
D [28/Sep/2009:20:37:56 +0100] [Job 33]
D [28/Sep/2009:20:37:56 +0100] [Job 33] -----------
D [28/Sep/2009:20:37:56 +0100] [Job 33] Found: %%BeginProlog
D [28/Sep/2009:20:37:56 +0100] [Job 33] Found: %%EndProlog
D [28/Sep/2009:20:37:56 +0100] [Job 33]
D [28/Sep/2009:20:37:56 +0100] [Job 33] -----------
D [28/Sep/2009:20:37:56 +0100] [Job 33] Found: %%BeginSetup
D [28/Sep/2009:20:37:56 +0100] [Job 33] Found: %%BeginFeature: *PageSize A4
D [28/Sep/2009:20:37:56 +0100] [Job 33] Option: PageSize=A4 --> Setting option
D [28/Sep/2009:20:37:56 +0100] [Job 33] Found: %% FoomaticRIPOptionSetting: Page
Size=A4
D [28/Sep/2009:20:37:56 +0100] [Job 33] Option: PageSize=A4 --> Setting option
D [28/Sep/2009:20:37:56 +0100] [Job 33] Found: %%BeginFeature: *PrintoutMode Nor
mal
D [28/Sep/2009:20:37:56 +0100] [Job 33] Option: PrintoutMode=Normal --> Setting
option
D [28/Sep/2009:20:37:56 +0100] [Job 33] Found: %% FoomaticRIPOptionSetting: Prin
toutMode=Normal
D [28/Sep/2009:20:37:56 +0100] [Job 33] Option: PrintoutMode=Normal --> Setting
option
D [28/Sep/2009:20:37:56 +0100] [Job 33] Found: %%BeginFeature: *Quality FromPrin
toutMode
D [28/Sep/2009:20:37:56 +0100] [Job 33] Option: Quality=FromPrintoutMode --> Set
ting option
D [28/Sep/2009:20:37:56 +0100] [Job 33] Found: %% FoomaticRIPOptionSetting: Qual
ity=@PrintoutMode
D [28/Sep/2009:20:37:56 +0100] [Job 33] Option: Quality=FromPrintoutMode --> Set
ting option
D [28/Sep/2009:20:37:56 +0100] [Job 33] Found: %%EndSetup
D [28/Sep/2009:20:37:56 +0100] [Job 33] Inserting PostScript code for CUPS' page
 accounting
D [28/Sep/2009:20:37:56 +0100] [Job 33]
D [28/Sep/2009:20:37:56 +0100] [Job 33] -----------
D [28/Sep/2009:20:37:56 +0100] [Job 33] New page: 1 1
D [28/Sep/2009:20:37:56 +0100] [Job 33]
D [28/Sep/2009:20:37:56 +0100] [Job 33] Found: %%BeginPageSetup
D [28/Sep/2009:20:37:56 +0100] [Job 33] Inserting option code into "PageSetup" s
ection.
D [28/Sep/2009:20:37:56 +0100] [Job 33] Found: %%EndPageSetup
D [28/Sep/2009:20:37:56 +0100] [Job 33] End of page header
D [28/Sep/2009:20:37:56 +0100] [Job 33] Flushing FIFO.
D [28/Sep/2009:20:37:56 +0100] [Job 33]
D [28/Sep/2009:20:37:56 +0100] [Job 33] Starting renderer
D [28/Sep/2009:20:37:56 +0100] [Job 33] JCL: <job data>
D [28/Sep/2009:20:37:56 +0100] [Job 33]
D [28/Sep/2009:20:37:56 +0100] [Job 33] renderer PID kid4=5932
D [28/Sep/2009:20:37:56 +0100] [Job 33] renderer command: gs -q -dBATCH -dPARANO
IDSAFER -dQUIET -dNOPAUSE -sDEVICE=ijs -sIjsServer=hpijs -dDEVICEWIDTHPOINTS=595
 -dDEVICEHEIGHTPOINTS=842 -sDeviceManufacturer="HEWLETT-PACKARD" -sDeviceModel="
deskjet 3600" -r300 -sIjsParams=Quality:Quality=0,Quality:ColorMode=2,Quality:Me
diaType=0,Quality:PenSet=1 -dIjsUseOutputFD -sOutputFile=- -
D [28/Sep/2009:20:37:56 +0100] [Job 33] Starting process 5933: "foomatic-gswrapp
er -q -dBATCH -dPARANOIDSAFER -dQUIET -dNOPAUSE -sDEVICE=ijs -sIjsServer=hpijs -
dDEV..."
D [28/Sep/2009:20:37:56 +0100] [Job 33]
D [28/Sep/2009:20:37:56 +0100] [Job 33] Closing renderer
D [28/Sep/2009:20:37:56 +0100] cupsdAcceptClient: 10 from localhost (Domain)
D [28/Sep/2009:20:37:56 +0100] cupsdReadClient: 10 POST / HTTP/1.1
D [28/Sep/2009:20:37:56 +0100] cupsdAuthorize: No authentication data provided.
D [28/Sep/2009:20:37:56 +0100] Get-Jobs ipp://localhost/jobs/
D [28/Sep/2009:20:37:56 +0100] cupsdProcessIPPRequest: 10 status_code=0 (success
ful-ok)
D [28/Sep/2009:20:37:56 +0100] cupsdReadClient: 10 POST / HTTP/1.1
D [28/Sep/2009:20:37:56 +0100] cupsdAuthorize: No authentication data provided.
D [28/Sep/2009:20:37:56 +0100] CUPS-Get-Printers
D [28/Sep/2009:20:37:56 +0100] cupsdProcessIPPRequest: 10 status_code=0 (success
ful-ok)
D [28/Sep/2009:20:37:56 +0100] cupsdCloseClient: 10
D [28/Sep/2009:20:37:57 +0100] [Job 33] foomatic-gswrapper: gs '-sstdout=%stderr
' '-dBATCH' '-dPARANOIDSAFER' '-dQUIET' '-dNOPAUSE' '-sDEVICE=ijs' '-sIjsServer=
hpijs' '-dDEVICEWIDTHPOINTS=595' '-dDEVICEHEIGHTPOINTS=842' '-sDeviceManufacture
r=HEWLETT-PACKARD' '-sDeviceModel=deskjet 3600' '-r300' '-sIjsParams=Quality:Qua
lity=0,Quality:ColorMode=2,Quality:MediaType=0,Quality:PenSet=1' '-dIjsUseOutput
FD' '-sOutputFile=%stdout' '-_'
D [28/Sep/2009:20:37:58 +0100] [Job 33] sh: hpijs: not found
D [28/Sep/2009:20:37:58 +0100] [Job 33] GPL Ghostscript 8.61: Can't start ijs se
rver "hpijs"
D [28/Sep/2009:20:37:58 +0100] [Job 33] **** Unable to open the initial device,
quitting.
D [28/Sep/2009:20:37:58 +0100] [Job 33] Process 5933 ending: "foomatic-gswrapper
 -q -dBATCH -dPARANOIDSAFER -dQUIET -dNOPAUSE -sDEVICE=ijs -sIjsServer=hpijs -dD
EV..."
D [28/Sep/2009:20:37:58 +0100] [Job 33] renderer return value: 1
D [28/Sep/2009:20:37:58 +0100] [Job 33] renderer received signal: 1
D [28/Sep/2009:20:37:58 +0100] [Job 33] Process dying with "Possible error on re
nderer command line or PostScript error. Check options.", exit stat: 3
D [28/Sep/2009:20:37:58 +0100] [Job 33] error: Illegal seek (29)
D [28/Sep/2009:20:37:58 +0100] [Job 33] Cleaning up ...
D [28/Sep/2009:20:37:58 +0100] [Job 33] Killing process 5932 (KID4) with signal
15
D [28/Sep/2009:20:37:58 +0100] [Job 33] Process dying with "Caught termination s
ignal: Job canceled", exit stat: 0
D [28/Sep/2009:20:37:58 +0100] [Job 33] error: (0)
D [28/Sep/2009:20:37:58 +0100] [Job 33] Cleaning up ...
D [28/Sep/2009:20:37:58 +0100] [Job 33] KID3 exited with status 3
D [28/Sep/2009:20:37:58 +0100] [Job 33] Renderer exit stat: 3
D [28/Sep/2009:20:38:01 +0100] [Job 33]
D [28/Sep/2009:20:38:01 +0100] [Job 33] Closing foomatic-rip.
D [28/Sep/2009:20:38:02 +0100] [Job 33] Killing process 5932 (KID4) with signal
9
D [28/Sep/2009:20:38:02 +0100] [Job 33]
D [28/Sep/2009:20:38:02 +0100] [Job 33] Closing foomatic-rip.
D [28/Sep/2009:20:38:02 +0100] [Job 33] Renderer process finished
D [28/Sep/2009:20:38:02 +0100] [Job 33] Process dying with "Error closing render
er", exit stat: 3
D [28/Sep/2009:20:38:02 +0100] [Job 33] error: Bad file descriptor (9)
D [28/Sep/2009:20:38:02 +0100] [Job 33] Cleaning up ...
D [28/Sep/2009:20:38:02 +0100] [Job 33] Killing process 5931 (KID3) with signal
15
D [28/Sep/2009:20:38:07 +0100] [Job 33] Killing process 5931 (KID3) with signal
9
D [28/Sep/2009:20:38:07 +0100] [Job 33] Error closing renderer
D [28/Sep/2009:20:38:07 +0100] [Job 33]
D [28/Sep/2009:20:38:07 +0100] [Job 33] Closing foomatic-rip.
E [28/Sep/2009:20:38:07 +0100] PID 5923 (/usr/lib/cups/filter/foomatic-rip) stop
ped with status 3!
D [28/Sep/2009:20:38:07 +0100] [Job 33] prnt/backend/hp.c 802: ERROR: null print
 job total=0
E [28/Sep/2009:20:38:07 +0100] PID 5924 (/usr/lib/cups/backend/hp) stopped with
status 1!
D [28/Sep/2009:20:38:07 +0100] [Job 33] File 0 is complete.
I [28/Sep/2009:20:38:07 +0100] [Job 33] Backend returned status 1 (failed)
D [28/Sep/2009:20:38:07 +0100] Discarding unused printer-state-changed event...
D [28/Sep/2009:20:38:07 +0100] set_hold_until: hold_until = 1254166987
D [28/Sep/2009:20:38:07 +0100] Discarding unused job-state-changed event...
D [28/Sep/2009:20:38:07 +0100] cupsdAcceptClient: 10 from localhost (Domain)
D [28/Sep/2009:20:38:07 +0100] cupsdReadClient: 10 POST / HTTP/1.1
D [28/Sep/2009:20:38:07 +0100] cupsdAuthorize: No authentication data provided.
D [28/Sep/2009:20:38:07 +0100] CUPS-Get-Printers
D [28/Sep/2009:20:38:07 +0100] cupsdProcessIPPRequest: 10 status_code=0 (success
ful-ok)
D [28/Sep/2009:20:38:07 +0100] cupsdAcceptClient: 11 from localhost (Domain)
D [28/Sep/2009:20:38:07 +0100] cupsdReadClient: 11 POST / HTTP/1.1
D [28/Sep/2009:20:38:07 +0100] cupsdAuthorize: No authentication data provided.
D [28/Sep/2009:20:38:07 +0100] Get-Jobs ipp://localhost/jobs/
D [28/Sep/2009:20:38:07 +0100] cupsdProcessIPPRequest: 11 status_code=0 (success
ful-ok)
D [28/Sep/2009:20:38:07 +0100] cupsdReadClient: 11 POST / HTTP/1.1
D [28/Sep/2009:20:38:07 +0100] cupsdAuthorize: No authentication data provided.
D [28/Sep/2009:20:38:07 +0100] CUPS-Get-Printers
D [28/Sep/2009:20:38:07 +0100] cupsdProcessIPPRequest: 11 status_code=0 (success
ful-ok)
D [28/Sep/2009:20:38:07 +0100] cupsdCloseClient: 11
D [28/Sep/2009:20:38:30 +0100] Report: clients=2
D [28/Sep/2009:20:38:30 +0100] Report: jobs=19
D [28/Sep/2009:20:38:30 +0100] Report: jobs-active=1
D [28/Sep/2009:20:38:30 +0100] Report: printers=2
D [28/Sep/2009:20:38:30 +0100] Report: printers-implicit=0
D [28/Sep/2009:20:38:30 +0100] Report: stringpool-string-count=574
D [28/Sep/2009:20:38:30 +0100] Report: stringpool-alloc-bytes=9144
D [28/Sep/2009:20:38:30 +0100] Report: stringpool-total-bytes=11240
D [28/Sep/2009:20:39:36 +0100] Report: clients=2
D [28/Sep/2009:20:39:36 +0100] Report: jobs=19
D [28/Sep/2009:20:39:36 +0100] Report: jobs-active=1
D [28/Sep/2009:20:39:36 +0100] Report: printers=2
D [28/Sep/2009:20:39:36 +0100] Report: printers-implicit=0
D [28/Sep/2009:20:39:36 +0100] Report: stringpool-string-count=574
D [28/Sep/2009:20:39:36 +0100] Report: stringpool-alloc-bytes=9144
D [28/Sep/2009:20:39:36 +0100] Report: stringpool-total-bytes=11240
D [28/Sep/2009:20:40:42 +0100] Report: clients=2
D [28/Sep/2009:20:40:42 +0100] Report: jobs=19
D [28/Sep/2009:20:40:42 +0100] Report: jobs-active=1
D [28/Sep/2009:20:40:42 +0100] Report: printers=2
D [28/Sep/2009:20:40:42 +0100] Report: printers-implicit=0
D [28/Sep/2009:20:40:42 +0100] Report: stringpool-string-count=574
D [28/Sep/2009:20:40:42 +0100] Report: stringpool-alloc-bytes=9144
D [28/Sep/2009:20:40:42 +0100] Report: stringpool-total-bytes=11240
D [28/Sep/2009:20:41:48 +0100] Report: clients=2
D [28/Sep/2009:20:41:48 +0100] Report: jobs=19
D [28/Sep/2009:20:41:48 +0100] Report: jobs-active=1
D [28/Sep/2009:20:41:48 +0100] Report: printers=2
D [28/Sep/2009:20:41:48 +0100] Report: printers-implicit=0
D [28/Sep/2009:20:41:48 +0100] Report: stringpool-string-count=574
D [28/Sep/2009:20:41:48 +0100] Report: stringpool-alloc-bytes=9144
D [28/Sep/2009:20:41:48 +0100] Report: stringpool-total-bytes=11240
root@neil-desktop:/etc/init.d#

Revision history for this message
Aaron Albright (albrigha-deactivatedaccount) said :
#6

From the cups log I'm seeing:

---

D [28/Sep/2009:20:37:58 +0100] [Job 33] sh: hpijs: not found

---

It could be that HPLIP for some reason didn't get fully installed.

Try remove HPLIP using this process:

http://hplipopensource.com/node/188

and then re-installing HPLIP.

Hope this helps.

Aaron

Revision history for this message
Simon k (swkelso) said :
#7

Super Aaron

Thats worked fine. Top Job !!! :)