Advanced - Powered by Google


   
Log In
New Account
  
 
Home
My Page
Project Tree
Project Openings
Funambol
          
 
 
Summary
Tracker
Lists
Tasks
Docs
News
CVS
Files
                
 

Tracker: Bugs

Submit New | Browse | Admin | ExportToXml

[ #305833 ] processInitSyncMapMessage() NPE

Date:
2006-07-27 03:51
Priority:
5
Submitted By:
Mark Swanson (markswanson)
Assigned To:
Nobody (None)
Category:
server ds
State:
Open
Summary:
processInitSyncMapMessage() NPE

Detailed description:
Server 3.0b5 - This happens every time with some devices: This code block: if (!isAuthenticated()) { response = init.getResponseMessage(msgId); } else { Must set init if it is null, or provide a useful error message that can help debug this problem - that happens regularly... [Jul 10, 2006 6:50:19 PM][funambol.server] FINEST: Calling input pipeline [Jul 10, 2006 6:50:19 PM][funambol.handler] FINEST: current state: STATE_START [Jul 10, 2006 6:50:19 PM][funambol.handler] FINEST: moving to state STATE_PKG1_R ECEIVING [Jul 10, 2006 6:50:19 PM][funambol.handler] FINEST: Server auhenticated (code 20 0) [Jul 10, 2006 6:50:19 PM][funambol.handler] FINER: THROW java.lang.NullPointerException at com.funambol.server.session.SyncSessionHandler.processInitSyncMapMessage( SyncSessionHandler.java:850) at com.funambol.server.session.SyncSessionHandler.processMessage(SyncSession Handler.java:438) at com.funambol.server.engine.SyncAdapter.processInputMessage(SyncAdapter.ja va:459) at com.funambol.server.engine.SyncAdapter.processXMLMessage(SyncAdapter.java :217)

Add A Comment:

Please login

Followup

Message
Date: 2007-03-13 19:51
Sender: cvidal
Logged In: YES 
user_id=10868

> It seems like 305085/303691/303703.
> 
> Could you post the full server log ?

Just look at the code, as I wrote before, the code assumes
that you cannot get to line 850 without an initialized
'init' object, so when this happens the server crashes
miserably and the client gets a error code 511.

IMHO the first thing to do is fix this issue with a proper
error message. Then try to trace (via logs and user
feedback) under which conditions 'init' is not initialized.

Carlos
Date: 2007-03-12 23:18
Sender: martinlong1978
Logged In: YES 
user_id=11949

I'm guessing that this works for most people, as this hasn't
been updated since October, and doesn't seem to be very high
priority. I'm trying to work out what I'm doing differently,
or what is different about my data. Does anyone know of the
workaround?
Date: 2007-03-12 23:17
Sender: martinlong1978
Logged In: YES 
user_id=11949

I'm guessing that this works for most people, as this hasn't
been updated since October, and doesn't seem to be very high
priority. I'm trying to work out what I'm doing differently,
or what is different about my data. Does anyone know of the
workaround?
Date: 2007-03-12 23:03
Sender: martinlong1978
Logged In: YES 
user_id=11949

I'm getting the same:


[Mar 12, 2007 9:48:19 PM][funambol.handler] FINEST: current
state: STATE_START
[Mar 12, 2007 9:48:19 PM][funambol.handler] FINEST: moving
to state STATE_PKG1_RECEIVING
[Mar 12, 2007 9:48:19 PM][funambol.handler] FINEST: Server
auhenticated (code 200)
[Mar 12, 2007 9:48:19 PM][funambol.handler] FINER: THROW
java.lang.NullPointerException
        at
com.funambol.server.session.SyncSessionHandler.processInitSyncMap
Message(SyncSessionHandler.java:850)
        at
com.funambol.server.session.SyncSessionHandler.processMessage(Syn
cSessionHandler.java:440)
        at
com.funambol.server.engine.SyncAdapter.processInputMessage(SyncAd
apter.java:459)
        at
com.funambol.server.engine.SyncAdapter.processXMLMessage(SyncAdap
ter.java:215)
        at
com.funambol.transport.http.server.LocalSyncHolder.processXMLMess
age(LocalSyncHolder.java:80)
        at
com.funambol.transport.http.server.Sync4jServlet.doPost(Sync4jSer
vlet.java:297)
        at
javax.servlet.http.HttpServlet.service(HttpServlet.java:709)
        at
javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
        at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(
ApplicationFilterChain.java:252)
        at
org.apache.catalina.core.ApplicationFilterChain.doFilter(Applicat
ionFilterChain.java:173)
        at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrap
perValve.java:214)
        at
org.apache.catalina.core.StandardValveContext.invokeNext(Standard
ValveContext.java:104)
        at
org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline
.java:520)
        at
org.apache.catalina.core.StandardContextValve.invokeInternal(Stan
dardContextValve.java:198)
        at
