SFSWorker is crazy

[Wei]

My extension didn't work yesterday, I didn't know why, so I was debugging, I found that 2 SFSWorkers were running my extension in the same time, because that I saw the trace method was called twice, and first time ws always fail to work, but the second time was fine, why? It's never happened before. I was just using one client to connect my server.

Code: Select all

07:11:42,484 INFO  [SocketReader] sessions.DefaultSessionManager     - Session created: { Id: 2, Type: DEFAULT, Logged: No, IP: 192.168.31.161:52266 } on Server port: 9933 <---> 52266
07:11:48,666 WARN  [SFSWorker:Ext:4] managers.SFSExtensionManager     - java.lang.NullPointerException:
::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::
Exception: java.lang.NullPointerException
Message: *** Null ***
Description: Error during event handling: java.lang.NullPointerException, Listener: { Ext: LobbyExtension, Type: JAVA, Lev: ZONE, { Zone: Mazing }, {} }
+--- --- ---+
Stack Trace:
+--- --- ---+
com.smartfoxserver.v2.extensions.BaseSFSExtension.getTraceMessage(BaseSFSExtension.java:551)
com.smartfoxserver.v2.extensions.BaseSFSExtension.trace(BaseSFSExtension.java:529)
com.smartfoxserver.v2.extensions.BaseSFSExtension.trace(BaseSFSExtension.java:519)
com.smartfoxserver.v2.extensions.BaseServerEventHandler.trace(BaseServerEventHandler.java:98)
com.mazingtec.lobbyextension.OnLogin.handleServerEvent(OnLogin.java:47)
com.smartfoxserver.v2.extensions.SFSExtension.handleServerEvent(SFSExtension.java:259)
com.smartfoxserver.v2.entities.managers.SFSExtensionManager.dispatchEvent(SFSExtensionManager.java:768)
com.smartfoxserver.v2.entities.managers.SFSExtensionManager.dispatchZoneLevelEvent(SFSExtensionManager.java:689)
com.smartfoxserver.v2.entities.managers.SFSExtensionManager.handleServerEvent(SFSExtensionManager.java:887)
com.smartfoxserver.v2.core.SFSEventManager$SFSEventRunner.run(SFSEventManager.java:65)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
java.lang.Thread.run(Thread.java:745)
::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

