Hi,
I'm testing the Security configurations in Chapter 7 of the WSIT Tutorial
with GF b16, Netbeans 5.5 Beta2, wsit module 1.31 on Windows.
Although, I've been able to create the web service and client projects,
build, deploy, and run them, looking at Glassfish's server logs shows
something is seriously wrong. I was seeing lots of warnings that
seemed to be repeating over and over. After a while, the server.log
began showed
> [#|2006-09-12T10:42:07.484-0400|WARNING|sun-appserver-pe9.1|javax.enterprise.system.stream.err|_ThreadID=1815;_ThreadName=Thread-1829;_RequestID=1dc2d457-f8b9-4b03-ba8a-f66fab238cb3;|
> java.util.logging.ErrorManager: 4: FATAL ERROR: COULD NOT OPEN LOG
> FILE..|#]
>
> [#|2006-09-12T10:42:07.500-0400|WARNING|sun-appserver-pe9.1|javax.enterprise.system.stream.err|_ThreadID=1815;_ThreadName=Thread-1829;_RequestID=1dc2d457-f8b9-4b03-ba8a-f66fab238cb3;|
> java.io.FileNotFoundException:
> F:\Sun\glassfish\domains\domain1\logs\server.log (The requested
> operation cannot be performed on a file with a user-mapped section open)
> at java.io.FileOutputStream.open(Native Method)
> at java.io.FileOutputStream.<init>(FileOutputStream.java:179)
> at java.io.FileOutputStream.<init>(FileOutputStream.java:70)
> at
> com.sun.enterprise.server.logging.FileandSyslogHandler$1.run(FileandSyslogHandler.java:381)
> at java.security.AccessController.doPrivileged(Native Method)
> at
> com.sun.enterprise.server.logging.FileandSyslogHandler.rotate(FileandSyslogHandler.java:353)
> at
> com.sun.enterprise.server.logging.FileandSyslogHandler.publish(FileandSyslogHandler.java:492)
> at
> com.sun.enterprise.server.logging.FileandSyslogHandler.publish(FileandSyslogHandler.java:496)
> at
> com.sun.enterprise.server.logging.FileandSyslogHandler.publish(FileandSyslogHandler.java:496)
> at
> com.sun.enterprise.server.logging.FileandSyslogHandler.publish(FileandSyslogHandler.java:496)
> at
> com.sun.enterprise.server.logging.FileandSyslogHandler.publish(FileandSyslogHandler.java:496)
> at
> com.sun.enterprise.server.logging.FileandSyslogHandler.publish(FileandSyslogHandler.java:496)
> at
> com.sun.enterprise.server.logging.FileandSyslogHandler.publish(FileandSyslogHandler.java:496)
> at
> com.sun.enterprise.server.logging.FileandSyslogHandler.publish(FileandSyslogHandler.java:496)
> at
> com.sun.enterprise.server.logging.FileandSyslogHandler.publish(FileandSyslogHandler.java:496)
> at
> com.sun.enterprise.server.logging.FileandSyslogHandler.publish(FileandSyslogHandler.java:496)
> at
> com.sun.enterprise.server.logging.FileandSyslogHandler.publish(FileandSyslogHandler.java:496)
The log directory for domain1 shows lots of logs are being created, see
listing below, and they
are filled with message like above
> F:\Sun\glassfish\domains\domain1\logs>dir
> Volume in drive F has no label.
> Volume Serial Number is 347C-123C
>
> Directory of F:\Sun\glassfish\domains\domain1\logs
>
> 09/12/2006 10:42 AM <DIR> .
> 09/12/2006 10:42 AM <DIR> ..
> 09/12/2006 09:40 AM <DIR> access
> 09/12/2006 10:42 AM 2,005,449 server.log
> 09/12/2006 10:41 AM 2,000,161 server.log_2006-09-12T10-41-46
> 09/12/2006 10:41 AM 2,000,161 server.log_2006-09-12T10-41-47
> 09/12/2006 10:41 AM 2,000,161 server.log_2006-09-12T10-41-48
> 09/12/2006 10:41 AM 2,000,161 server.log_2006-09-12T10-41-49
> 09/12/2006 10:41 AM 2,000,161 server.log_2006-09-12T10-41-50
> 09/12/2006 10:41 AM 2,000,161 server.log_2006-09-12T10-41-51
> 09/12/2006 10:41 AM 2,000,161 server.log_2006-09-12T10-41-52
> 09/12/2006 10:41 AM 2,000,161 server.log_2006-09-12T10-41-53
> 09/12/2006 10:41 AM 2,000,161 server.log_2006-09-12T10-41-54
> 09/12/2006 10:41 AM 2,000,161 server.log_2006-09-12T10-41-55
> 09/12/2006 10:41 AM 2,000,161 server.log_2006-09-12T10-41-56
> 09/12/2006 10:41 AM 2,000,161 server.log_2006-09-12T10-41-57
> 09/12/2006 10:41 AM 2,000,161 server.log_2006-09-12T10-41-58
> 09/12/2006 10:42 AM 2,000,161 server.log_2006-09-12T10-41-59
> 09/12/2006 10:42 AM 2,000,161 server.log_2006-09-12T10-42-00
> 09/12/2006 10:42 AM 2,000,161 server.log_2006-09-12T10-42-01
> 09/12/2006 10:42 AM 2,000,161 server.log_2006-09-12T10-42-02
> 09/12/2006 10:42 AM 2,000,161 server.log_2006-09-12T10-42-03
> 09/12/2006 10:42 AM 2,000,161 server.log_2006-09-12T10-42-04
> 09/12/2006 10:42 AM 2,000,161 server.log_2006-09-12T10-42-05
> 09/12/2006 10:42 AM 2,000,161 server.log_2006-09-12T10-42-06
> 09/12/2006 10:42 AM 2,000,161 server.log_2006-09-12T10-42-07
> 09/12/2006 10:42 AM 2,000,161 server.log_2006-09-12T10-42-08
> 09/12/2006 10:42 AM 2,000,161 server.log_2006-09-12T10-42-09
> 09/12/2006 10:42 AM 2,000,161 server.log_2006-09-12T10-42-10
> 09/12/2006 10:42 AM 2,006,787 server.log_2006-09-12T10-42-11
> 09/12/2006 10:42 AM 2,006,317 server.log_2006-09-12T10-42-12
> 09/12/2006 10:42 AM 2,005,315 server.log_2006-09-12T10-42-13
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-14
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-15
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-16
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-17
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-18
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-19
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-20
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-21
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-22
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-23
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-24
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-25
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-26
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-27
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-28
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-29
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-30
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-31
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-32
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-33
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-34
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-35
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-36
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-37
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-38
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-39
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-40
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-41
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-42
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-43
> 09/12/2006 10:42 AM 2,005,449 server.log_2006-09-12T10-42-44
> 60 File(s) 120,196,812 bytes
> 3 Dir(s) 24,120,672,256 bytes free
>
> F:\Sun\glassfish\domains\domain1\logs>
Before the runaway logging began, on running the wist-enabled secure sample
web service the logs were showing lots of these warnings
> Sending heartbeat message for sequence
> uuid:609dfe92-22d3-4dd5-8450-c193092b206d|#]
>
> [#|2006-09-12T09:48:25.718-0400|WARNING|sun-appserver-pe9.1|javax.enterprise.system.stream.err|_ThreadID=207;_ThreadName=Thread-222;_RequestID=25e7d1d7-de26-469b-8676-9d2dd2751705;|com.sun.xml.ws.rm.RMException
> at
> com.sun.xml.ws.rm.jaxws.runtime.client.ProtocolMessageSender.sendAckRequested(ProtocolMessageSender.java:268)
> at
> com.sun.xml.ws.rm.jaxws.runtime.client.ClientOutboundSequence$AckRequestedSender.run(ClientOutboundSequence.java:529)
> |#]
>
> [#|2006-09-12T09:48:26.546-0400|INFO|sun-appserver-pe9.1|javax.enterprise.system.stream.out|_ThreadID=208;_ThreadName=Thread-223;|
> Sending heartbeat message for sequence
> uuid:609dfe92-22d3-4dd5-8450-c193092b206d|#]
>
> [#|2006-09-12T09:48:26.562-0400|WARNING|sun-appserver-pe9.1|javax.enterprise.system.stream.err|_ThreadID=208;_ThreadName=Thread-223;_RequestID=100c9167-258a-42da-aaf4-e160167b3fe2;|
> com.sun.xml.ws.rm.RMException
> at
> com.sun.xml.ws.rm.jaxws.runtime.client.ProtocolMessageSender.sendAckRequested(ProtocolMessageSender.java:268)
> at
> com.sun.xml.ws.rm.jaxws.runtime.client.ClientOutboundSequence$AckRequestedSender.run(ClientOutboundSequence.java:529)
> |#]
>
> [#|2006-09-12T09:48:28.546-0400|INFO|sun-appserver-pe9.1|javax.enterprise.system.stream.out|_ThreadID=209;_ThreadName=Thread-224;|
> Sending heartbeat message for sequence
> uuid:609dfe92-22d3-4dd5-8450-c193092b206d|#]
>
> [#|2006-09-12T09:48:28.562-0400|WARNING|sun-appserver-pe9.1|javax.enterprise.system.stream.err|_ThreadID=209;_ThreadName=Thread-224;_RequestID=8cb82291-8c6d-4ec9-9fe9-4ea0a5c48622;|
> com.sun.xml.ws.rm.RMException
> at
> com.sun.xml.ws.rm.jaxws.runtime.client.ProtocolMessageSender.sendAckRequested(ProtocolMessageSender.java:268)
> at
> com.sun.xml.ws.rm.jaxws.runtime.client.ClientOutboundSequence$AckRequestedSender.run(ClientOutboundSequence.java:529)
> |#]
>
> [#|2006-09-12T09:48:30.546-0400|INFO|sun-appserver-pe9.1|javax.enterprise.system.stream.out|_ThreadID=210;_ThreadName=Thread-225;|
and on running the client servlet, the logs shows lots of these warnings
> Sending heartbeat message for sequence
> uuid:609dfe92-22d3-4dd5-8450-c193092b206d|#]
>
> [#|2006-09-12T10:41:40.609-0400|WARNING|sun-appserver-pe9.1|javax.enterprise.system.stream.err|_ThreadID=1812;_ThreadName=Thread-1826;_RequestID=44c8e7df-2199-454c-8b02-9e499bab50e8;|
> Exception in thread "Thread-1826" |#]
>
> [#|2006-09-12T10:41:40.609-0400|WARNING|sun-appserver-pe9.1|javax.enterprise.system.stream.err|_ThreadID=1812;_ThreadName=Thread-1826;_RequestID=44c8e7df-2199-454c-8b02-9e499bab50e8;|java.lang.NullPointerException
> at
> org.apache.catalina.loader.WebappClassLoader.findResources(WebappClassLoader.java:1048)
> at java.lang.ClassLoader.getResources(ClassLoader.java:1015)
> at sun.misc.Service$LazyIterator.hasNext(Service.java:249)
> at
> javax.xml.ws.addressing.AddressingBuilderFactory.newInstance(AddressingBuilderFactory.java:93)
> at
> javax.xml.ws.addressing.AddressingBuilder.newInstance(AddressingBuilder.java:56)
> at
> com.sun.xml.ws.rm.jaxws.runtime.client.ProtocolMessageSender.addAddressingHeaders(ProtocolMessageSender.java:297)
> at
> com.sun.xml.ws.rm.jaxws.runtime.client.ProtocolMessageSender.sendAckRequested(ProtocolMessageSender.java:260)
> at
> com.sun.xml.ws.rm.jaxws.runtime.client.ClientOutboundSequence$AckRequestedSender.run(ClientOutboundSequence.java:529)
> |#]
>
> [#|2006-09-12T10:41:42.609-0400|INFO|sun-appserver-pe9.1|javax.enterprise.system.stream.out|_ThreadID=1813;_ThreadName=Thread-1827;|
> Sending heartbeat message for sequence
> uuid:609dfe92-22d3-4dd5-8450-c193092b206d|#]
>
> [#|2006-09-12T10:41:42.609-0400|WARNING|sun-appserver-pe9.1|javax.enterprise.system.stream.err|_ThreadID=1813;_ThreadName=Thread-1827;_RequestID=6338ffd8-27cb-4937-bbae-64de3d7f4733;|
> Exception in thread "Thread-1827" |#]
>
> [#|2006-09-12T10:41:42.609-0400|WARNING|sun-appserver-pe9.1|javax.enterprise.system.stream.err|_ThreadID=1813;_ThreadName=Thread-1827;_RequestID=6338ffd8-27cb-4937-bbae-64de3d7f4733;|java.lang.NullPointerException
> at
> org.apache.catalina.loader.WebappClassLoader.findResources(WebappClassLoader.java:1048)
> at java.lang.ClassLoader.getResources(ClassLoader.java:1015)
> at sun.misc.Service$LazyIterator.hasNext(Service.java:249)
> at
> javax.xml.ws.addressing.AddressingBuilderFactory.newInstance(AddressingBuilderFactory.java:93)
> at
> javax.xml.ws.addressing.AddressingBuilder.newInstance(AddressingBuilder.java:56)
> at
> com.sun.xml.ws.rm.jaxws.runtime.client.ProtocolMessageSender.addAddressingHeaders(ProtocolMessageSender.java:297)
> at
> com.sun.xml.ws.rm.jaxws.runtime.client.ProtocolMessageSender.sendAckRequested(ProtocolMessageSender.java:260)
> at
> com.sun.xml.ws.rm.jaxws.runtime.client.ClientOutboundSequence$AckRequestedSender.run(ClientOutboundSequence.java:529)
> |#]
>
> [#|2006-09-12T10:41:44.609-0400|INFO|sun-appserver-pe9.1|javax.enterprise.system.stream.out|_ThreadID=1814;_ThreadName=Thread-1828;|
> Sending heartbeat message for sequence
> uuid:609dfe92-22d3-4dd5-8450-c193092b206d|#]
>
> [#|2006-09-12T10:41:44.609-0400|WARNING|sun-appserver-pe9.1|javax.enterprise.system.stream.err|_ThreadID=1814;_ThreadName=Thread-1828;_RequestID=603833e5-c967-4443-99ae-182bf354d926;|
> Exception in thread "Thread-1828" |#]
>
> [#|2006-09-12T10:41:44.609-0400|WARNING|sun-appserver-pe9.1|javax.enterprise.system.stream.err|_ThreadID=1814;_ThreadName=Thread-1828;_RequestID=603833e5-c967-4443-99ae-182bf354d926;|java.lang.NullPointerException
> at
> org.apache.catalina.loader.WebappClassLoader.findResources(WebappClassLoader.java:1048)
> at java.lang.ClassLoader.getResources(ClassLoader.java:1015)
> at sun.misc.Service$LazyIterator.hasNext(Service.java:249)
> at
> javax.xml.ws.addressing.AddressingBuilderFactory.newInstance(AddressingBuilderFactory.java:93)
> at
> javax.xml.ws.addressing.AddressingBuilder.newInstance(AddressingBuilder.java:56)
> at
> com.sun.xml.ws.rm.jaxws.runtime.client.ProtocolMessageSender.addAddressingHeaders(ProtocolMessageSender.java:297)
> at
> com.sun.xml.ws.rm.jaxws.runtime.client.ProtocolMessageSender.sendAckRequested(ProtocolMessageSender.java:260)
> at
> com.sun.xml.ws.rm.jaxws.runtime.client.ClientOutboundSequence$AckRequestedSender.run(ClientOutboundSequence.java:529)
> |#]
>
> [#|2006-09-12T10:41:46.609-0400|INFO|sun-appserver-pe9.1|javax.enterprise.system.stream.out|_ThreadID=1815;_ThreadName=Thread-1829;|
> Sending heartbeat message for sequence
> uuid:609dfe92-22d3-4dd5-8450-c193092b206d|#]
>
I think Glassfish is pretty much hosed at this point. I tried making
changes to
the client servlet to get a different result and still get the original
result, so
the new war isn't getting deployed even though NetBeans says it is.
Also, the Admin Console is unusable now. Clicking on any link gives
an Alert saying "This document cannot be displayed while offlline".
Tom