Friday, 14 November 2014

Hmmmm, HTTP404 and SRVE0190E seen with IBM HTTP Server and WebSphere Application Server

Hmm, so I am seeing this: -

Error 404: java.io.FileNotFoundException: SRVE0190E: File not found: /index.html

when I attempt to access a HTML page from IBM HTTP Server via HTTPS: -


even though I can get the page via HTTP: -


This is part of an IBM BPM Advanced 8.5.5 infrastructure, and the most recent change was to add IHS into the mix, federate it into the WAS cell, and add a Virtual Host entry for port 8443: -

cellID=AdminControl.getCell() 
AdminConfig.create('HostAlias', AdminConfig.getid('/Cell:'+cellID+'/VirtualHost:default_host/'), '[[hostname "*"] [port "8443"]]') 
AdminConfig.save() 
AdminNodeManagement.syncActiveNodes() 
quit 


I tried enabling further debugging in IHS by changing: -

LogLevel warn

to: -

LogLevel debug

in: -

/opt/IBM/HTTPServer/conf/httpd.conf

but the only thing that popped up in access_log was: -

192.168.1.70 - - [14/Nov/2014:15:08:26 +0000] "GET / HTTP/1.1" 404 42

and nothing useful in error_log.

I wondered whether the problem was related to the WAS Plugin, which was configured at the end of httpd.conf : -

LoadModule was_ap22_module "/opt/IBM/WebSphere/Plugins/bin/64bits/mod_was_ap22_http.so"
WebSpherePluginConfig /opt/IBM/WebSphere/Plugins/config/webserver1/plugin-cfg.xml

so I temporarily commented out both lines, and restarted IHS.

At that point, getting index.html via HTTP *and* HTTPS worked a treat.

So it's definitely somehow related to the Plugin and/or WAS.

I enabled debug in the plugin, by changing: -

   <Log LogLevel="Error" Name="/opt/IBM/WebSphere/Plugins/logs/webserver1/http_plugin.log"/>

to: -

   <Log LogLevel="Debug" Name="/opt/IBM/WebSphere/Plugins/logs/webserver1/http_plugin.log"/>

in: -

/opt/IBM/WebSphere/Plugins/config/webserver1/plugin-cfg.xml 

and can see: -

[14/Nov/2014:15:01:23.89900] 000045c2 057fb700 - DETAIL:    GET /index.html HTTP/1.1
[14/Nov/2014:15:01:23.89901] 000045c2 057fb700 - DETAIL:    Host: bpm855.uk.ibm.com:8443
[14/Nov/2014:15:01:23.89901] 000045c2 057fb700 - DETAIL:    Cache-Control: max-age=0
[14/Nov/2014:15:01:23.89902] 000045c2 057fb700 - DETAIL:    Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8
[14/Nov/2014:15:01:23.89902] 000045c2 057fb700 - DETAIL:    User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.122 Safari/537.36
[14/Nov/2014:15:01:23.89903] 000045c2 057fb700 - DETAIL:    DNT: 1
[14/Nov/2014:15:01:23.89903] 000045c2 057fb700 - DETAIL:    Accept-Encoding: gzip,deflate,sdch
[14/Nov/2014:15:01:23.89904] 000045c2 057fb700 - DETAIL:    Accept-Language: en-US,en;q=0.8
[14/Nov/2014:15:01:23.89905] 000045c2 057fb700 - DETAIL:    Cookie: JSESSIONID=00002GxGEWjz6XsUDTV69LDQYmi:196509vjn; CoreID6=40736703432114159613577&ci=50200000|ESTKCS; UnicaNIODID=JOlYGvtFslm-Y5kRjJ7; CoreM_State=72~-1~-1~-1~-1~3~3~5~3~3~7~7~|~~|~~|~~|~||||||~|~~|~~|~~|~~|~~|~~|~~|~; CoreM_State_Content=6~|~38D1983DAF0161AD~|~0; 50200000|ESTKCS_clogin=v=1&l=1415961357&e=1415963160646; LtpaToken2=ELcJ3s000hNQAmekT9IFK4NhSC419BFnN4WsQxjSBdXOIt78jL/UVc/tSQd4p+wBCpygJwkLG51qhZQcYOoZN0PNsYOwLyow8ERnvf4jeWyqw45ZetsBSErQjemaZHoHXMyO8c85FdH4edxT5M5AFdojKPpKKAabTKe94Jm2KAlsGb6Mw5BkQMkVIIocUMqTFqpoyBxmxGbADGAjJ86eiI+1MtYQXVFYggAIevtQllckeB77xEkionOnm1q0POYq+5CLdjVpGxXE0sizd2vua5iySBjWoIuIR6pfhfBw8DE8htetEXvHzJlDBErGXcUdo43zMeQQINzSxAYzWsEvlxjxCqYEuEpYSzplj7Kf8RmM4QSjtYWc+v9ZmHYgGBA9; sessionCode=514564614; TJE=; TE3=
[14/Nov/2014:15:01:23.89905] 000045c2 057fb700 - DETAIL:    $WSCS: TLS_RSA_WITH_AES_128_GCM_SHA256
[14/Nov/2014:15:01:23.89906] 000045c2 057fb700 - DETAIL:    $WSIS: true
[14/Nov/2014:15:01:23.89907] 000045c2 057fb700 - DETAIL:    $WSSC: https
[14/Nov/2014:15:01:23.89907] 000045c2 057fb700 - DETAIL:    $WSPR: HTTP/1.1
[14/Nov/2014:15:01:23.89908] 000045c2 057fb700 - DETAIL:    $WSRA: 192.168.1.70
[14/Nov/2014:15:01:23.89908] 000045c2 057fb700 - DETAIL:    $WSRH: 192.168.1.70
[14/Nov/2014:15:01:23.89909] 000045c2 057fb700 - DETAIL:    $WSSN: bpm855.uk.ibm.com
[14/Nov/2014:15:01:23.89909] 000045c2 057fb700 - DETAIL:    $WSSP: 8443
[14/Nov/2014:15:01:23.89910] 000045c2 057fb700 - DETAIL:    $WSSI: wkUAAOMXLq4ktsQ6fdbYIboGeENYWFhYQxlmVAAAAAI=
[14/Nov/2014:15:01:23.89910] 000045c2 057fb700 - DETAIL:    Surrogate-Capability: WS-ESI="ESI/1.0+"
[14/Nov/2014:15:01:23.89911] 000045c2 057fb700 - DETAIL:    _WS_HAPRT_WLMVERSION: -1
[14/Nov/2014:15:01:23.89916] 000045c2 057fb700 - DEBUG: ws_common: websphereExecute: Wrote the request; reading the response (timeout 900)
[14/Nov/2014:15:01:23.89917] 000045c2 057fb700 - DETAIL: lib_htresponse: htresponseRead: Reading the response: f002ab30
[14/Nov/2014:15:01:23.90631] 000045c2 057fb700 - DETAIL:    HTTP/1.1 404 Not Found
[14/Nov/2014:15:01:23.90637] 000045c2 057fb700 - DETAIL:    X-Powered-By: Servlet/3.0
[14/Nov/2014:15:01:23.90638] 000045c2 057fb700 - DETAIL:    Content-Type: text/html;charset=ISO-8859-1
[14/Nov/2014:15:01:23.90639] 000045c2 057fb700 - DETAIL:    $WSEP:
[14/Nov/2014:15:01:23.90639] 000045c2 057fb700 - DETAIL:    Content-Language: en-GB