07:11:48,666 INFO  [SFSWorker:Ext:1] Extensions     - {LobbyExtension}: 8cVDark7fNdYg4bxGvGIWUbdl6B_3hh2MNQ65JF6RBB8OvnWBI2ZCqr2CKgNck_UBez1DBjDdGcOrQnaavfx56UYOLeDNm46VOhMmnSG1e4
07:11:48,667 INFO  [SFSWorker:Ext:1] Extensions     - {LobbyExtension}: wlqeErHMLcAvMbRd4kbKXWndfiO6wbV-rT5ivDkA0tsToMDiil0Dlg6R0SHdNOwGqaYb5H_a6Wf63B4iRDTgAPegAXZBEAoNdFnY4y3b9bU
07:11:48,667 INFO  [SFSWorker:Ext:1] Extensions     - {LobbyExtension}: oVH8Gv1J_Dc34JGRO15IBeXSKnFA
07:11:48,667 INFO  [SFSWorker:Ext:1] Extensions     - {LobbyExtension}: ofVsy1D7N3QGQMNzF9Wmblr7sILk
[Ljava.lang.String;@54bca8f7
07:11:49,067 INFO  [SFSWorker:Ext:1] Extensions     - {LobbyExtension}: Jason
07:11:50,568 INFO  [SFSWorker:Ext:1] api.SFSApi     - User login: { Zone: Mazing }, ( User Name: 051Dyfzk2ylvmH0FZezk2KB7zk2Dyfze, Id: 0, Priv: 0, Sess: 192.168.31.161:52266 ) , Type: Unity
07:16:54,272 INFO  [SocketReader] sessions.DefaultSessionManager     - Session removed: { Id: 2, Type: DEFAULT, Logged: Yes, IP: 192.168.31.161:52266 }
07:16:54,275 INFO  [SFSWorker:Sys:4] api.SFSApi     - User disconnected: { Zone: Mazing }, ( User Name: 051Dyfzk2ylvmH0FZezk2KB7zk2Dyfze, Id: 0, Priv: 0, Sess: 192.168.31.161:52266 ) , SessionLen: 303706, Type: Unity


[Lapo]

SFS is multi-thread so your Extension is too.
Can you show me the code that causes the error you have posted?

Thanks

[Wei]

Sure, I know SFS2X is multi-thread, but if there's only one client, below is my code.

We use WeChat authorization, some thing like login with facebook, so there is no user name or password, I use LOGIN_NAME to contain openid and use LOGIN_PASSWORD to contain user type. 00 means new user, 01 means old user on a new device.

Code: Select all

public class OnLogin extends BaseServerEventHandler {
   
    private SimpleDateFormat sdf = new SimpleDateFormat("yyyy-MM-dd");
   
    @Override
    public void handleServerEvent(ISFSEvent event)
    {
        List CacheInfo;
        List DBInfo;
        String[] token;
        String[] userInfo;
        WeChatAuth wca = new WeChatAuth();
        ISFSObject userdata = new SFSObject();
        String code = (String) event.getParameter(SFSEventParam.LOGIN_NAME);
        String userType = (String) event.getParameter(SFSEventParam.LOGIN_PASSWORD);
        ISession session = (ISession) event.getParameter(SFSEventParam.SESSION);
       
        if (getApi().checkSecurePassword(session, "00", userType))
        {
           
            token = wca.GetAccessToken(code, (byte) 0);
           
            userInfo = wca.GetUserInfo(token[0], token[2]);
           
            CacheInfo = GetCacheInfo(token[2]);
            DBInfo = GetDBInfo(token[2]);
           
            trace(DBInfo.size());
            if (CacheInfo.get(0) == null & DBInfo.isEmpty())
            {
                String[] user = {token[2], token[0], token[1], token[3], userInfo[0], userInfo[5], userInfo[1], userInfo[2], userInfo[3]};
                trace(user);
                AddUser(user);
            }
           
            else
            {
                UpdateUserInfo(token[0], token[1], token[2]);
            }
           
            userdata.putUtfString("openid", token[2]);
            userdata.putUtfString("nickname", userInfo[0]);
            userdata.putUtfString("headurl", userInfo[5]);
        }
       
        if (getApi().checkSecurePassword(session, "01", userType))
        {
            String at;
            String rt;
            String openid;
            String last;
   
            CacheInfo = GetCacheInfo(code);
            DBInfo = GetDBInfo(code);
           
            if (CacheInfo.get(0) == null & DBInfo.isEmpty())
            {
                SFSErrorData errData = new SFSErrorData(SFSErrorCode.LOGIN_BAD_USERNAME);
   
                try {
                    throw new SFSLoginException("Bad openid", errData);
                } catch (SFSLoginException e) {
                    e.printStackTrace();
                }
            }
   }


[Lapo]

Hi,
I think that the NPE you've reported is simply due to having passed a null object to the trace method. Nothing to do with multi-threading

I've added a ticket to our bug db to add checks for null values.

Cheers

[Wei]

Thanks man, I really am. I'm a newbie here, actually I was a ASM and C++ programmer, I own a mobile game company, and we want to move all of our games to SFS2X, but I need to ensure that SFS2X is what we need before we do so, I definitely will ask more stupid questions, hope you don't mind.

[Lapo]

No problem

[Wei]

Hi man, it keeps happening, I have two trace() in my code, but every time there are 4 records on the console

Code: Select all

[Ljava.lang.String;@7918d768
19:06:47,224 INFO  [SFSWorker:Ext:4] Extensions     - {LobbyExtension}: oVH8Gv1J_Dc34JGRO15IBeXSKnFA
[Ljava.lang.String;@1e5ee5ae
19:06:47,396 INFO  [SFSWorker:Ext:1] Extensions     - {LobbyExtension}: oVH8Gv1J_Dc34JGRO15IBeXSKnFA
19:06:48,090 INFO  [SFSWorker:Ext:1] Extensions     - {LobbyExtension}: 30
19:06:48,174 INFO  [SFSWorker:Ext:4] Extensions     - {LobbyExtension}: 30


[Lapo]

I am not sure "what" keeps happening.
This doesn't look like it's causing any error. So can you explain what you are expecting?

Also keep in mind that in Java objects must have an overridden toString() method to produce a specific output when passed to an output function. I suspect that's the problem.

Take a look here:
https://stackoverflow.com/questions/361 ... od-in-java

[Wei]

As you can see, there are only 2 trace methods in my code, but everyone was ran twice.

[Lapo]

I think the problem for the duplicate messages is that you have some some leaked handler.
Normally this shouldn't happen as SmartFoxServer keeps track of all the request/event handlers that are added to an Extension and releases them when the Extension is reloaded.

But I have no idea what your code does, so it's difficult for me to guess. Maybe you are working with scheduled tasks and you have forgot to remove them when it's time to?

In any case event listeners or tasks seem the first place where to take a look in your code.

cheers