[SOLVED] Problem with logger

Ali_RS · January 19, 2018, 9:00pm

Hi

I am getting the following log output in console nonstop.
Everything was working OK . I am getting this behavior since this morning. Not sure what goes wrong here.

zone update underflow FPS:59
DelayService.delay done
00:13:29.586 [com.jme3.network.kernel.tcp.SelectorKernel@4b7a960a] DEBUG example.net.server.AccountHostedService - startHostingOnConnection(Connection[ id=0, reliable=NioEndpoint[1, java.nio.channels.SocketChannel[connected local=/127.0.0.1:4271 remote=/127.0.0.1:48114]], fast=UdpEndpoint[1, /127.0.0.1:49313] ])
00:13:29.607 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] INFO diagnostics.MessageDebugger - Received:RpcCallMessage[#-1, channel=-2, async, objId=-1, procId=0, args.length=1]
00:13:29.609 [com.jme3.network.kernel.tcp.SelectorKernel@4b7a960a] DEBUG com.otm.service.editor.EditorHostedService - startHostingOnConnection(Connection[ id=0, reliable=NioEndpoint[1, java.nio.channels.SocketChannel[connected local=/127.0.0.1:4271 remote=/127.0.0.1:48114]], fast=UdpEndpoint[1, /127.0.0.1:49313] ])
00:13:29.610 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] INFO diagnostics.MessageDebugger - Received:RpcCallMessage[#-1, channel=-2, async, objId=-1, procId=1, args.length=4]
00:13:29.629 [com.jme3.network.kernel.tcp.SelectorKernel@4b7a960a] DEBUG com.simsilica.es.server.EntityDataHostedService - Connection added:Connection[ id=0, reliable=NioEndpoint[1, java.nio.channels.SocketChannel[connected local=/127.0.0.1:4271 remote=/127.0.0.1:48114]], fast=UdpEndpoint[1, /127.0.0.1:49313] ]
00:13:29.629 [com.jme3.network.kernel.tcp.SelectorKernel@4b7a960a] DEBUG com.simsilica.es.server.EntityDataHostedService - startHostingOnConnection:Connection[ id=0, reliable=NioEndpoint[1, java.nio.channels.SocketChannel[connected local=/127.0.0.1:4271 remote=/127.0.0.1:48114]], fast=UdpEndpoint[1, /127.0.0.1:49313] ]
00:13:29.635 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] INFO diagnostics.MessageDebugger - Received:RpcCallMessage[#-1, channel=-2, async, objId=-1, procId=0, args.length=1]
00:13:29.635 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] INFO diagnostics.MessageDebugger - Received:RpcCallMessage[#-1, channel=-2, async, objId=-1, procId=1, args.length=4]
00:13:29.685 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG example.net.client.AccountClientService - start()
00:13:29.693 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG example.net.client.AccountClientService - delegate:RemoteObject[#1, example.net.AccountSession]
00:13:29.693 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG example.net.client.GameSessionClientService - start()
00:13:29.693 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG example.net.chat.client.ChatClientService - start()
00:13:29.693 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] INFO example.net.client.SharedObjectUpdater - start()
00:13:29.728 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.otm.service.editor.EditorClientService - start()
00:13:29.728 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] INFO example.ConnectionState - clientConnected(com.jme3.network.base.DefaultClient@7eda295d)
00:13:29.754 [jME3 Main] INFO example.ConnectionState - onConnected()
00:13:29.760 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] INFO diagnostics.MessageDebugger - Received:RpcResponseMessage[#0, result=This a game server.
There are many like it
but this one is mine.]
00:13:29.761 [jME3 Main] DEBUG example.ConnectionState - Server info:This a game server.
There are many like it
but this one is mine.
zone update underflow FPS:55
00:13:31.120 [jME3 Main] INFO example.ConnectionState - join(idea)
00:13:31.132 [com.jme3.network.kernel.tcp.SelectorKernel@394463ba] INFO example.net.server.AccountHostedService - login(idea)
00:13:31.146 [com.jme3.network.kernel.tcp.SelectorKernel@394463ba] INFO com.simsilica.es.sql.SqlEntityData - Created connection.  Autocommit:true
00:13:31.175 [com.jme3.network.kernel.tcp.SelectorKernel@394463ba] INFO com.simsilica.es.sql.ComponentTable - Checking for table:NAME
zone update underflow FPS:59
00:13:31.242 [com.jme3.network.kernel.tcp.SelectorKernel@394463ba] INFO com.simsilica.es.sql.ComponentTable - Table fields:{NAME=12}
00:13:31.251 [com.jme3.network.kernel.tcp.SelectorKernel@394463ba] INFO com.simsilica.es.sql.ComponentTable - Object fields:{NAME=name:class java.lang.String}
00:13:31.259 [com.jme3.network.kernel.tcp.SelectorKernel@394463ba] INFO com.simsilica.es.sql.ComponentTable - New fields:[]
00:13:31.260 [com.jme3.network.kernel.tcp.SelectorKernel@394463ba] INFO com.simsilica.es.sql.ComponentTable - Removed fields:[]
00:13:31.287 [com.jme3.network.kernel.tcp.SelectorKernel@394463ba] INFO example.net.server.AccountHostedService - Created player entity:EntityId[14] for:idea
00:13:31.297 [com.jme3.network.kernel.tcp.SelectorKernel@394463ba] DEBUG example.net.server.AccountHostedService - publishing playerLoggedOn event for:Connection[ id=0, reliable=NioEndpoint[1, java.nio.channels.SocketChannel[connected local=/127.0.0.1:4271 remote=/127.0.0.1:48114]], fast=UdpEndpoint[1, /127.0.0.1:49313] ]
00:13:31.297 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] INFO diagnostics.MessageDebugger - Received:RpcCallMessage[#-1, channel=-2, async, objId=1, procId=0, args.length=1]
00:13:31.298 [com.jme3.network.kernel.tcp.SelectorKernel@394463ba] DEBUG example.net.server.GameSessionHostedService - onPlayerLoggedOn()
00:13:31.299 [com.jme3.network.kernel.tcp.SelectorKernel@394463ba] DEBUG example.net.server.GameSessionHostedService - startHostingOnConnection(Connection[ id=0, reliable=NioEndpoint[1, java.nio.channels.SocketChannel[connected local=/127.0.0.1:4271 remote=/127.0.0.1:48114]], fast=UdpEndpoint[1, /127.0.0.1:49313] ])
00:13:31.330 [com.jme3.network.kernel.tcp.SelectorKernel@394463ba] INFO com.overthemoon.game.entity.system.server.GameEntities - Create entity :ship
00:13:31.354 [GameLoopThread] DEBUG com.simsilica.es.base.DefaultEntitySet - Pulling component type:class com.otm.es.physics.BodyPosition for id:EntityId[15]
00:13:31.356 [GameLoopThread] DEBUG com.simsilica.es.base.DefaultEntitySet - Entity EntityId[15] could not be completed for type:class com.otm.es.physics.BodyPosition
00:13:31.359 [GameLoopThread] DEBUG com.simsilica.es.base.DefaultEntitySet - Pulling component type:class com.otm.es.physics.Position for id:EntityId[15]
00:13:31.361 [GameLoopThread] INFO com.simsilica.es.sql.SqlEntityData - Created connection.  Autocommit:true
Set position on:EntityId[15]
00:13:31.373 [GameLoopThread] INFO com.otm.state.physics.BulletPhysicsState - Add Mob physic body
00:13:31.376 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] INFO diagnostics.MessageDebugger - Received:RpcCallMessage[#-1, channel=-2, async, objId=-1, procId=0, args.length=1]
00:13:31.377 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] INFO diagnostics.MessageDebugger - Received:RpcCallMessage[#-1, channel=-2, async, objId=-1, procId=1, args.length=4]
00:13:31.403 [com.jme3.network.kernel.tcp.SelectorKernel@394463ba] DEBUG example.net.chat.server.ChatHostedService - startHostingOnConnection(Connection[ id=0, reliable=NioEndpoint[1, java.nio.channels.SocketChannel[connected local=/127.0.0.1:4271 remote=/127.0.0.1:48114]], fast=UdpEndpoint[1, /127.0.0.1:49313] ])
00:13:31.416 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] INFO diagnostics.MessageDebugger - Received:RpcCallMessage[#-1, channel=-2, async, objId=-1, procId=0, args.length=1]
00:13:31.417 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] INFO diagnostics.MessageDebugger - Received:RpcCallMessage[#-1, channel=-2, async, objId=-1, procId=1, args.length=4]
00:13:31.491 [GameLoopThread] INFO com.otm.state.physics.BulletPhysicsState - Add static physic body
00:13:31.511 [GameLoopThread] DEBUG com.simsilica.ethereal.zone.ZoneManager - ZONE: enter zone:15  0:1:0
00:13:31.526 [com.jme3.network.kernel.tcp.SocketConnector@4ff1e2c3] INFO diagnostics.MessageDebugger - Received:EntityDataMessage[0, [ComponentData[EntityId[15], [BodyPosition[null]]]]]
00:13:31.528 [com.jme3.network.kernel.tcp.SocketConnector@4ff1e2c3] INFO diagnostics.MessageDebugger - Received:ComponentChangeMessage[[EntityChange[EntityId[15], BodyPosition[null], class com.otm.es.physics.BodyPosition]]]
00:13:31.529 [GameLoopThread] DEBUG com.simsilica.es.base.DefaultEntitySet - Pulling component type:class com.otm.es.ai.behaviors.Observer for id:EntityId[15]
00:13:31.529 [GameLoopThread] DEBUG com.simsilica.es.base.DefaultEntitySet - Entity EntityId[15] could not be completed for type:class com.otm.es.ai.behaviors.Observer
00:13:31.529 [GameLoopThread] DEBUG com.simsilica.es.base.DefaultEntitySet - Pulling component type:class com.otm.es.ai.behaviors.Observable for id:EntityId[15]
00:13:31.529 [GameLoopThread] DEBUG com.simsilica.es.base.DefaultEntitySet - Entity EntityId[15] could not be completed for type:class com.otm.es.ai.behaviors.Observable
00:13:31.546 [GameLoopThread] DEBUG com.simsilica.es.base.DefaultEntitySet - Pulling component type:class com.otm.es.physics.cshape.SphereShape for id:EntityId[15]
00:13:31.548 [GameLoopThread] DEBUG com.simsilica.es.base.DefaultEntitySet - Pulling component type:class com.otm.es.physics.MassProperties for id:EntityId[15]
00:13:31.548 [GameLoopThread] DEBUG com.simsilica.es.base.DefaultEntitySet - Pulling component type:class com.otm.es.ai.behaviors.SteerSpeed for id:EntityId[15]
00:13:31.549 [GameLoopThread] DEBUG com.simsilica.es.base.DefaultEntitySet - Entity EntityId[15] could not be completed for type:class com.otm.es.ai.behaviors.SteerSpeed
00:13:31.549 [GameLoopThread] DEBUG com.simsilica.es.base.DefaultEntitySet - Pulling component type:class com.otm.es.ai.navigation.NavRequest for id:EntityId[15]
00:13:31.552 [GameLoopThread] DEBUG com.simsilica.es.base.DefaultEntitySet - Entity EntityId[15] could not be completed for type:class com.otm.es.ai.navigation.NavRequest
00:13:31.560 [com.jme3.network.kernel.tcp.SocketConnector@4ff1e2c3] INFO diagnostics.MessageDebugger - Received:EntityDataMessage[1, [ComponentData[EntityId[15], [ObjectType[type=6], BodyPosition[null]]]]]
MobContainer.addObject(Entity[EntityId[15], values=[ObjectType[type=6], BodyPosition[null]]])
00:13:31.581 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] INFO diagnostics.MessageDebugger - Object state updates started.
00:13:31.584 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.RemoteTimeSource - ======== Time delta:-5,550,832 nanos (-5.55 ms)  drift:-5,550,832 nanos (-5.55 ms)  windowSize:0
00:13:31.585 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.RemoteTimeSource - === oldDrift:0  drift change:-5,550,832 nanos (-5.55 ms)
00:13:31.585 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.StateReceiver - Update state:ObjectStateMessage[id=0, time=8414686734264, size=51]
00:13:31.587 [com.jme3.network.kernel.tcp.SelectorKernel@394463ba] DEBUG com.simsilica.ethereal.NetworkStateListener - ********** Connection[ id=0, reliable=NioEndpoint[1, java.nio.channels.SocketChannel[connected local=/127.0.0.1:4271 remote=/127.0.0.1:48114]], fast=UdpEndpoint[1, /127.0.0.1:49313] ]  avg ping:10805888  10.805888 ms
00:13:31.589 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.StateReceiver - State:SentState[messageId=0, created=8414699757014, acked=[], frames=[FrameState[time=8414657271859, legacySequence=8414657271808, columnId=0, states=[com.simsilica.ethereal.net.ObjectState[id=10, realId=15, zoneId=17, positionBits=567c48a6567c, rotationBits=fff800800800]]]]]
00:13:31.589 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.StateReceiver - ** frame begin:8414657271859
00:13:31.597 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.SharedObject - applyNetworkState(8414657271859, com.simsilica.ethereal.net.ObjectState[id=10, realId=15, zoneId=17, positionBits=567c48a6567c, rotationBits=fff800800800])
00:13:31.598 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] INFO diagnostics.MessageDebugger - Received:StringIdMessage[id=null, string=ship]
00:13:31.610 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.RemoteTimeSource - ======== Time delta:-3,378,338 nanos (-3.38 ms)  drift:-4,464,585 nanos (-4.46 ms)  windowSize:1
00:13:31.612 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.RemoteTimeSource - === oldDrift:-5550832  drift change:1,086,247 nanos (1.09 ms)
00:13:31.613 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.StateReceiver - Update state:ObjectStateMessage[id=1, time=8414717812373, size=65]
00:13:31.615 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.StateReceiver - State:SentState[messageId=1, created=8414725844706, acked=[(0)], frames=[FrameState[time=8414674889384, legacySequence=8414674889216, columnId=2097152, states=[com.simsilica.ethereal.net.ObjectState[id=10, zoneId=14]]], FrameState[time=8414703721454, legacySequence=8414703721216, columnId=2097152, states=[com.simsilica.ethereal.net.ObjectState[id=10, zoneId=14]]]]]
00:13:31.617 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.StateReceiver - Updating baseline for message:0
00:13:31.618 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.StateReceiver - ** frame begin:8414674889384
00:13:31.620 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.SharedObject - applyNetworkState(8414674889384, com.simsilica.ethereal.net.ObjectState[id=10, zoneId=14])
00:13:31.622 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.StateReceiver - ** frame begin:8414703721454
00:13:31.623 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.SharedObject - applyNetworkState(8414703721454, com.simsilica.ethereal.net.ObjectState[id=10, zoneId=14])
00:13:31.657 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.RemoteTimeSource - ======== Time delta:-467,974 nanos (-0.47 ms)  drift:-3,132,381 nanos (-3.13 ms)  windowSize:2
00:13:31.657 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.RemoteTimeSource - === oldDrift:-4464585  drift change:1,332,204 nanos (1.33 ms)
00:13:31.657 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.StateReceiver - Update state:ObjectStateMessage[id=2, time=8414767796032, size=92]
00:13:31.657 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.StateReceiver - State:SentState[messageId=2, created=8414768650387, acked=[(1)], frames=[FrameState[time=8414723867018, legacySequence=8414723866880, columnId=2097152, states=[com.simsilica.ethereal.net.ObjectState[id=10]]], FrameState[time=8414741255287, legacySequence=8414741255168, columnId=2097152, states=[com.simsilica.ethereal.net.ObjectState[id=10]]], FrameState[time=8414757921317, legacySequence=8414757921280, columnId=2097152, states=[com.simsilica.ethereal.net.ObjectState[id=10]]]]]
00:13:31.658 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.StateReceiver - Updating baseline for message:1
00:13:31.658 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.StateReceiver - ** frame begin:8414723867018
00:13:31.658 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.SharedObject - applyNetworkState(8414723867018, com.simsilica.ethereal.net.ObjectState[id=10])
00:13:31.658 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.StateReceiver - ** frame begin:8414741255287
00:13:31.658 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.SharedObject - applyNetworkState(8414741255287, com.simsilica.ethereal.net.ObjectState[id=10])
00:13:31.658 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.StateReceiver - ** frame begin:8414757921317
00:13:31.658 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.SharedObject - applyNetworkState(8414757921317, com.simsilica.ethereal.net.ObjectState[id=10])
00:13:31.708 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.RemoteTimeSource - ======== Time delta:-988,196 nanos (-0.99 ms)  drift:-2,596,334 nanos (-2.6 ms)  windowSize:3
00:13:31.708 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.RemoteTimeSource - === oldDrift:-3132381  drift change:536,047 nanos (0.54 ms)
00:13:31.708 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.StateReceiver - Update state:ObjectStateMessage[id=3, time=8414817881383, size=92]
00:13:31.708 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.StateReceiver - State:SentState[messageId=3, created=8414819331107, acked=[(2)], frames=[FrameState[time=8414774587753, legacySequence=8414774587648, columnId=2097152, states=[com.simsilica.ethereal.net.ObjectState[id=10]]], FrameState[time=8414792328309, legacySequence=8414792328192, columnId=2097152, states=[com.simsilica.ethereal.net.ObjectState[id=10]]], FrameState[time=8414808994691, legacySequence=8414808994560, columnId=2097152, states=[com.simsilica.ethereal.net.ObjectState[id=10]]]]]
00:13:31.708 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.StateReceiver - Updating baseline for message:2
00:13:31.708 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.StateReceiver - ** frame begin:8414774587753
00:13:31.708 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.SharedObject - applyNetworkState(8414774587753, com.simsilica.ethereal.net.ObjectState[id=10])
00:13:31.708 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.StateReceiver - ** frame begin:8414792328309
00:13:31.708 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.SharedObject - applyNetworkState(8414792328309, com.simsilica.ethereal.net.ObjectState[id=10])
00:13:31.708 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.StateReceiver - ** frame begin:8414808994691
00:13:31.708 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.SharedObject - applyNetworkState(8414808994691, com.simsilica.ethereal.net.ObjectState[id=10])
00:13:31.755 [com.jme3.network.kernel.tcp.SelectorKernel@1bb79986] INFO com.simsilica.es.sql.SqlEntityData - Created connection.  Autocommit:true
00:13:31.758 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.RemoteTimeSource - ======== Time delta:-533,284 nanos (-0.53 ms)  drift:-2,183,724 nanos (-2.18 ms)  windowSize:4
00:13:31.758 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.RemoteTimeSource - === oldDrift:-2596334  drift change:412,610 nanos (0.41 ms)
00:13:31.758 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.StateReceiver - Update state:ObjectStateMessage[id=4, time=8414868229870, size=92]
00:13:31.758 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.StateReceiver - State:SentState[messageId=4, created=8414869577485, acked=[(3)], frames=[FrameState[time=8414825661167, legacySequence=8414825660928, columnId=2097152, states=[com.simsilica.ethereal.net.ObjectState[id=10]]], FrameState[time=8414842327985, legacySequence=8414842327808, columnId=2097152, states=[com.simsilica.ethereal.net.ObjectState[id=10]]], FrameState[time=8414860020162, legacySequence=8414860019968, columnId=2097152, states=[com.simsilica.ethereal.net.ObjectState[id=10]]]]]
00:13:31.758 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.StateReceiver - Updating baseline for message:3
00:13:31.758 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.StateReceiver - ** frame begin:8414825661167
00:13:31.759 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.SharedObject - applyNetworkState(8414825661167, com.simsilica.ethereal.net.ObjectState[id=10])
00:13:31.759 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.net.StateReceiver - ** frame begin:8414842327985
00:13:31.759 [com.jme3.network.kernel.tcp.SocketConnector@59934e58] DEBUG com.simsilica.ethereal.SharedObject - applyNetworkState(8414842327985, com.simsilica.ethereal.net.ObjectState[id=10])
00:13:31.759