org.apache.catalina.core.StandardContextValve.invoke(StandardCont
extValve.java:152)
        at
org.apache.catalina.core.StandardValveContext.invokeNext(Standard
ValveContext.java:104)
        at
org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline
.java:520)
        at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostVal
ve.java:137)
        at
org.apache.catalina.core.StandardValveContext.invokeNext(Standard
ValveContext.java:104)
        at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportVal
ve.java:118)
        at
org.apache.catalina.core.StandardValveContext.invokeNext(Standard
ValveContext.java:102)
        at
org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline
.java:520)
        at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngin
eValve.java:109)
        at
org.apache.catalina.core.StandardValveContext.invokeNext(Standard
ValveContext.java:104)
        at
org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline
.java:520)
        at
org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:
929)
        at
org.apache.coyote.tomcat5.CoyoteAdapter.service(CoyoteAdapter.jav
a:160)
        at
org.apache.coyote.http11.Http11Processor.process(Http11Processor.
java:799)
        at
org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.p
rocessConnection(Http11Protocol.java:705)
        at
org.apache.tomcat.util.net.TcpWorkerThread.runIt(PoolTcpEndpoint.
java:577)
        at
org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(Thr
eadPool.java:684)
        at java.lang.Thread.run(Unknown Source)
Date: 2006-10-27 20:05
Sender: cvidal
Logged In: YES 
user_id=10868

Hi:

I have the same behavior. I'm using a QTek M3100 from Orange
(FR) with Win Mobile. I installed the PPC funambol package
without problems, and funambol-3.0a on Linux on the server side.

The log looks exactly the same as Mark's.

I also agree with him that the code is not robust enough
around line 850. The code assumes that you cannot get to
line 850 without an initialized 'init' object, so when this
happens the server crashes miserably and the client gets a 
error code 511.

The communication is active, client and server exchange a
few messages, the device ID is seen by the server, then it
finds the scard database, then it does the synchronization
(I see a "INFO" log entry in the server with the device
ID
saying so), but at the end of the conversation it hits this
problem.

I enclose the full log on the server side.

Carlos

