D
dbeavon
Guest
So in my effort to troubleshoot high cpu in the admin server (related primarily to our attempts to start using OEE), I've turned up the logging level to 5 as explained here: https://documentation.progress.com/output/ua/OpenEdge_latest/index.html#page/oemgs/setting-the-log-level-for-the-adminserver-log-fi.html The logs definitely pump out lot of additional messaging for the entire time that the java process is swamping CPU. Here is a sample showing the beginning and ending (omitting intermediate stuff). Keep in mind that this is only the admin server activity from clicking on a single user ID in OEE, on a relatively quiet testing database that has only been up for about 2 hours. Depending on the user I click on, and the length of time the database has been up, the duration of these clicks can cause a much bigger problem in admin server CPU. I'm not trying to mislead anyone or exagerate. I would love for this to work better on HP-UX. I am starting to suspect there aren't many who are using this, or at least not on HP-UX. [2017/04/20@11:02:24.147-0400] [5] [DatabaseAgent] VST query for agent _SMDatabase_etest table _Database-Feature start [2017/04/20@11:02:24.148-0400] [5] [DatabaseAgent] id: 1 nioendpoint: uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679] ----> agent message: time: 1492700544147 name : QRY_VST_TBL code: 0 length: 74 sequence: 0 type: 1 session: 0 status: 0 [2017/04/20@11:02:24.148-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: queue write: java.nio.HeapByteBuffer[pos=0 lim=74 cap=74] [2017/04/20@11:02:24.148-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: writing buffer: java.nio.HeapByteBuffer[pos=0 lim=74 cap=74] [2017/04/20@11:02:24.149-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: wrote 74 bytes [2017/04/20@11:02:24.155-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: reading into buffer: java.nio.HeapByteBuffer[pos=0 lim=68 cap=68] [2017/04/20@11:02:24.155-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: returning with 68 total bytes read [2017/04/20@11:02:24.155-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: reading into buffer: java.nio.HeapByteBuffer[pos=0 lim=1111 cap=1111] [2017/04/20@11:02:24.155-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: returning with 1111 total bytes read [2017/04/20@11:02:24.156-0400] [5] [DatabaseAgent] id: 1 nioendpoint: uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679] agent message: time: 1492700544171 name : QRY_VST_TBL code: 0 length: 74 sequence: 0 type: 1 session: 0 status: 0 [2017/04/20@11:02:24.171-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: queue write: java.nio.HeapByteBuffer[pos=0 lim=74 cap=74] [2017/04/20@11:02:24.172-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: writing buffer: java.nio.HeapByteBuffer[pos=0 lim=74 cap=74] [2017/04/20@11:02:24.172-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: wrote 74 bytes [2017/04/20@11:02:24.175-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: reading into buffer: java.nio.HeapByteBuffer[pos=0 lim=68 cap=68] [2017/04/20@11:02:24.175-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: returning with 68 total bytes read [2017/04/20@11:02:24.176-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: reading into buffer: java.nio.HeapByteBuffer[pos=0 lim=14463 cap=14463] [2017/04/20@11:02:24.176-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: returning with 14463 total bytes read [2017/04/20@11:02:24.185-0400] [5] [DatabaseAgent] id: 1 nioendpoint: uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679] agent message: time: 1492700544689 name : QRY_VST_TBL code: 0 length: 72 sequence: 0 type: 1 session: 0 status: 0 [2017/04/20@11:02:24.690-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: queue write: java.nio.HeapByteBuffer[pos=0 lim=72 cap=72] [2017/04/20@11:02:24.723-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: writing buffer: java.nio.HeapByteBuffer[pos=0 lim=72 cap=72] [2017/04/20@11:02:24.723-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: wrote 72 bytes [2017/04/20@11:02:24.724-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: reading into buffer: java.nio.HeapByteBuffer[pos=0 lim=68 cap=68] [2017/04/20@11:02:24.724-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: returning with 68 total bytes read [2017/04/20@11:02:24.724-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: reading into buffer: java.nio.HeapByteBuffer[pos=0 lim=760 cap=760] [2017/04/20@11:02:24.724-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: returning with 760 total bytes read [2017/04/20@11:02:24.725-0400] [5] [DatabaseAgent] id: 1 nioendpoint: uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679] agent message: time: 1492700544736 name : QRY_VST_TBL code: 0 length: 74 sequence: 0 type: 1 session: 0 status: 0 [2017/04/20@11:02:24.737-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: queue write: java.nio.HeapByteBuffer[pos=0 lim=74 cap=74] [2017/04/20@11:02:24.756-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: writing buffer: java.nio.HeapByteBuffer[pos=0 lim=74 cap=74] [2017/04/20@11:02:24.756-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: wrote 74 bytes [2017/04/20@11:02:24.759-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: reading into buffer: java.nio.HeapByteBuffer[pos=0 lim=68 cap=68] [2017/04/20@11:02:24.759-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: returning with 68 total bytes read [2017/04/20@11:02:24.759-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: reading into buffer: java.nio.HeapByteBuffer[pos=0 lim=4047 cap=4047] [2017/04/20@11:02:24.759-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: returning with 4047 total bytes read [2017/04/20@11:02:24.762-0400] [5] [DatabaseAgent] id: 1 nioendpoint: uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679] agent message: time: 1492700544792 name : QRY_VST_TBL code: 0 length: 74 sequence: 0 type: 1 session: 0 status: 0 [2017/04/20@11:02:24.793-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: queue write: java.nio.HeapByteBuffer[pos=0 lim=74 cap=74] [2017/04/20@11:02:24.793-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: writing buffer: java.nio.HeapByteBuffer[pos=0 lim=74 cap=74] [2017/04/20@11:02:24.793-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: wrote 74 bytes [2017/04/20@11:02:24.794-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: reading into buffer: java.nio.HeapByteBuffer[pos=0 lim=68 cap=68] [2017/04/20@11:02:24.794-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: returning with 68 total bytes read [2017/04/20@11:02:24.795-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: reading into buffer: java.nio.HeapByteBuffer[pos=0 lim=4038 cap=4038] [2017/04/20@11:02:24.795-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: returning with 4038 total bytes read [2017/04/20@11:02:24.797-0400] [5] [DatabaseAgent] id: 1 nioendpoint: uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679] agent message: time: 1492700617833 name : QRY_VST_TBL code: 0 length: 79 sequence: 0 type: 1 session: 0 status: 0 [2017/04/20@11:03:37.833-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: queue write: java.nio.HeapByteBuffer[pos=0 lim=79 cap=79] [2017/04/20@11:03:37.834-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: writing buffer: java.nio.HeapByteBuffer[pos=0 lim=79 cap=79] [2017/04/20@11:03:37.834-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: wrote 79 bytes [2017/04/20@11:03:37.859-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: reading into buffer: java.nio.HeapByteBuffer[pos=0 lim=68 cap=68] [2017/04/20@11:03:37.859-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: returning with 68 total bytes read [2017/04/20@11:03:37.859-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: reading into buffer: java.nio.HeapByteBuffer[pos=0 lim=14226 cap=14226] [2017/04/20@11:03:37.859-0400] [5] [DatabaseAgent] uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679]: returning with 14226 total bytes read [2017/04/20@11:03:37.860-0400] [5] [DatabaseAgent] id: 1 nioendpoint: uuid:9784fb00-1a10-4d64-a6b2-f047fcef41da channel: java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8845 remote=/172.31.18.79:60679] <---- agent message: time: 1492700617859 name : QRY_VST_TBL_ACK code: 1101 length: 14294 sequence: 1 type: 5 session: 463 status: 0 [2017/04/20@11:03:37.860-0400] [5] [DatabaseAgent] Received message agent message: time: 1492700617859 name : QRY_VST_TBL_ACK code: 1101 length: 14294 sequence: 1 type: 5 session: 463 status: 0 from client 1. (8492) [2017/04/20@11:03:37.860-0400] [5] [DatabaseAgent] VST query for agent _SMDatabase_etest table _StorageObject end time(ms): 27
Continue reading...
Continue reading...