I tried to change log level to ERROR in log4j xml config but no success, yet getting the logs.

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="warn" name="MyApp" packages="">
  <Appenders>
    <RollingFile name="RollingFile" fileName="application.log" ignoreExceptions="false"                
                 filePattern="logs/$${date:yyyy-MM}/application-%d{MM-dd-yyyy}-%i.log.gz">
      <PatternLayout>
        <Pattern>%d{ABSOLUTE} %-5p [%c{1}] %m%n</Pattern>        
      </PatternLayout>
      <OnStartupTriggeringPolicy />
    </RollingFile>
    
    <Console name="STDOUT" target="SYSTEM_OUT" ignoreExceptions="false">
      <PatternLayout pattern="%d{ABSOLUTE} %-5p [%c{1}] %m%n"/>
    </Console>
  </Appenders>
  <Loggers>
    <Logger name="example" level="ERROR"/>
    <Logger name="com.simsilica.sim" level="ERROR"/>
    <!-- <Logger name="com.simsilica.lemur.input.InputMapper" level="TRACE"/> -->
    <!-- <Logger name="com.simsilica.lemur.CallMethodAction" level="TRACE"/> -->
    <Root level="ERROR">
      <AppenderRef ref="RollingFile"/>
      <AppenderRef ref="STDOUT"/>
    </Root>
  </Loggers>