--------------------------
[Oct 27, 2006 7:57:03 PM][funambol.transport.http] FINEST:
Http header:
[Oct 27, 2006 7:57:03 PM][funambol.transport.http] FINEST:
accept: */*
[Oct 27, 2006 7:57:03 PM][funambol.transport.http] FINEST:
content-type: application/vnd.syncml+xml
[Oct 27, 2006 7:57:03 PM][funambol.transport.http] FINEST:
content-length: 725
[Oct 27, 2006 7:57:03 PM][funambol.transport.http] FINEST:
user-agent: Windows Mobile Plug in 3.0.31
[Oct 27, 2006 7:57:03 PM][funambol.transport.http] FINEST:
host: mytest.asso.fr:8080
[Oct 27, 2006 7:57:03 PM][funambol.transport.http] FINEST:
cache-control: no-cache
[Oct 27, 2006 7:57:03 PM] INFO: Handling incoming request:
http://mytest.asso.fr:8080/funambol/ds
[Oct 27, 2006 7:57:03 PM] INFO: Requested sessionId: null
[Oct 27, 2006 7:57:03 PM][funambol.transport.http] FINEST:
contentType: application/vnd.syncml+xml
[Oct 27, 2006 7:57:03 PM][funambol.transport.http] FINEST:
contentLength: 725
[Oct 27, 2006 7:57:03 PM][funambol.transport.http] FINEST:
cache:
{C568F09865675F3398D092933C690DCF=com.funambol.transport.http.ser
ver.LocalSyncHolder@11b92e6}
[Oct 27, 2006 7:57:03 PM][funambol.transport.http] FINEST:
Searching holder with sessionId:
0BB0997B4557C3FD046CD6202D6964DC
[Oct 27, 2006 7:57:03 PM][funambol.transport.http] FINEST:
Holder not found. A new holder will be created
[Oct 27, 2006 7:57:03 PM][funambol.transport.http] FINEST:
Cleaning procedure...
[Oct 27, 2006 7:57:03 PM][funambol.transport.http] FINEST:
now: 1161971823808
[Oct 27, 2006 7:57:03 PM][funambol.transport.http] FINEST:
CLEANING_PERIOD: 300000
[Oct 27, 2006 7:57:03 PM][funambol.transport.http] FINEST:
lastCleaningTimestamp: 1161971319916
[Oct 27, 2006 7:57:03 PM][funambol.transport.http] FINEST:
holderTimeToLive: 1200000
[Oct 27, 2006 7:57:03 PM][funambol.transport.http] FINEST:
Performing purging...
[Oct 27, 2006 7:57:03 PM][funambol.transport.http] FINEST:
Caching
0BB0997B4557C3FD046CD6202D6964DC(com.funambol.transport.http.serv
er.LocalSyncHolder@cff49f)
[Oct 27, 2006 7:57:03 PM][funambol.server] FINEST: Message
has content type: application/vnd.syncml+xml
[Oct 27, 2006 7:57:03 PM][funambol.server] FINEST: Charset
(default): UTF-8
[Oct 27, 2006 7:57:03 PM][funambol.server] FINEST: Message
to translate into the SyncML object:
<?xml version="1.0" encoding="UTF-8"?>
<SyncML>
<SyncHdr><VerDTD>1.1</VerDTD>
<VerProto>SyncML/1.1</VerProto>
<SessionID>54353420</SessionID>
<MsgID>1</MsgID>
<Target><LocURI>http://mytest.asso.fr:8080/funambol/d
s</LocURI>
</Target>
<Source><LocURI>fwm-359001607203F5173</LocURI>
</Source>
<Cred><Meta><Format>b64</Format>
<Type>syncml:auth-basic</Type>
</Meta>
<Data>Z3Vlc3Q6Z3Vlc3Q=</Data>
</Cred>
<Meta><MaxMsgSize>16384</MaxMsgSize>
</Meta>
</SyncHdr>
<SyncBody><Alert><CmdID>1</CmdID>
<Data>205</Data>
<Item><Target><LocURI>scard</LocURI>
</Target>
<Source><LocURI>contact</LocURI>
</Source>
<Meta><Anchor><Last>1</Last>
<Next>54353420</Next>
</Anchor>
</Meta>
</Item>
</Alert>
<Final></Final>
</SyncBody>
</SyncML>
[Oct 27, 2006 7:57:03 PM][funambol.server] FINEST: Starting
input canonization
[Oct 27, 2006 7:57:03 PM][funambol.server] FINEST: prolog:
<?xml version="1.0" encoding="UTF-8"?>
[Oct 27, 2006 7:57:03 PM][funambol.server] FINEST: Calling
input pipeline
[Oct 27, 2006 7:57:03 PM][funambol.engine.pipeline] FINEST:
Starting preprocessing
[Oct 27, 2006 7:57:03 PM][funambol.engine.pipeline] FINEST:
com.funambol.foundation.synclet.ChangeSourceUriSynclet.preProcess
Message(...)
[Oct 27, 2006 7:57:03 PM][funambol.engine.pipeline] FINEST:
Change TargetURI into input Alert commands
[Oct 27, 2006 7:57:03 PM][funambol.engine.pipeline] FINEST:
original targetUri: scard
[Oct 27, 2006 7:57:03 PM][funambol.engine.pipeline] FINEST:
Change SourceRef into input Status commands
[Oct 27, 2006 7:57:03 PM][funambol.engine.pipeline] FINEST:
Change TargetURI into input Sync commands
[Oct 27, 2006 7:57:03 PM][funambol.engine.pipeline] FINEST:
Change TargetURI into input Map commands
[Oct 27, 2006 7:57:03 PM][funambol.engine.pipeline] FINEST:
Preprocessed message: <?xml version="1.0"
encoding="UTF-8"?>
<SyncML>
<SyncHdr>
<VerDTD>1.1</VerDTD>
<VerProto>SyncML/1.1</VerProto>
<SessionID>54353420</SessionID>
<MsgID>1</MsgID>
<Target>
<LocURI>http://mytest.asso.fr:8080/funambol/ds</LocURI&g
t;
</Target>
<Source>
<LocURI>fwm-359001607203F5173</LocURI>
</Source>
<Cred>
<Meta>
<Format>b64</Format>
<Type>syncml:auth-basic</Type>
</Meta>
<Data>Z3Vlc3Q6Z3Vlc3Q=</Data>
</Cred>
<Meta>
<MaxMsgSize>16384</MaxMsgSize>
</Meta>
</SyncHdr>
<SyncBody>
<Alert>
<CmdID>1</CmdID>
<Data>205</Data>
<Item>
<Target>
<LocURI>scard</LocURI>
</Target>
<Source>
<LocURI>contact</LocURI>
</Source>
<Meta>
<Anchor xmlns="syncml:metinf">
<Last>1</Last>
<Next>54353420</Next>
</Anchor>
</Meta>
</Item>
</Alert>
<Final></Final>
</SyncBody>
</SyncML>

[Oct 27, 2006 7:57:03 PM][funambol.handler] FINEST: current
state: STATE_START
[Oct 27, 2006 7:57:03 PM][funambol] FINEST: User to check: guest
[Oct 27, 2006 7:57:03 PM][funambol] FINEST: User 'guest' found
[Oct 27, 2006 7:57:03 PM][funambol] FINEST: User authenticate
[Oct 27, 2006 7:57:03 PM][funambol] FINEST: Principal
'guest/fwm-359001607203F5173' found
[Oct 27, 2006 7:57:03 PM] INFO: guest/fwm-359001607203F5173
logged in.
[Oct 27, 2006 7:57:03 PM][funambol.handler] FINEST: moving
to state STATE_PKG1_RECEIVING
[Oct 27, 2006 7:57:03 PM][funambol.handler] FINEST:
Processing the initialization commands
[Oct 27, 2006 7:57:03 PM][funambol.engine] FINEST: Checking
if the database
com.funambol.framework.database.Database@1d7bd04[name=scard,type=
<null>,statusCode=200,target=com.funambol.framework.core.Ta
rget@ba8af9,source=com.funambol.framework.core.Source@fa0094,anch
or=com.funambol.framework.core.Anchor@13c339f,principal=fwm-35900
1607203F5173/guest]
is in the server database list.
[Oct 27, 2006 7:57:03 PM] INFO: fwm-359001607203F5173/guest:
database 'scard' found
[Oct 27, 2006 7:57:03 PM][funambol.handler] FINEST:
Requested databases:
[com.funambol.framework.database.Database@1d7bd04[name=scard,type
=<null>,statusCode=200,target=com.funambol.framework.core.T
arget@ba8af9,source=com.funambol.framework.core.Source@fa0094,anc
hor=com.funambol.framework.core.Anchor@13c339f,principal=fwm-3590
01607203F5173/guest]]
[Oct 27, 2006 7:57:03 PM][funambol.engine] FINEST: adding
com.funambol.framework.engine.source.MemorySyncSource@105e560
- {name: scard, type: unknown, uri: scard}
[Oct 27, 2006 7:57:03 PM][funambol.handler] FINEST: Checking
if MaxMsgSize is larger than the minimum size supported by
the server (2500)
[Oct 27, 2006 7:57:03 PM][funambol.handler] FINEST: moving
to state STATE_PKG3_RECEIVING
[Oct 27, 2006 7:57:03 PM][funambol.server] FINEST: Using the
configured server uri to create the RespURI
[Oct 27, 2006 7:57:03 PM][funambol.server] FINEST: Calling
output pipeline
[Oct 27, 2006 7:57:03 PM][funambol.engine.pipeline] FINEST:
Starting postprocessing
[Oct 27, 2006 7:57:03 PM][funambol.engine.pipeline] FINEST:
Returning message to process: <?xml version="1.0"
encoding="UTF-8"?>
<SyncML>
<SyncHdr>
<VerDTD>1.1</VerDTD>
<VerProto>SyncML/1.1</VerProto>
<SessionID>54353420</SessionID>
<MsgID>1</MsgID>
<Target>
<LocURI>fwm-359001607203F5173</LocURI>
</Target>
<Source>
<LocURI>http://mytest.asso.fr:8080/funambol/ds</LocURI&g
t;
</Source>
<RespURI>mytest.asso.fr;jsessionid=0BB0997B4557C3FD046CD620
2D6964DC</RespURI>
</SyncHdr>
<SyncBody>
<Status>
<CmdID>1</CmdID>
<MsgRef>1</MsgRef>
<CmdRef>0</CmdRef>
<Cmd>SyncHdr</Cmd>
<TargetRef>http://mytest.asso.fr:8080/funambol/ds</Targe
tRef>
<SourceRef>fwm-359001607203F5173</SourceRef>
<Data>212</Data>
</Status>
<Status>
<CmdID>2</CmdID>
<MsgRef>1</MsgRef>
<CmdRef>1</CmdRef>
<Cmd>Alert</Cmd>
<TargetRef>scard</TargetRef>
<SourceRef>contact</SourceRef>
<Data>200</Data>
<Item>
<Data>
<Anchor xmlns="syncml:metinf">
<Next>54353420</Next>
</Anchor>
</Data>
</Item>
</Status>
<Alert>
<CmdID>3</CmdID>
<Data>205</Data>
<Item>
<Target>
<LocURI>contact</LocURI>
</Target>
<Source>
<LocURI>scard</LocURI>
</Source>
<Meta>
<Anchor xmlns="syncml:metinf">
<Last>1161971823829</Last>
<Next>1161971823829</Next>
</Anchor>
</Meta>
</Item>
</Alert>
<Final></Final>
</SyncBody>
</SyncML>

[Oct 27, 2006 7:57:03 PM][funambol.engine.pipeline] FINEST:
com.funambol.foundation.synclet.ChangeSourceUriSynclet.postProces
sMessage(...)
[Oct 27, 2006 7:57:03 PM][funambol.engine.pipeline] FINEST:
Replace TargetRef into output Status commands
[Oct 27, 2006 7:57:03 PM][funambol.engine.pipeline] FINEST:
Replace SourceRef into output Result commands
[Oct 27, 2006 7:57:03 PM][funambol.engine.pipeline] FINEST:
Replace Source into output Alert commands
[Oct 27, 2006 7:57:03 PM][funambol.engine.pipeline] FINEST:
Replace Source into output Sync commands
[Oct 27, 2006 7:57:03 PM][funambol.server] FINEST: Outgoing
message: <?xml version="1.0"
encoding="UTF-8"?>
<SyncML>
<SyncHdr>
<VerDTD>1.1</VerDTD>
<VerProto>SyncML/1.1</VerProto>
<SessionID>54353420</SessionID>
<MsgID>1</MsgID>
<Target>
<LocURI>fwm-359001607203F5173</LocURI>
</Target>
<Source>
<LocURI>http://mytest.asso.fr:8080/funambol/ds</LocURI&g
t;
</Source>
<RespURI>mytest.asso.fr;jsessionid=0BB0997B4557C3FD046CD620
2D6964DC</RespURI>
</SyncHdr>
<SyncBody>
<Status>
<CmdID>1</CmdID>
<MsgRef>1</MsgRef>
<CmdRef>0</CmdRef>
<Cmd>SyncHdr</Cmd>
<TargetRef>http://mytest.asso.fr:8080/funambol/ds</Targe
tRef>
<SourceRef>fwm-359001607203F5173</SourceRef>
<Data>212</Data>
</Status>
<Status>
<CmdID>2</CmdID>
<MsgRef>1</MsgRef>
<CmdRef>1</CmdRef>
<Cmd>Alert</Cmd>
<TargetRef>scard</TargetRef>
<SourceRef>contact</SourceRef>
<Data>200</Data>
<Item>
<Data>
<Anchor xmlns="syncml:metinf">
<Next>54353420</Next>
</Anchor>
</Data>
</Item>
</Status>
<Alert>
<CmdID>3</CmdID>
<Data>205</Data>
<Item>
<Target>
<LocURI>contact</LocURI>
</Target>
<Source>
<LocURI>scard</LocURI>
</Source>
<Meta>
<Anchor xmlns="syncml:metinf">
<Last>1161971823829</Last>
<Next>1161971823829</Next>
</Anchor>
</Meta>
</Item>
</Alert>
<Final></Final>
</SyncBody>
</SyncML>

[Oct 27, 2006 7:57:03 PM][funambol.server] FINEST: Creating
response with charset: UTF-8
[Oct 27, 2006 7:57:03 PM][funambol.server] FINEST: Starting
output canonization
[Oct 27, 2006 7:57:03 PM][funambol.transport.http] FINEST:
Outgoing message length: 1186
[Oct 27, 2006 7:57:03 PM][funambol.transport.http] FINEST:
Finally
[Oct 27, 2006 7:57:05 PM][funambol.transport.http] FINEST:
Http header:
[Oct 27, 2006 7:57:05 PM][funambol.transport.http] FINEST:
accept: */*
[Oct 27, 2006 7:57:05 PM][funambol.transport.http] FINEST:
content-type: application/vnd.syncml+xml
[Oct 27, 2006 7:57:05 PM][funambol.transport.http] FINEST:
content-length: 974
[Oct 27, 2006 7:57:05 PM][funambol.transport.http] FINEST:
user-agent: Windows Mobile Plug in 3.0.31
[Oct 27, 2006 7:57:05 PM][funambol.transport.http] FINEST:
host: mytest.asso.fr:8080
[Oct 27, 2006 7:57:05 PM][funambol.transport.http] FINEST:
cache-control: no-cache
[Oct 27, 2006 7:57:05 PM] INFO: Handling incoming request:
http://mytest.asso.fr:8080/funambol/ds
[Oct 27, 2006 7:57:05 PM] INFO: Requested sessionId: null
[Oct 27, 2006 7:57:05 PM][funambol.transport.http] FINEST:
contentType: application/vnd.syncml+xml
[Oct 27, 2006 7:57:05 PM][funambol.transport.http] FINEST:
contentLength: 974
[Oct 27, 2006 7:57:05 PM][funambol.transport.http] FINEST:
cache:
{0BB0997B4557C3FD046CD6202D6964DC=com.funambol.transport.http.ser
ver.LocalSyncHolder@cff49f,
C568F09865675F3398D092933C690DCF=com.funambol.transport.http.serv
er.LocalSyncHolder@11b92e6}
[Oct 27, 2006 7:57:05 PM][funambol.transport.http] FINEST:
Searching holder with sessionId:
418462F35CF1D3D3927A4DC815A3A92E
[Oct 27, 2006 7:57:05 PM][funambol.transport.http] FINEST:
Holder not found. A new holder will be created
[Oct 27, 2006 7:57:05 PM][funambol.transport.http] FINEST:
Cleaning procedure...
[Oct 27, 2006 7:57:05 PM][funambol.transport.http] FINEST:
now: 1161971825573
[Oct 27, 2006 7:57:05 PM][funambol.transport.http] FINEST:
CLEANING_PERIOD: 300000
[Oct 27, 2006 7:57:05 PM][funambol.transport.http] FINEST:
lastCleaningTimestamp: 1161971823808
[Oct 27, 2006 7:57:05 PM][funambol.transport.http] FINEST:
holderTimeToLive: 1200000
[Oct 27, 2006 7:57:05 PM][funambol.transport.http] FINEST:
No purging required
[Oct 27, 2006 7:57:05 PM][funambol.transport.http] FINEST:
Caching
418462F35CF1D3D3927A4DC815A3A92E(com.funambol.transport.http.serv
er.LocalSyncHolder@1641c0)
[Oct 27, 2006 7:57:05 PM][funambol.server] FINEST: Message
has content type: application/vnd.syncml+xml
[Oct 27, 2006 7:57:05 PM][funambol.server] FINEST: Charset
(default): UTF-8
[Oct 27, 2006 7:57:05 PM][funambol.server] FINEST: Message
to translate into the SyncML object:
<?xml version="1.0" encoding="UTF-8"?>
<SyncML>
<SyncHdr><VerDTD>1.1</VerDTD>
<VerProto>SyncML/1.1</VerProto>
<SessionID>54353420</SessionID>
<MsgID>2</MsgID>
<Target><LocURI>http://mytest.asso.fr:8080/funambol/d
s</LocURI>
</Target>
<Source><LocURI>fwm-359001607203F5173</LocURI>
</Source>
<Meta><MaxMsgSize>16384</MaxMsgSize>
</Meta>
</SyncHdr>
<SyncBody><Status><CmdID>1</CmdID>
<MsgRef>1</MsgRef>
<CmdRef>0</CmdRef>
<Cmd>SyncHdr</Cmd>
<TargetRef>http://mytest.asso.fr:8080/funambol/ds</Targe
tRef>
<SourceRef>fwm-359001607203F5173</SourceRef>
<Data>200</Data>
</Status>
<Status><CmdID>2</CmdID>
<MsgRef>1</MsgRef>
<CmdRef>3</CmdRef>
<Cmd>Alert</Cmd>
<TargetRef>scard</TargetRef>
<SourceRef>contact</SourceRef>
<Data>200</Data>
<Item><Data><Anchor><Next>1161971823829&l
t;/Next>
</Anchor>
</Data>
</Item>
</Status>
<Sync><CmdID>3</CmdID>
<Target><LocURI>scard</LocURI>
</Target>
<Source><LocURI>contact</LocURI>
</Source>
</Sync>
<Final></Final>
</SyncBody>
</SyncML>
[Oct 27, 2006 7:57:05 PM][funambol.server] FINEST: Starting
input canonization
[Oct 27, 2006 7:57:05 PM][funambol.server] FINEST: prolog:
<?xml version="1.0" encoding="UTF-8"?>
[Oct 27, 2006 7:57:05 PM][funambol.server] FINEST: Calling
input pipeline
[Oct 27, 2006 7:57:05 PM][funambol.engine.pipeline] FINEST:
Starting preprocessing
[Oct 27, 2006 7:57:05 PM][funambol.engine.pipeline] FINEST:
com.funambol.foundation.synclet.ChangeSourceUriSynclet.preProcess
Message(...)
[Oct 27, 2006 7:57:05 PM][funambol.engine.pipeline] FINEST:
Change TargetURI into input Alert commands
[Oct 27, 2006 7:57:05 PM][funambol.engine.pipeline] FINEST:
Change SourceRef into input Status commands
[Oct 27, 2006 7:57:05 PM][funambol.engine.pipeline] FINEST:
original sourceRef: fwm-359001607203F5173
[Oct 27, 2006 7:57:05 PM][funambol.engine.pipeline] FINEST:
original sourceRef: contact
[Oct 27, 2006 7:57:05 PM][funambol.engine.pipeline] FINEST:
Change TargetURI into input Sync commands
[Oct 27, 2006 7:57:05 PM][funambol.engine.pipeline] FINEST:
original targetUri: scard
[Oct 27, 2006 7:57:05 PM][funambol.engine.pipeline] FINEST:
Change TargetURI into input Map commands
[Oct 27, 2006 7:57:05 PM][funambol.engine.pipeline] FINEST:
Preprocessed message: <?xml version="1.0"
encoding="UTF-8"?>
<SyncML>
<SyncHdr>
<VerDTD>1.1</VerDTD>
<VerProto>SyncML/1.1</VerProto>
<SessionID>54353420</SessionID>
<MsgID>2</MsgID>
<Target>
<LocURI>http://mytest.asso.fr:8080/funambol/ds</LocURI&g
t;
</Target>
<Source>
<LocURI>fwm-359001607203F5173</LocURI>
</Source>
<Meta>
<MaxMsgSize>16384</MaxMsgSize>
</Meta>
</SyncHdr>
<SyncBody>
<Status>
<CmdID>1</CmdID>
<MsgRef>1</MsgRef>
<CmdRef>0</CmdRef>
<Cmd>SyncHdr</Cmd>
<TargetRef>http://mytest.asso.fr:8080/funambol/ds</Targe
tRef>
<SourceRef>fwm-359001607203F5173</SourceRef>
<Data>200</Data>
</Status>
<Status>
<CmdID>2</CmdID>
<MsgRef>1</MsgRef>
<CmdRef>3</CmdRef>
<Cmd>Alert</Cmd>
<TargetRef>scard</TargetRef>
<SourceRef>contact</SourceRef>
<Data>200</Data>
<Item>
<Data>
<Anchor xmlns="syncml:metinf">
<Next>1161971823829</Next>
</Anchor>
</Data>
</Item>
</Status>
<Sync>
<CmdID>3</CmdID>
<Target>
<LocURI>scard</LocURI>
</Target>
<Source>
<LocURI>contact</LocURI>
</Source>
</Sync>
<Final></Final>
</SyncBody>
</SyncML>

