JDK-6290446 : REG: Application hangs / VM crashes when printing through merlin print APIs on SolSparc10-CUPS
  • Type: Bug
  • Component: client-libs
  • Sub-Component: 2d
  • Affected Version: 6
  • Priority: P4
  • Status: Closed
  • Resolution: Cannot Reproduce
  • OS: solaris_10
  • CPU: sparc
  • Submitted: 2005-06-24
  • Updated: 2011-01-31
  • Resolved: 2005-09-07
Related Reports
Relates :  
Description
I am running few applications that are using javax.print classes for obtaining a print service. I am calling PrintServiceLookup.lookupPrintServices() with respect to a DocFlavor and an empty AttributeSet. When I run this application on SolSparc10-JDS with CUPS enabled, the application hangs indefinitely. Sometimes, the VM crashes or I am getting Segmentation Fault: Core dumped. Very rarely, the application works correctly. 

This is reproducible only since B33 and not occuring on Mustang-b32. Hence it is regression in b32. A RFE was fixed in b33 - 4744405 RFE: lookupPrintServices() to refresh the printers list dynamically, not sure whether this issue is related to that. This is not reproducible on Win32. This is not reproducible with the above mentioned builds on Non-CUPS systems. Looks like it is specific to CUPS.

I have tried this on Sparc-systems with ESPPrintPro4.5.4, 4.5.3, CUPS1.1.15 and reproducible on all of them. On ESPPrintPro4.4.1, it occurs intermittently. On All the above configs, the tests passes with b32. 

I have attached a couple of sample tests for reproducing this bug. Run them on the above configs. If you see application hanging or a VM crash or a Core dump, the bug is reproduced.

Here is the Crash info:

#
# An unexpected error has been detected by HotSpot Virtual Machine:
#
#  SIGSEGV (0xb) at pc=0xd34249e4, pid=1255, tid=17
#
# Java VM: Java HotSpot(TM) Server VM (1.6.0-ea-b41 mixed mode)
# Problematic frame:
# C  [libcups.so.2+0xa49e4]  lh_insert+0xac
#

---------------  T H R E A D  ---------------

Current thread (0x00285710):  JavaThread "Thread-1" daemon [_thread_in_native, id=17]

siginfo:si_signo=11, si_errno=0, si_code=2, si_addr=0xf219f22c

Registers:
 O0=0x000000ad O1=0x000000ad O2=0x04000000 O3=0x00000159
 O4=0x00000159 O5=0xd34a02cc O6=0xd357f0c0 O7=0xd3424990
 G1=0x03000000 G2=0x0000068e G3=0x000002b4 G4=0x00000040
 G5=0x0000620c G6=0x00000000 G7=0xfe613800 Y=0x00000000
 PC=0xd34249e4 nPC=0xd34249e8


Top of Stack: (sp=0xd357f0c0)
0xd357f0c0:   d3427058 00000009 00285330 ff340431
0xd357f0d0:   00000000 00000000 00000028 ff368c00
0xd357f0e0:   d34270cc 040000ad 0043f30c f219f224
0xd357f0f0:   d34bf6e8 0030f4e8 d357f120 d3425934
0xd357f100:   0000000e 00000001 00000000 00000005
0xd357f110:   00000000 00000043 00000000 00000000
0xd357f120:   d34a02cc 0000000a ff364278 00000a41
0xd357f130:   ff33f9f0 000001fc 00110b88 ff368210 

Instructions: (pc=0xd34249e4)
0xd34249d4:   b4 00 80 03 c4 07 60 58 84 00 a0 01 c4 27 60 58
0xd34249e4:   c4 06 e0 08 80 a0 80 19 22 80 00 06 c4 07 60 3c 

