16:23:53.671 -[heartbeat]- client heartbeat timeout times=1, connection=[channel=[id: 0x7217ffbd, L:/169.254.157.130:3000 - R:/169.254.157.130:59796], context={osName='android', osVersion='1.0.1', deviceId='test-device-id-0', userId='user-0', tags='test', heartbeat=30000}, status=1, lastReadTime=1577694191784, lastWriteTime=1577694191783]
16:24:00.148 -[connection]- client connected conn=[id: 0x3833963c, L:/192.168.0.168:3001 - R:/192.168.0.168:59993]
16:24:01.216 - [mp-gateway-work-5-3] DEBUG - c.m.c.server.ServerChannelHandler - channelRead conn=[id: 0x3833963c, L:/192.168.0.168:3001 - R:/192.168.0.168:59993], packet=
16:24:01.216 - [mp-gateway-work-5-3] DEBUG - com.mpush.core.push.PushCenter - add new task to push center, count=5, task=com.mpush.core.push.SingleUserPushTask@3f589db2
16:24:01.217 - [mp-gateway-work-5-3] INFO - c.m.core.router.LocalRouterManager - lookup local router userId=user-0, router=LocalRouter{[channel=[id: 0x7217ffbd, L:/169.254.157.130:3000 - R:/169.254.157.130:59796], context={osName='android', osVersion='1.0.1', deviceId='test-device-id-0', userId='user-0', tags='test', heartbeat=30000}, status=1, lastReadTime=1577694191784, lastWriteTime=1577694191783]}
16:24:01.218 - [mp-conn-work-3-1] DEBUG - com.mpush.core.ack.AckTaskQueue - one ack task add to queue, task={, ackMessageId=3}, timeout=1499
16:24:01.218 -[push]- [SingleUserPush] push message to client success, timeLine=TimeLine[2](ms){push-center-begin --(1ms) --> before-send --(1ms) --> waiting-ack}, message=GatewayPushMessage{userId='user-0', clientType='1', timeout='1500', content='0'}
16:24:01.219 - [mp-conn-work-3-1] DEBUG - c.m.c.server.ServerChannelHandler - channelRead conn=[id: 0x7217ffbd, L:/169.254.157.130:3000 - R:/169.254.157.130:59796], packet={osName='android', osVersion='1.0.1', deviceId='test-device-id-0', userId='user-0', tags='test', heartbeat=30000}
16:24:01.219 - [mp-conn-work-3-1] DEBUG - com.mpush.core.push.PushCenter - add new task to push center, count=6, task=com.mpush.core.push.GatewayPushListener$2@45ce1e4b
16:24:01.219 -[push]- [SingleUserPush] client ack success, timeLine=TimeLine[3](ms){push-center-begin --(1ms) --> before-send --(1ms) --> waiting-ack --(1ms) --> success-end}, task={, ackMessageId=3}
16:24:03.502 -[monitor]- {"results":{"jvm-gc":{"fullGcCollectionCount":1,"yongGcCollectionTime":38,"spanYongGcCollectionTime":0,"spanFullGcCollectionCount":0,"yongGcCollectionCount":5,"spanYongGcCollectionCount":0,"fullGcCollectionTime":33,"spanFullGcCollectionTime":0},"jvm-memory":{"heapMemoryMax":1883242496,"survivorMax":5242880,"survivorInit":5242880,"heapMemoryUsed":83237632,"oldGenInit":89653248,"nonHeapMemoryCommitted":34275328,"heapMemoryCommitted":99614720,"edenSpaceUsed":22376208,"nonHeapMemoryUsed":33027936,"oldGenUsed":57274384,"permGenCommitted":0,"oldGenCommitted":60817408,"heapMemoryInit":134217728,"survivorUsed":3587040,"permGenInit":0,"permGenUsed":0,"edenSpaceMax":691535872,"nonHeapMemoryMax":-1,"nonHeapMemoryInit":2555904,"permGenMax":0,"edenSpaceCommitted":33554432,"survivorCommitted":5242880,"oldGenMax":1412431872,"edenSpaceInit":34078720},"jvm-thread":{"threadCount":40,"daemonThreadCount":17,"totalStartedThreadCount":43,"deadLockedThreadCount":0},"jvm-thread-pool":{"event-bus":{"corePoolSize":1,"poolSize(workThread)":1,"maxPoolSize":16,"queueSize(blockedTask)":0,"activeCount(workingThread)":0},"conn-worker":{"poolSize(workThread)":16,"queueSize(blockedTask)":0,"activeCount(workingThread)":16},"mq":{"corePoolSize":1,"poolSize(workThread)":0,"maxPoolSize":4,"queueSize(blockedTask)":0,"activeCount(workingThread)":0},"ack-timer":{"corePoolSize":1,"poolSize(workThread)":1,"maxPoolSize":2147483647,"queueSize(blockedTask)":0,"activeCount(workingThread)":0}},"jvm-info":{"totalMemory":"95m","load":-1.0,"pid":"13348","freeMemory":"15m","maxMemory":"1796m"}},"timestamp":1577694243496}
16:24:35.863 - [mp-conn-work-3-1] DEBUG - c.m.c.server.ServerChannelHandler - channelRead conn=[id: 0x7217ffbd, L:/169.254.157.130:3000 - R:/169.254.157.130:59796], packet={osName='android', osVersion='1.0.1', deviceId='test-device-id-0', userId='user-0', tags='test', heartbeat=30000}
16:24:35.864 -[heartbeat]- ping -> pong, [channel=[id: 0x7217ffbd, L:/169.254.157.130:3000 - R:/169.254.157.130:59796], context={osName='android', osVersion='1.0.1', deviceId='test-device-id-0', userId='user-0', tags='test', heartbeat=30000}, status=1, lastReadTime=1577694275864, lastWriteTime=1577694275864]
16:25:03.506 -[monitor]- {"results":{"jvm-gc":{"fullGcCollectionCount":1,"yongGcCollectionTime":38,"spanYongGcCollectionTime":0,"spanFullGcCollectionCount":0,"yongGcCollectionCount":5,"spanYongGcCollectionCount":0,"fullGcCollectionTime":33,"spanFullGcCollectionTime":0},"jvm-memory":{"heapMemoryMax":1883242496,"survivorMax":5242880,"survivorInit":5242880,"heapMemoryUsed":83591784,"oldGenInit":89653248,"nonHeapMemoryCommitted":34406400,"heapMemoryCommitted":99614720,"edenSpaceUsed":22730360,"nonHeapMemoryUsed":33177824,"oldGenUsed":57274384,"permGenCommitted":0,"oldGenCommitted":60817408,"heapMemoryInit":134217728,"survivorUsed":3587040,"permGenInit":0,"permGenUsed":0,"edenSpaceMax":691535872,"nonHeapMemoryMax":-1,"nonHeapMemoryInit":2555904,"permGenMax":0,"edenSpaceCommitted":33554432,"survivorCommitted":5242880,"oldGenMax":1412431872,"edenSpaceInit":34078720},"jvm-thread":{"threadCount":40,"daemonThreadCount":17,"totalStartedThreadCount":43,"deadLockedThreadCount":0},"jvm-thread-pool":{"event-bus":{"corePoolSize":1,"poolSize(workThread)":1,"maxPoolSize":16,"queueSize(blockedTask)":0,"activeCount(workingThread)":0},"conn-worker":{"poolSize(workThread)":16,"queueSize(blockedTask)":0,"activeCount(workingThread)":16},"mq":{"corePoolSize":1,"poolSize(workThread)":0,"maxPoolSize":4,"queueSize(blockedTask)":0,"activeCount(workingThread)":0},"ack-timer":{"corePoolSize":1,"poolSize(workThread)":1,"maxPoolSize":2147483647,"queueSize(blockedTask)":0,"activeCount(workingThread)":0}},"jvm-info":{"totalMemory":"95m","load":-1.0,"pid":"13348","freeMemory":"15m","maxMemory":"1796m"}},"timestamp":1577694303502}
16:25:04.963 - [mp-conn-work-3-1] DEBUG - c.m.c.server.ServerChannelHandler - channelRead conn=[id: 0x7217ffbd, L:/169.254.157.130:3000 - R:/169.254.157.130:59796], packet={osName='android', osVersion='1.0.1', deviceId='test-device-id-0', userId='user-0', tags='test', heartbeat=30000}
16:25:04.964 -[heartbeat]- ping -> pong, [channel=[id: 0x7217ffbd, L:/169.254.157.130:3000 - R:/169.254.157.130:59796], context={osName='android', osVersion='1.0.1', deviceId='test-device-id-0', userId='user-0', tags='test', heartbeat=30000}, status=1, lastReadTime=1577694304964, lastWriteTime=1577694304964]
16:25:34.061 - [mp-conn-work-3-1] DEBUG - c.m.c.server.ServerChannelHandler - channelRead conn=[id: 0x7217ffbd, L:/169.254.157.130:3000 - R:/169.254.157.130:59796], packet={osName='android', osVersion='1.0.1', deviceId='test-device-id-0', userId='user-0', tags='test', heartbeat=30000}
16:25:34.061 -[heartbeat]- ping -> pong, [channel=[id: 0x7217ffbd, L:/169.254.157.130:3000 - R:/169.254.157.130:59796], context={osName='android', osVersion='1.0.1', deviceId='test-device-id-0', userId='user-0', tags='test', heartbeat=30000}, status=1, lastReadTime=1577694334061, lastWriteTime=1577694334061]
16:26:03.162 - [mp-conn-work-3-1] DEBUG - c.m.c.server.ServerChannelHandler - channelRead conn=[id: 0x7217ffbd, L:/169.254.157.130:3000 - R:/169.254.157.130:59796], packet={osName='android', osVersion='1.0.1', deviceId='test-device-id-0', userId='user-0', tags='test', heartbeat=30000}
16:26:03.162 -[heartbeat]- ping -> pong, [channel=[id: 0x7217ffbd, L:/169.254.157.130:3000 - R:/169.254.157.130:59796], context={osName='android', osVersion='1.0.1', deviceId='test-device-id-0', userId='user-0', tags='test', heartbeat=30000}, status=1, lastReadTime=1577694363162, lastWriteTime=1577694363162]
16:26:03.510 -[monitor]- {"results":{"jvm-gc":{"fullGcCollectionCount":1,"yongGcCollectionTime":38,"spanYongGcCollectionTime":0,"spanFullGcCollectionCount":0,"yongGcCollectionCount":5,"spanYongGcCollectionCount":0,"fullGcCollectionTime":33,"spanFullGcCollectionTime":0},"jvm-memory":{"heapMemoryMax":1883242496,"survivorMax":5242880,"survivorInit":5242880,"heapMemoryUsed":83753800,"oldGenInit":89653248,"nonHeapMemoryCommitted":34406400,"heapMemoryCommitted":99614720,"edenSpaceUsed":22892376,"nonHeapMemoryUsed":33226144,"oldGenUsed":57274384,"permGenCommitted":0,"oldGenCommitted":60817408,"heapMemoryInit":134217728,"survivorUsed":3587040,"permGenInit":0,"permGenUsed":0,"edenSpaceMax":691535872,"nonHeapMemoryMax":-1,"nonHeapMemoryInit":2555904,"permGenMax":0,"edenSpaceCommitted":33554432,"survivorCommitted":5242880,"oldGenMax":1412431872,"edenSpaceInit":34078720},"jvm-thread":{"threadCount":40,"daemonThreadCount":17,"totalStartedThreadCount":43,"deadLockedThreadCount":0},"jvm-thread-pool":{"event-bus":{"corePoolSize":1,"poolSize(workThread)":1,"maxPoolSize":16,"queueSize(blockedTask)":0,"activeCount(workingThread)":0},"conn-worker":{"poolSize(workThread)":16,"queueSize(blockedTask)":0,"activeCount(workingThread)":16},"mq":{"corePoolSize":1,"poolSize(workThread)":0,"maxPoolSize":4,"queueSize(blockedTask)":0,"activeCount(workingThread)":0},"ack-timer":{"corePoolSize":1,"poolSize(workThread)":1,"maxPoolSize":2147483647,"queueSize(blockedTask)":0,"activeCount(workingThread)":0}},"jvm-info":{"totalMemory":"95m","load":-1.0,"pid":"13348","freeMemory":"15m","maxMemory":"1796m"}},"timestamp":1577694363507}
16:26:32.264 - [mp-conn-work-3-1] DEBUG - c.m.c.server.ServerChannelHandler - channelRead conn=[id: 0x7217ffbd, L:/169.254.157.130:3000 - R:/169.254.157.130:59796], packet={osName='android', osVersion='1.0.1', deviceId='test-device-id-0', userId='user-0', tags='test', heartbeat=30000}
16:26:32.265 -[heartbeat]- ping -> pong, [channel=[id: 0x7217ffbd, L:/169.254.157.130:3000 - R:/169.254.157.130:59796], context={osName='android', osVersion='1.0.1', deviceId='test-device-id-0', userId='user-0', tags='test', heartbeat=30000}, status=1, lastReadTime=1577694392264, lastWriteTime=1577694392265]
16:27:01.363 - [mp-conn-work-3-1] DEBUG - c.m.c.server.ServerChannelHandler - channelRead conn=[id: 0x7217ffbd, L:/169.254.157.130:3000 - R:/169.254.157.130:59796], packet={osName='android', osVersion='1.0.1', deviceId='test-device-id-0', userId='user-0', tags='test', heartbeat=30000}
16:27:01.364 -[heartbeat]- ping -> pong, [channel=[id: 0x7217ffbd, L:/169.254.157.130:3000 - R:/169.254.157.130:59796], context={osName='android', osVersion='1.0.1', deviceId='test-device-id-0', userId='user-0', tags='test', heartbeat=30000}, status=1, lastReadTime=1577694421363, lastWriteTime=1577694421364]
16:27:03.518 -[monitor]- {"results":{"jvm-gc":{"fullGcCollectionCount":1,"yongGcCollectionTime":38,"spanYongGcCollectionTime":0,"spanFullGcCollectionCount":0,"yongGcCollectionCount":5,"spanYongGcCollectionCount":0,"fullGcCollectionTime":33,"spanFullGcCollectionTime":0},"jvm-memory":{"heapMemoryMax":1883242496,"survivorMax":5242880,"survivorInit":5242880,"heapMemoryUsed":83971304,"oldGenInit":89653248,"nonHeapMemoryCommitted":34471936,"heapMemoryCommitted":99614720,"edenSpaceUsed":23109880,"nonHeapMemoryUsed":33248760,"oldGenUsed":57274384,"permGenCommitted":0,"oldGenCommitted":60817408,"heapMemoryInit":134217728,"survivorUsed":3587040,"permGenInit":0,"permGenUsed":0,"edenSpaceMax":691535872,"nonHeapMemoryMax":-1,"nonHeapMemoryInit":2555904,"permGenMax":0,"edenSpaceCommitted":33554432,"survivorCommitted":5242880,"oldGenMax":1412431872,"edenSpaceInit":34078720},"jvm-thread":{"threadCount":40,"daemonThreadCount":17,"totalStartedThreadCount":43,"deadLockedThreadCount":0},"jvm-thread-pool":{"event-bus":{"corePoolSize":1,"poolSize(workThread)":1,"maxPoolSize":16,"queueSize(blockedTask)":0,"activeCount(workingThread)":0},"conn-worker":{"poolSize(workThread)":16,"queueSize(blockedTask)":0,"activeCount(workingThread)":16},"mq":{"corePoolSize":1,"poolSize(workThread)":0,"maxPoolSize":4,"queueSize(blockedTask)":0,"activeCount(workingThread)":0},"ack-timer":{"corePoolSize":1,"poolSize(workThread)":1,"maxPoolSize":2147483647,"queueSize(blockedTask)":0,"activeCount(workingThread)":0}},"jvm-info":{"totalMemory":"95m","load":-1.0,"pid":"13348","freeMemory":"14m","maxMemory":"1796m"}},"timestamp":1577694423510}
16:27:30.461 - [mp-conn-work-3-1] DEBUG - c.m.c.server.ServerChannelHandler - channelRead conn=[id: 0x7217ffbd, L:/169.254.157.130:3000 - R:/169.254.157.130:59796], packet={osName='android', osVersion='1.0.1', deviceId='test-device-id-0', userId='user-0', tags='test', heartbeat=30000}
16:27:30.462 -[heartbeat]- ping -> pong, [channel=[id: 0x7217ffbd, L:/169.254.157.130:3000 - R:/169.254.157.130:59796], context={osName='android', osVersion='1.0.1', deviceId='test-device-id-0', userId='user-0', tags='test', heartbeat=30000}, status=1, lastReadTime=1577694450461, lastWriteTime=1577694450462]
16:27:59.561 - [mp-conn-work-3-1] DEBUG - c.m.c.server.ServerChannelHandler - channelRead conn=[id: 0x7217ffbd, L:/169.254.157.130:3000 - R:/169.254.157.130:59796], packet={osName='android', osVersion='1.0.1', deviceId='test-device-id-0', userId='user-0', tags='test', heartbeat=30000}
16:27:59.561 -[heartbeat]- ping -> pong, [channel=[id: 0x7217ffbd, L:/169.254.157.130:3000 - R:/169.254.157.130:59796], context={osName='android', osVersion='1.0.1', deviceId='test-device-id-0', userId='user-0', tags='test', heartbeat=30000}, status=1, lastReadTime=1577694479561, lastWriteTime=1577694479561]
16:28:03.521 -[monitor]- {"results":{"jvm-gc":{"fullGcCollectionCount":1,"yongGcCollectionTime":38,"spanYongGcCollectionTime":0,"spanFullGcCollectionCount":0,"yongGcCollectionCount":5,"spanYongGcCollectionCount":0,"fullGcCollectionTime":33,"spanFullGcCollectionTime":0},"jvm-memory":{"heapMemoryMax":1883242496,"survivorMax":5242880,"survivorInit":5242880,"heapMemoryUsed":84133208,"oldGenInit":89653248,"nonHeapMemoryCommitted":34537472,"heapMemoryCommitted":99614720,"edenSpaceUsed":23271784,"nonHeapMemoryUsed":33328912,"oldGenUsed":57274384,"permGenCommitted":0,"oldGenCommitted":60817408,"heapMemoryInit":134217728,"survivorUsed":3587040,"permGenInit":0,"permGenUsed":0,"edenSpaceMax":691535872,"nonHeapMemoryMax":-1,"nonHeapMemoryInit":2555904,"permGenMax":0,"edenSpaceCommitted":33554432,"survivorCommitted":5242880,"oldGenMax":1412431872,"edenSpaceInit":34078720},"jvm-thread":{"threadCount":40,"daemonThreadCount":17,"totalStartedThreadCount":43,"deadLockedThreadCount":0},"jvm-thread-pool":{"event-bus":{"corePoolSize":1,"poolSize(workThread)":1,"maxPoolSize":16,"queueSize(blockedTask)":0,"activeCount(workingThread)":0},"conn-worker":{"poolSize(workThread)":16,"queueSize(blockedTask)":0,"activeCount(workingThread)":16},"mq":{"corePoolSize":1,"poolSize(workThread)":0,"maxPoolSize":4,"queueSize(blockedTask)":0,"activeCount(workingThread)":0},"ack-timer":{"corePoolSize":1,"poolSize(workThread)":1,"maxPoolSize":2147483647,"queueSize(blockedTask)":0,"activeCount(workingThread)":0}},"jvm-info":{"totalMemory":"95m","load":-1.0,"pid":"13348","freeMemory":"14m","maxMemory":"1796m"}},"timestamp":1577694483518}