[Oct 27, 2006 7:57:05 PM][funambol.handler] FINEST: current
state: STATE_START
[Oct 27, 2006 7:57:05 PM][funambol.handler] FINEST: moving
to state STATE_PKG1_RECEIVING
[Oct 27, 2006 7:57:05 PM][funambol.handler] FINEST: Server
auhenticated (code 200)
[Oct 27, 2006 7:57:05 PM][funambol.handler] FINER: THROW
java.lang.NullPointerException
        at
com.funambol.server.session.SyncSessionHandler.processInitSyncMap
Message(SyncSessionHandler.java:850)
        at
com.funambol.server.session.SyncSessionHandler.processMessage(Syn
cSessionHandler.java:440)
        at
com.funambol.server.engine.SyncAdapter.processInputMessage(SyncAd
apter.java:459)
        at
com.funambol.server.engine.SyncAdapter.processXMLMessage(SyncAdap
ter.java:215)
        at
com.funambol.transport.http.server.LocalSyncHolder.processXMLMess
age(LocalSyncHolder.java:80)
        at
com.funambol.transport.http.server.Sync4jServlet.doPost(Sync4jSer
vlet.java:297)
        at
javax.servlet.http.HttpServlet.service(HttpServlet.java:709)
        at
javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
        at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(
ApplicationFilterChain.java:252)
        at