Stack: [0xd3500000,0xd3580000),  sp=0xd357f0c0,  free space=508k
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
C  [libcups.so.2+0xa49e4]  lh_insert+0xac
C  [libcups.so.2+0xa593c]
C  [libcups.so.2+0xa61ac]  ERR_load_strings+0x98
C  [libcups.so.2+0xa762c]  ERR_load_crypto_strings+0x30
C  [libcups.so.2+0x83ea8]  SSL_load_error_strings+0xc
C  [libcups.so.2+0x6bb5c]  httpInitialize+0x1c
C  [libcups.so.2+0x6bd18]  httpConnectEncrypt+0x30
C  [libmawt.so+0x2cb98]  Java_sun_print_CUPSPrinter_canConnect+0x50
j  sun.print.CUPSPrinter.canConnect(Ljava/lang/String;I)Z+-1421482800
j  sun.print.CUPSPrinter.canConnect(Ljava/lang/String;I)Z+0
j  sun.print.CUPSPrinter.isCupsRunning()Z+71
j  sun.print.UnixPrintServiceLookup.getDefaultPrintService()Ljavax/print/PrintService;+29
j  sun.print.UnixPrintServiceLookup.refreshServices()V+1
j  sun.print.UnixPrintServiceLookup$PrinterChangeListener.run()V+4
v  ~StubRoutines::call_stub
V  [libjvm.so+0x177ca4]
V  [libjvm.so+0x40d8a0]
V  [libjvm.so+0x26039c]
V  [libjvm.so+0x27d598]
V  [libjvm.so+0x279928]
V  [libjvm.so+0x5aec40]

Java frames: (J=compiled Java code, j=interpreted, Vv=VM code)
j  sun.print.CUPSPrinter.canConnect(Ljava/lang/String;I)Z+0
j  sun.print.CUPSPrinter.isCupsRunning()Z+71
j  sun.print.UnixPrintServiceLookup.getDefaultPrintService()Ljavax/print/PrintService;+29
j  sun.print.UnixPrintServiceLookup.refreshServices()V+1
j  sun.print.UnixPrintServiceLookup$PrinterChangeListener.run()V+4
v  ~StubRoutines::call_stub

---------------  P R O C E S S  ---------------

Java Threads: ( => current thread )
=>0x00285710 JavaThread "Thread-1" daemon [_thread_in_native, id=17]
  0x00037490 JavaThread "DestroyJavaVM" [_thread_blocked, id=1]
  0x002dc268 JavaThread "TimerQueue" daemon [_thread_blocked, id=16]
  0x0027f208 JavaThread "AWT-EventQueue-0" [_thread_in_native, id=15]
  0x0027edb0 JavaThread "AWT-Shutdown" [_thread_blocked, id=14]
  0x0027e6f0 JavaThread "AWT-XAWT" daemon [_thread_in_native, id=13]
  0x001b3820 JavaThread "Java2D Disposer" daemon [_thread_blocked, id=12]
  0x00111098 JavaThread "Low Memory Detector" daemon [_thread_blocked, id=10]
  0x0010f880 JavaThread "CompilerThread1" daemon [_thread_blocked, id=9]
  0x0010ea50 JavaThread "CompilerThread0" daemon [_thread_blocked, id=8]
  0x0010dd48 JavaThread "Signal Dispatcher" daemon [_thread_blocked, id=7]
  0x000ffe80 JavaThread "Finalizer" daemon [_thread_blocked, id=6]
  0x000ff190 JavaThread "Reference Handler" daemon [_thread_blocked, id=5]

Other Threads:
  0x000fb5f8 VMThread [id=4]
  0x001128e8 WatcherThread [id=11]

VM state:not at safepoint (normal execution)

VM Mutex/Monitor currently owned by a thread: None

Heap
 PSYoungGen      total 10752K, used 3912K [0xedc00000, 0xee800000, 0xf8800000)
  eden space 9216K, 42% used [0xedc00000,0xedfd20a8,0xee500000)
  from space 1536K, 0% used [0xee680000,0xee680000,0xee800000)
  to   space 1536K, 0% used [0xee500000,0xee500000,0xee680000)
 PSOldGen        total 24576K, used 0K [0xd8400000, 0xd9c00000, 0xedc00000)
  object space 24576K, 0% used [0xd8400000,0xd8400000,0xd9c00000)
 PSPermGen       total 16384K, used 7927K [0xd4400000, 0xd5400000, 0xd8400000)
  object space 16384K, 48% used [0xd4400000,0xd4bbded0,0xd5400000)