</Configuration>

I also tried to change it this way

Logger.getLogger( "com.jme3" ).setLevel( Level.SEVERE );

again no success.

Can anybody help me with this problem?

Regards

pspeed · January 19, 2018, 9:57pm

It’s JME logging it… which unfortunately uses the crappy built-in Java logging… so configuring log4j won’t help there. (Unless you are using a utility to copy the configuration over… but I don’t think I include one of those in any of my libs. I don’t remember though.)

Domenic · January 19, 2018, 10:27pm

What’s so bad about it?

Ali_RS · January 19, 2018, 10:30pm

Yep, I am using the LogAdapter utility class you provided.

in main method

 // Make sure JUL logging goes to our log4j configuration
 LogAdapter.initialize();

and output

Setting root JUL log level to:FINE
logger config:root
Setting JUL Log: level to:SEVERE
logger config:com.jme3.network
Setting JUL Log:com.jme3.network level to:SEVERE
logger config:com.simsilica.sim
Setting JUL Log:com.simsilica.sim level to:SEVERE
logger config:example
Setting JUL Log:example level to:SEVERE

but I do not know why yet I am getting the log in DEBUG level

01:52:16.218 [com.jme3.network.kernel.tcp.SocketConnector@7b90c501] DEBUG com.simsilica.ethereal.net.StateReceiver - Updating baseline for message:136
01:52:16.218 [com.jme3.network.kernel.tcp.SocketConnector@7b90c501] DEBUG com.simsilica.ethereal.net.StateReceiver - ** frame begin:14339286089784
01:52:16.218 [com.jme3.network.kernel.tcp.SocketConnector@7b90c501] DEBUG com.simsilica.ethereal.SharedObject - applyNetworkState(14339286089784, com.simsilica.ethereal.net.ObjectState[id=10])
01:52:16.218 [com.jme3.network.kernel.tcp.SocketConnector@7b90c501] DEBUG com.simsilica.ethereal.net.StateReceiver - ** frame begin:14339302755297
01:52:16.218 [com.jme3.network.kernel.tcp.SocketConnector@7b90c501] DEBUG com.simsilica.ethereal.SharedObject - applyNetworkState(14339302755297, com.simsilica.ethereal.net.ObjectState[id=10])
01:52:16.218 [com.jme3.network.kernel.tcp.SocketConnector@7b90c501] DEBUG com.simsilica.ethereal.net.StateReceiver - ** frame begin:14339319421882