org.apache.catalina.core.ApplicationFilterChain.doFilter(Applicat
ionFilterChain.java:173)
        at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrap
perValve.java:214)
        at
org.apache.catalina.core.StandardValveContext.invokeNext(Standard
ValveContext.java:104)
        at
org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline
.java:520)
        at
org.apache.catalina.core.StandardContextValve.invokeInternal(Stan
dardContextValve.java:198)
        at
org.apache.catalina.core.StandardContextValve.invoke(StandardCont
extValve.java:152)
        at
org.apache.catalina.core.StandardValveContext.invokeNext(Standard
ValveContext.java:104)
        at
org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline
.java:520)
        at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostVal
ve.java:137)
        at
org.apache.catalina.core.StandardValveContext.invokeNext(Standard
ValveContext.java:104)
        at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportVal
ve.java:118)
        at
org.apache.catalina.core.StandardValveContext.invokeNext(Standard
ValveContext.java:102)
        at
org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline
.java:520)
        at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngin
eValve.java:109)
        at
org.apache.catalina.core.StandardValveContext.invokeNext(Standard
ValveContext.java:104)
        at
org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline
.java:520)
        at
org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:
929)
        at
org.apache.coyote.tomcat5.CoyoteAdapter.service(CoyoteAdapter.jav
a:160)
        at