Dynamic libraries:
0x00010000 	/net/sqindia/export/disk05/2d-SQE/PIT/2005-06-20.mustang/solaris-sparc/bin/java
0xff3f8000 	/lib/libthread.so.1
0xff3a0000 	/lib/libdl.so.1
0xff280000 	/lib/libc.so.1
0xff270000 	/platform/SUNW,Sun-Blade-2500/lib/libc_psr.so.1
0xfe800000 	/net/sqindia/export/disk05/2d-SQE/PIT/2005-06-20.mustang/solaris-sparc/jre/lib/sparc/server/libjvm.so
0xff230000 	/lib/libsocket.so.1
0xff260000 	/usr/lib/libsched.so.1
0xff1f0000 	/usr/lib/libCrun.so.1
0xff1d0000 	/lib/libm.so.1
0xff1b0000 	/lib/libdoor.so.1
0xff080000 	/lib/libnsl.so.1
0xfe700000 	/lib/libm.so.2
0xff170000 	/lib/libscf.so.1
0xff150000 	/lib/libuutil.so.1
0xff060000 	/lib/libmd5.so.1
0xff040000 	/platform/SUNW,Sun-Blade-2500/lib/libmd5_psr.so.1
0xff020000 	/lib/libmp.so.2
0xfefe0000 	/net/sqindia/export/disk05/2d-SQE/PIT/2005-06-20.mustang/solaris-sparc/jre/lib/sparc/native_threads/libhpi.so
0xfef90000 	/net/sqindia/export/disk05/2d-SQE/PIT/2005-06-20.mustang/solaris-sparc/jre/lib/sparc/libverify.so
0xfe6c0000 	/net/sqindia/export/disk05/2d-SQE/PIT/2005-06-20.mustang/solaris-sparc/jre/lib/sparc/libjava.so
0xfef70000 	/net/sqindia/export/disk05/2d-SQE/PIT/2005-06-20.mustang/solaris-sparc/jre/lib/sparc/libzip.so
0xd3e80000 	/net/sqindia/export/disk05/2d-SQE/PIT/2005-06-20.mustang/solaris-sparc/jre/lib/sparc/libawt.so
0xd3d00000 	/net/sqindia/export/disk05/2d-SQE/PIT/2005-06-20.mustang/solaris-sparc/jre/lib/sparc/libmlib_image.so
0xfb6b0000 	/net/sqindia/export/disk05/2d-SQE/PIT/2005-06-20.mustang/solaris-sparc/jre/lib/sparc/xawt/libmawt.so
0xfb440000 	/usr/lib/libXext.so.0
0xd3c00000 	/usr/lib/libX11.so.4
0xd3b00000 	/net/sqindia/export/disk05/2d-SQE/PIT/2005-06-20.mustang/solaris-sparc/jre/lib/sparc/libfontmanager.so
0xfb790000 	/net/sqindia/export/disk05/2d-SQE/PIT/2005-06-20.mustang/solaris-sparc/jre/lib/sparc/libnet.so
0xfb420000 	/net/sqindia/export/disk05/2d-SQE/PIT/2005-06-20.mustang/solaris-sparc/jre/lib/sparc/libnio.so
0xfafe0000 	/lib/librt.so.1
0xfafc0000 	/lib/libaio.so.1
0xfafa0000 	/usr/lib/libsendfile.so.1
0xfae90000 	/net/sqindia/export/disk05/2d-SQE/PIT/2005-06-20.mustang/solaris-sparc/jre/lib/sparc/libcmm.so
0xfadb0000 	/net/sqindia/export/disk05/2d-SQE/PIT/2005-06-20.mustang/solaris-sparc/jre/lib/sparc/libjpeg.so
0xd3380000 	/usr/lib/libcups.so
0xfac60000 	/lib/nss_files.so.1
0xfac40000 	/lib/nss_nis.so.1

VM Arguments:
java_command: javasoft.clientsqe.tonga.TTBuilder PrintDocDestinationTest
Launcher Type: generic

Environment Variables:
LD_LIBRARY_PATH=/net/sqindia/export/disk05/2d-SQE/PIT/2005-06-20.mustang/solaris-sparc/jre/lib/sparc/server:/net/sqindia/export/disk05/2d-SQE/PIT/2005-06-20.mustang/solaris-sparc/jre/lib/sparc:/net/sqindia/export/disk05/2d-SQE/PIT/2005-06-20.mustang/solaris-sparc/jre/../lib/sparc
DISPLAY=divinemelody:0.0