pspeed · January 19, 2018, 10:35pm

Yeah, weird.

Where do I start?.. heck I don’t even remember half the things I hate about it.

There were at least three major logging APIs when Sun/Oracle decided to add one to Java. Rather than adopt ANY of their conventions, they went 100% their own path.

My recollection is that setting log levels in in JUL is very strange. Like, if you don’t do it before some class retrieves its logger than that particular logger instance won’t pick it up. (Which could actually be Ali_RS’s problem if he changed the order of operations at all.)

I have that LogAdapter class that I wrote and I tell you I jumped through hoops to get it to work right at all and it’s still extremely fragile in init order issues… all because of JUL. Literally every other Java logging API on the planet does not have this issue.

Fortunately, all of my stuff uses slf4j… so you can use whatever underlying logging mechanism you want… so if you have a hard-on for JUL, then you can use that.

Personally, I prefer the wealth of appenders already included in log4j. Rolling file appender with automatic zipping of older files? No problem.

louhy · January 20, 2018, 7:01pm

Could be worse, it could use commons-logging…

Is there a reason we can’t use SLF4J with a bridge to grab JUL output?

pspeed · January 21, 2018, 2:28am

I do use a bridge… that’s what the LogAdapter is.

The trick is copying the configuration to JUL so that it’s not wasting time building strings that are just going to get swallowed.

I’m pretty sure tht the JUL to SLF4J bridge also doesn’t do this properly… but it’s been a while since I’ve looked.

Most logging libraries are completely sensible… except JUL.

Ali_RS · January 22, 2018, 12:12pm

One of my program dependencies (which I had no more needed to it) was causing this problem with JUL. I removed that and everything works just fine now.

Thanks