org.apache.coyote.http11.Http11Processor.process(Http11Processor.
java:799)
        at
org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.p
rocessConnection(Http11Protocol.java:705)
        at
org.apache.tomcat.util.net.TcpWorkerThread.runIt(PoolTcpEndpoint.
java:577)
        at
org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(Thr
eadPool.java:684)
        at java.lang.Thread.run(Unknown Source)

[Oct 27, 2006 7:57:05 PM][funambol.handler] FINEST: moving
to state STATE_ERROR
[Oct 27, 2006 7:57:05 PM][funambol.handler] FINEST: moving
to state STATE_ERROR
[Oct 27, 2006 7:57:05 PM][funambol.server] FINEST: Using the
configured server uri to create the RespURI
[Oct 27, 2006 7:57:05 PM][funambol.server] FINEST: Calling
output pipeline
[Oct 27, 2006 7:57:05 PM][funambol.engine.pipeline] FINEST:
Starting postprocessing
[Oct 27, 2006 7:57:05 PM][funambol.engine.pipeline] FINEST:
Returning message to process: <?xml version="1.0"
encoding="UTF-8"?>
<SyncML>
<SyncHdr>
<VerDTD>1.1</VerDTD>
<VerProto>SyncML/1.1</VerProto>
<SessionID>54353420</SessionID>
<MsgID>2</MsgID>
<Target>
<LocURI>fwm-359001607203F5173</LocURI>
</Target>
<Source>
<LocURI>mytest.asso.fr</LocURI>
</Source>
<RespURI>mytest.asso.fr;jsessionid=418462F35CF1D3D3927A4DC8
15A3A92E</RespURI>
</SyncHdr>
<SyncBody>
<Status>
<CmdID>1</CmdID>
<MsgRef>2</MsgRef>
<CmdRef>0</CmdRef>
<Cmd>SyncHdr</Cmd>
<TargetRef>http://mytest.asso.fr:8080/funambol/ds</Targe
tRef>
<SourceRef>fwm-359001607203F5173</SourceRef>
<Data>511</Data>
</Status>
<Final></Final>
</SyncBody>
</SyncML>