in: -

/opt/IBM/WebSphere/Plugins/logs/webserver1/http_plugin.log

So this suggests that the request is being forwarded, by IHS, via the WAS Plugin, to WAS.

So I drilled into the plugin-cfg.xml file a bit more.

Logic dictated that the problem was somehow related to the context root of the URL, in that the page I'm requesting - /index.html - doesn't have the usual context root of, say, /ProcessCenter or /ProcessPortal.

Lo and behold, in plugin-cfg.xml, I can see: -

   <ServerCluster CloneSeparatorChange="false" GetDWLMTable="false" IgnoreAffinityRequests="false" LoadBalance="Round Robin" Name="dmgr_Dmgr_Cluster" PostBufferSize="0" PostSizeLimit="-1" RemoveSpecialHeaders="true" RetryInterval="60" ServerIOTimeoutRetry="-1">
      <Server ConnectTimeout="0" ExtendedHandshake="false" MaxConnections="-1" Name="Dmgr_dmgr" ServerIOTimeout="900" WaitForContinue="false"/>
   </ServerCluster>
   <UriGroup Name="default_host_AppCluster_URIs">
...
<Uri AffinityCookie="JSESSIONID" AffinityURLIdentifier="jsessionid" Name="/*"/>
...
   </UriGroup>
   <Route ServerCluster="AppCluster" UriGroup="default_host_AppCluster_URIs" VirtualHostGroup="default_host"/>

Now where did that little sucker come from ?

I checked the source, which is held at the WAS cell level: -

/opt/IBM/WebSphere/AppServer/profiles/Dmgr01/config/cells/PCCell1/nodes/Node1/servers/webserver1

which has the same thing.

I'm going to retrace my steps but .... at least I have a successful resolution / circumvention, which is nice.

2 comments:

Unknown said...

Have you found a permanent solution to this? I'm having a similar issue with WebSphere 8.5 and Maximo 7.6. I have a PMR in with IBM, but they have been slow to respond.

Dave Hay said...

Hi Chris, nope, I've not seen the problem since. It looks like I had an application in WAS that, when I mapped it to the federated-in IHS, added the URI pattern for the context root of / rather than, say, /mum or /rest or /snoop.

Once I worked out the symptom i.e. the malformed URI in the plugin configuration, and removed it, it was all good :-)

Yay, VMware Fusion and macOS Big Sur - no longer "NAT good friends" - forgive the double negative and the terrible pun ...

After macOS 11 Big Sur was released in 2020, VMware updated their Fusion product to v12 and, sadly, managed to break Network Address Trans...