Signal Handlers:
SIGSEGV: [libjvm.so+0x632bcc], sa_mask[0]=0xffbffeff, sa_flags=0x00000004
SIGBUS: [libjvm.so+0x632bcc], sa_mask[0]=0xffbffeff, sa_flags=0x00000004
SIGFPE: [libjvm.so+0x21d808], sa_mask[0]=0xffbffeff, sa_flags=0x0000000c
SIGPIPE: SIG_IGN, sa_mask[0]=0x00000000, sa_flags=0x00000000
SIGILL: [libjvm.so+0x21d808], sa_mask[0]=0xffbffeff, sa_flags=0x0000000c
SIGUSR1: SIG_DFL, sa_mask[0]=0x00000000, sa_flags=0x00000000
SIGUSR2: SIG_DFL, sa_mask[0]=0x00000000, sa_flags=0x00000000
SIGHUP: [libjvm.so+0x5afe08], sa_mask[0]=0xffbffeff, sa_flags=0x00000004
SIGINT: [libjvm.so+0x5afe08], sa_mask[0]=0xffbffeff, sa_flags=0x00000004
SIGQUIT: [libjvm.so+0x5afe08], sa_mask[0]=0xffbffeff, sa_flags=0x00000004
SIGTERM: [libjvm.so+0x5afe08], sa_mask[0]=0xffbffeff, sa_flags=0x00000004


---------------  S Y S T E M  ---------------

OS:                         Solaris 10 3/05 s10_74L2a SPARC
           Copyright 2005 Sun Microsystems, Inc.  All Rights Reserved.
                        Use is subject to license terms.
                            Assembled 22 January 2005

uname:SunOS 5.10 Generic sun4u  (T2 libthread)
rlimit: STACK 8192k, CORE infinity, NOFILE 65536, AS infinity
load average:0.23 0.40 0.33

CPU:total 2 has_v8, has_v9, has_vis1, has_vis2, is_ultra3

Memory: 8k page, physical 2097152k(1566816k free)

vm_info: Java HotSpot(TM) Server VM (1.6.0-ea-b41) for solaris-sparc, built on Jun 16 2005 02:33:16 by  with unknown Workshop:0x570

###@###.### 2005-06-24 13:56:18 GMT

I tried it on d2-sunblade and it is not reproducible. But it is reproducible on jlab322.india. The workaround provided in this bug report actually works and I don't see any VM crash or hang when I turn off the polling.

I will try installing ESPPrintPro on another Sol10 machine and check whether it is reproducible. Will keep the state 'incomplete' until I update the bug with this information.

I have downloaded and installed the evaluation version of ESPPrintPro 4.5.4 on another SolarisSparc10 (SunBlade 2500) machine and the VM crash is still reproducible with Mustang-b45. No such crash is seen when turning off the polling. I have selected the following option when configuring the printer:
->LPD Printer
-> Print Server: pr-cblr03-01.india.sun.com,   Queue: photon
-> Driver: Xerox Docuprint N4025PS
Will investigate more on the configuration. I have attached the new log file.

I have compared the 2 machines and there are no obvious differences that could impact printing. So I don't know what to look for exactly. I tried connnecting my printer in india to d2-sunblade and even then it is not reproducible. Likewise, I tried connecting a network printer (available locally) directly to my machine without going through the print server. The hang/crash is reproducible even in this case. Need some guidance on what I should look for, when comparing these 2 configurations. For debugging, you can use the following info:

Reproducible on jlab322.india.sun.com, divinemelody.india.sun.com. 
Printer configured: photon from pr-cblr03-01.india.sun.com - Xerox Docuprint N4025.
I am reproduce the bug with b45 located at /net/sqindia.india/export/disk09/jdk/1.6.0/latest/binaries/solsparc.

Comments
EVALUATION Changing defer to close as not reproducible. Submitter can reopen this after submitting a configuration to reproduce it here at our site.
07-09-2005

EVALUATION Looks like this is caused by multiple calls to CUPS' httpInitialize/httpConnect but since this seems to be specific to a certain configuration, hard to tell if this is really a bug in JDK. Will be deferring this bug until submitter can give us specific system configuration to reproduce this bug.
31-08-2005

EVALUATION Tried on d2-sunblade which has ESPPPrintPro and CUPS and could not reproduce. Asked submitter to try it on same machine to find out the difference in environment that's causing the bug. Marking incomplete.
01-08-2005

EVALUATION Seems like specific to ESPPrintPro because I tried in my solaris 10 without ESPPP and could not reproduce it. Maybe a threading issue between the polling and the ESPPP. ###@###.### 2005-07-11 20:40:58 GMT
11-07-2005

WORK AROUND Use -Dsun.java2d.print.polling=false ###@###.### 2005-07-11 20:40:58 GMT
11-07-2005