[Oct 27, 2006 7:57:05 PM][funambol.engine.pipeline] FINEST:
com.funambol.foundation.synclet.ChangeSourceUriSynclet.postProces
sMessage(...)
[Oct 27, 2006 7:57:05 PM][funambol.engine.pipeline] FINEST:
Replace TargetRef into output Status commands
[Oct 27, 2006 7:57:05 PM][funambol.engine.pipeline] FINEST:
Replace SourceRef into output Result commands
[Oct 27, 2006 7:57:05 PM][funambol.engine.pipeline] FINEST:
Replace Source into output Alert commands
[Oct 27, 2006 7:57:05 PM][funambol.engine.pipeline] FINEST:
Replace Source into output Sync commands
[Oct 27, 2006 7:57:05 PM][funambol.server] FINEST: Outgoing
message: <?xml version="1.0"
encoding="UTF-8"?>
<SyncML>
<SyncHdr>
<VerDTD>1.1</VerDTD>
<VerProto>SyncML/1.1</VerProto>
<SessionID>54353420</SessionID>
<MsgID>2</MsgID>
<Target>
<LocURI>fwm-359001607203F5173</LocURI>
</Target>
<Source>
<LocURI>mytest.asso.fr</LocURI>
</Source>
<RespURI>mytest.asso.fr;jsessionid=418462F35CF1D3D3927A4DC8
15A3A92E</RespURI>
</SyncHdr>
<SyncBody>
<Status>
<CmdID>1</CmdID>
<MsgRef>2</MsgRef>
<CmdRef>0</CmdRef>
<Cmd>SyncHdr</Cmd>
<TargetRef>http://mytest.asso.fr:8080/funambol/ds</Targe
tRef>
<SourceRef>fwm-359001607203F5173</SourceRef>
<Data>511</Data>
</Status>
<Final></Final>
</SyncBody>
</SyncML>

[Oct 27, 2006 7:57:05 PM][funambol.server] FINEST: Creating
response with charset: UTF-8
[Oct 27, 2006 7:57:05 PM][funambol.server] FINEST: Starting
output canonization
[Oct 27, 2006 7:57:05 PM][funambol.transport.http] FINEST:
Outgoing message length: 639
[Oct 27, 2006 7:57:05 PM][funambol.transport.http] FINEST:
Finally
[Oct 27, 2006 7:57:05 PM][funambol.engine] FINEST: null:
synchronization ending
[Oct 27, 2006 7:57:05 PM][funambol.engine.strategy] FINEST:
SyncStrategy synchronization completed.
[Oct 27, 2006 7:57:05 PM] INFO: null: synchronization completed
[Oct 27, 2006 7:57:05 PM][funambol.handler] FINEST: moving
to state STATE_ERROR
[Oct 27, 2006 7:57:05 PM][funambol.handler] FINEST: moving
to state STATE_ENDED
[Oct 27, 2006 7:57:05 PM][funambol.transport.http] FINEST:
Removing holder for 418462F35CF1D3D3927A4DC815A3A92E
Date: 2006-08-09 21:23
Sender: jfinkelstein
Logged In: YES 
user_id=8085

Mark - can you please supply more log for this issue?  Thanks.
Date: 2006-08-09 11:19
Sender: stefano_fornari
Logged In: YES 
user_id=1039

Under investigation. We need more log. If we won't have it
by the next bug review I will close it as invalid.
Date: 2006-07-27 08:17
Sender: nichele
Collegato: no 
user_id=2381

It seems like 305085/303691/303703.

Could you post the full server log ?

Attached Files:

Name Description Download
No Files Currently Attached

Changes:

Field Old Value Date By
resolution_idNone2006-08-09 11:14stefano_fornari

Copyright © 1999-2008, OW2 Consortium | contact | webmaster.