By Alex - 15 Aug 2020
Hi,
I'm trying to parse a logcat file, which is like below:
01-01 00:03:31.788 591 591 W SELinux : Multiple same specifications for qti.ims.ext. 06-16 12:49:15.390 734 1334 I abc : type=1400 audit(0.0:18414): avc: denied { read } for abc 06-16 12:49:15.390 734 734 I e : something here 06-16 12:49:15.403 1502 1668 I Engine: vs_get_temperature: read[0] skin-therm 33922 mC, weight[0] 553
I create one parse rule like below: %d{MM-dd %H:mm:ss.fff} %t %t %p %c:%m%n
but the output is not correct, as below, output exist 3 problem: 1. line 2,3,4 mixed 2. subpid is missing. 3. the space between pid and subpid is not fixed value. It may be 2 or 3, depends on the length of subpid. I can't find one way to handle such case.
Could you please kindly help me here?
Thanks!
|
By LogViewPlus Support - 15 Aug 2020
Hi Alex,
What version of LogViewPlus are you using? Using v2.4.41, if I parse the file with the pattern you provided, I get a different result.
Which looks like the file was parsed correctly. Maybe the parser is getting confused before the actual problem is visible? In which case, I will not be able to reproduce the problem with the lines provided.
There appears to be a little bit of weirdness happening with the colon. Sometimes it is proceeded with a space, and sometimes it isn't. It does not appear to mark a place holder for an optional field. This is a bit strange and might be part of the problem.
Also, your pattern has "%t" twice. This is saying you have two sets of data which both belong in the 'Thread' column. This is not supported and the first set of data would be overwritten by the second.
Putting this all together, I would recommend parsing the file with: %d{MM-dd %H:mm:ss.fff} %s{Column1} %t %p %c: %m%n
This is very similar to the pattern you suggested, so I think the problem may be somewhere else.
Hope that helps,
Toby
|
By Alex - 22 Aug 2020
Hi Toby,
Thanks for your checking and answer, finally I wrote one parser dll and resolved this problem
Have a nice day.
BR Alex
|
By LogViewPlus Support - 22 Aug 2020
Thanks for the update Alex. Glad to hear you got it working.
Were you able to find the underlying issue? It would be good to know why LogViewPlus was having difficulty with this file.
Toby
|
By morty - 9 Jan 2022
im using this %d %t %s{Column1} %p %m%n i had to add a global log level in configuration so the "E" gets recongnized as error. and sometimes i get a bad parsing when there is only one space between the numbers (after the timestamp) as the next two lines show : 01-09 13:24:22.251 4826 4826 I SurfaceFlinger: SFWD update time=19495346470633 01-09 13:24:23.125 26402 26402 I SoundAlivePolicyManager: isGlobalEffectSupportCurrentAudioPath, currentDeviceType : 2
|
By LogViewPlus Support - 10 Jan 2022
Hi Morty,
It looks like the Thread and String1 columns are left padded to be a minimum length of 5 characters. I can get a good parse of the sample log entries provided with:
%d %5t %5s{Column1} %p %m%n
It looks like you could even add the logger with:
%d %5t %5s{Column1} %p %c: %m%n
Please see our documentation for more information on fixed length fields.
However, from your screenshot it looks like the log entries above these are also 4 characters long. If you still have problems, it may help if you could provide some additional log entries.
You needed to add 'E' as a global log level because there is also an 'Emergency' level declared as fatal - so there is a conflict. I will take a look to see if we can handle 'E' as a special case.
Hope that helps,
Toby
|
By morty - 11 Jan 2022
for me is working great with your recommendation, thank you for that, i dont need more support but in case you want to look further into this im adding a bigger piece of the log, And for those who wonder how to get the android log live into a file here is the command i use in windows terminal:
adb logcat all > yourfile.txt my device is connected to my pc with a usb and i had installed android studio (which installs adb), and using logviewplus i open "yourfile.txt"
Log sample::01-10 22:27:24.162 363 409 I DBG_FMESEC :[FmmMcfManager ]: Start offline scanining 01-10 22:27:24.163 363 409 I [MCFSDK_fmm_1.0.2039]_17_McfBleAdapterImpl: getBleScanner - 01-10 22:27:24.166 363 409 W [MCFSDK_fmm_1.0.2039]_17_McfBleAdapterImpl: stopScan - Ignore - not started 01-10 22:27:24.166 363 409 I [MCFSDK_fmm_1.0.2039]_17_McfBleAdapterImpl: getBleScanner - 01-10 22:27:24.169 363 409 I [MCFSDK_fmm_1.0.2039]_17_McfBleAdapterImpl: startScan - screenOnFilter - 2 01-10 22:27:24.170 363 409 I [MCFSDK_fmm_1.0.2039]_17_McfBleAdapterImpl: startScan - screenOffFilter - 2 01-10 22:27:24.175 6823 6823 I [MCFServer]_BleAdapterManager: startScan - BAScanCallback{Settings=BleScanSettings{mode=0, rssi=-128, timeout=0, phy =0}, Callback=CB{i=17, h=102983574}} 01-10 22:27:24.277 6823 6823 I [MCFServer]_BleScanner(BA): startScan - BAScanPolicy{, IDs={17}} 01-10 22:27:24.277 6823 6823 I BluetoothAdapter: STATE_BLE_ON 01-10 22:27:24.278 6823 6823 I BluetoothAdapter: appoCount is = 0 G/S = 4/4 01-10 22:27:24.279 6823 6823 I BluetoothAdapter: STATE_BLE_ON 01-10 22:27:24.279 6823 6823 I BluetoothAdapter: appoCount is = 0 G/S = 4/4 01-10 22:27:24.280 6823 6823 I BluetoothAdapter: STATE_BLE_ON 01-10 22:27:24.280 6823 6823 I BluetoothAdapter: appoCount is = 0 G/S = 4/4 01-10 22:27:24.292 6374 7999 D BtGatt.ContextMap: add() - appUid: 1000, appPid: 6823, appName: android.uid.system 01-10 22:27:24.297 6374 6497 I bt_stack: [INFO:gatt_api.cc(950)] GATT_Register 6e9ecb2b-3730-4c17-81cc-7954dc3fbfad 01-10 22:27:24.297 6374 6497 I bt_stack: [INFO:gatt_api.cc(994)] allocated gatt_if=5 01-10 22:27:24.297 6374 6497 I bt_stack: [INFO:gatt_api.cc(1101)] GATT_StartIf gatt_if=5 01-10 22:27:24.300 6374 6436 D BtGatt.GattService: onScannerRegistered() - UUID=6e9ecb2b-3730-4c17-81cc-7954dc3fbfad, scannerId=5, status=0 01-10 22:27:24.308 6374 7999 I BluetoothAdapter: STATE_BLE_ON 01-10 22:27:24.309 6374 7999 I BluetoothAdapter: bleAppCnt is = 4 01-10 22:27:24.335 6374 6471 I BluetoothAdapter: STATE_BLE_ON 01-10 22:27:24.335 6374 6471 I BluetoothAdapter: appoCount is = 0 G/S = 4/4 01-10 22:27:24.341 6374 6475 W BtGatt.GattService: checkToReportData before boot completed 01-10 22:27:24.341 6374 6471 I BluetoothAdapter: STATE_BLE_ON 01-10 22:27:24.341 6374 6475 E BtGatt.GattService: [GSIM LOG]: gsimLogHandler, msg: MESSAGE_SCAN_START, appName: android.uid.system, scannerId: 5, reportDelayMillis=0 01-10 22:27:24.342 6374 6471 I BluetoothAdapter: appoCount is = 0 G/S = 4/4 01-10 22:27:24.342 6374 6471 I BluetoothAdapter: STATE_BLE_ON 01-10 22:27:24.343 6374 6471 I BluetoothAdapter: appoCount is = 0 G/S = 4/4 01-10 22:27:24.360 6374 6471 D BtGatt.ScanManager: configureFilterParamter() : onFoundTimeout | onLostTimeout | onFoundCount | numOfTrackingEntries | scanFilterRssiThreshold | trackableScanFilterRssiThreshold | matchMode 01-10 22:27:24.360 6374 6471 D BtGatt.ScanManager: configureFilterParamter() : __________500__|________10000__|___________1__|___________________0__|___________________-128__|____________________________-128__|________1_ 01-10 22:27:24.371 6374 6471 D BtGatt.ScanManager: configureFilterParamter() : onFoundTimeout | onLostTimeout | onFoundCount | numOfTrackingEntries | scanFilterRssiThreshold | trackableScanFilterRssiThreshold | matchMode 01-10 22:27:24.371 6374 6471 D BtGatt.ScanManager: configureFilterParamter() : __________500__|________10000__|___________1__|___________________0__|___________________-128__|____________________________-128__|________1_ 01-10 22:27:24.381 6374 6497 W bt_btm : btm_ble_disable_resolving_list() rl_state = 0xb, rl_mask = 0x2, to_resume = 1 01-10 22:27:24.381 6374 6497 W bt_btm : btm_ble_enable_resolving_list() rl_state = 0x9, rl_mask = 0x2 01-10 22:27:24.655 6571 6571 D BoundBrokerSvc: onUnbind: Intent { act=com.google.android.gms.measurement.START pkg=com.google.android.gms } 01-10 22:27:24.712 4849 4849 I SurfaceFlinger: SFWD update time=9972350433983 01-10 22:27:24.928 5878 5878 I IpcDispatcher<0>: handleMessage: EVENT_SEC_CHANNEL_PROXY_DEAD cookie = 4955 mSecChannelProxyCookie = 4955 01-10 22:27:24.930 4257 4257 I hwservicemanager: getTransport: Cannot find entry vendor.samsung.hardware.radio.channel@2.0::ISehChannel/imsd in either framework or device manifest. 01-10 22:27:24.931 5878 5878 E IpcDispatcher<0>: SecChannelProxy getService/setCallback: java.util.NoSuchElementException 01-10 22:27:25.044 4783 32603 E HYPER-HAL: [HandlerSysfs.cpp]doResourceHandling(): Couldn't Open Sysfs - /sys/kernel/mm/vmscan/am_app_launch 01-10 22:27:25.046 4783 32603 I HYPER-HAL: [ResourceManager.cpp]removeResource(): [CPUMaxFreq] RemoveResource Request ID : 28143766 01-10 22:27:25.047 4783 32603 I HYPER-HAL: [RequestManager.cpp]releaseLocked(): Released ID : 28143766 01-10 22:27:25.331 5133 7424 I EDMNativeHelperService: isCameraEnabled 01-10 22:27:25.331 5133 7424 D EDMNativeHelper: isCameraEnabled 01-10 22:27:25.337 5133 7424 D EDMNativeHelper: checking for camera in EnterpriseDeviceManagerService 01-10 22:27:25.337 5133 7424 D EnterpriseDeviceManagerService: isCameraEnabledNative 01-10 22:27:25.337 5133 7424 D EnterpriseDeviceManagerService: checking for camera in restriction policy 01-10 22:27:25.338 5133 7424 D RestrictionPolicy: isCameraEnabled ret(true) userId(0) cxtInfo.mCallerUid(10364) cxtInfo.mContainerId(0) 01-10 22:27:25.967 5133 5460 I Pageboost: Launcher App Execution 01-10 22:27:26.084 5133 5460 I Pageboost: IoRecord pid : 23885 01-10 22:27:26.098 5133 5460 I Pageboost: IoRecord pid : 23885, result_size : 14098 01-10 22:27:26.115 4416 4416 D io_stats: !@ 8,0 r 559628 14758484 w 84810 2568420 d 53963 15318856 f 47573 57186 iot 177836 149357 th 102400 0 0 pt 0 inp 0 0 9973.749 01-10 22:27:26.139 5133 5460 I Pageboost: db create : CREATE TABLE IF NOT EXISTS mxmotionarfacemocap (FILENAME TEXT, OFFSET INTEGER, SIZE INTEGER, FORVRAMDISK INTEGER, BITMAP BLOB, unique (FILENAME, OFFSET) ); 01-10 22:27:26.142 5133 5460 I Pageboost: db insert start 01-10 22:27:26.147 5133 5460 I Pageboost: db insert done, overLimit false 01-10 22:27:26.148 5133 5460 I Pageboost: captureFinished success : 38395904 01-10 22:27:26.149 5133 5460 I Pageboost: db create : CREATE TABLE IF NOT EXISTS mxmotionarfacemocap (FILENAME TEXT, OFFSET INTEGER, SIZE INTEGER, FORVRAMDISK INTEGER, BITMAP BLOB, unique (FILENAME, OFFSET) ); 01-10 22:27:26.160 5133 5460 I Pageboost: db update :mx.motion.ar.facemocap ret 1 01-10 22:27:26.167 23885 342 V third_party/redwood/infrastructure/jni_common/jni_helper.cc: JniHelper: attached thread (Called from line 93). 01-10 22:27:26.167 23885 342 V third_party/redwood/infrastructure/jni_common/jni_helper.cc: ~JniHelper: about to detach thread (Called from line 93). 01-10 22:27:26.168 23885 342 V third_party/redwood/infrastructure/jni_common/jni_helper.cc: ~JniHelper: detached thread (Called from line 93). 01-10 22:27:26.168 23885 342 I native : I0110 22:27:26.168282 342 model_selector.cc:82] Switching to the ultra lite model. 01-10 22:27:26.221 23885 338 I tflite : Replacing 176 node(s) with delegate (TfLiteXNNPackDelegate) node, yielding 2 partitions. 01-10 22:27:26.391 5133 5460 I Pageboost: memUsage collected : 197622 27126 103920 for mx.motion.ar.facemocap 23885 01-10 22:27:26.398 5397 5397 I wpa_supplicant: Heartbeat 997 01-10 22:27:27.140 6170 6170 D BoundBrokerSvc: onUnbind: Intent { act=com.google.android.gms.udc.service.START pkg=com.google.android.gms } 01-10 22:27:27.160 4903 32728 I Camera3-Device: Watchdog... 01-10 22:27:27.181 5133 9591 D SemGameManager: getGMSBinder(), begin 01-10 22:27:27.183 5133 9591 D SemGameManager: getGMSBinder(), successful: true 01-10 22:27:27.183 5133 9591 D GameManagerService: identifyGamePackage. mx.motion.ar.facemocap, mCurrentUserId: 0, callerUserId: 0 01-10 22:27:27.183 5133 9591 D PkgDataHelper: getGamePkgData(). mx.motion.ar.facemocap 01-10 22:27:27.194 4786 32731 I ExynosCameraFrameManager: [CAM(1)][RUNNING FRAME WORKER]-(workerMain[952]): wait and pop fail, ret(-110) 01-10 22:27:27.906 5133 32640 I SystemUiVisibilityPolicyController: handleMessage: entry what = 101 01-10 22:27:28.122 4416 4416 D io_stats: !@ 8,0 r 559696 14759272 w 84821 2568832 d 54025 15319588 f 47620 57237 iot 177864 149385 th 102400 0 0 pt 0 inp 0 0 9975.755 01-10 22:27:28.344 5133 5565 I EDMNativeHelperService: isCameraEnabled 01-10 22:27:28.344 5133 5565 D EDMNativeHelper: isCameraEnabled 01-10 22:27:28.349 5133 5565 D EDMNativeHelper: checking for camera in EnterpriseDeviceManagerService 01-10 22:27:28.350 5133 5565 D EnterpriseDeviceManagerService: isCameraEnabledNative 01-10 22:27:28.350 5133 5565 D EnterpriseDeviceManagerService: checking for camera in restriction policy 01-10 22:27:28.350 5133 5565 D RestrictionPolicy: isCameraEnabled ret(true) userId(0) cxtInfo.mCallerUid(10364) cxtInfo.mContainerId(0) 01-10 22:27:28.451 23885 32646 I native : I0110 22:27:28.451508 32646 session.cc:3330] Update Frame Delay to 4 frames. 01-10 22:27:28.931 5878 5878 I IpcDispatcher<0>: handleMessage: EVENT_SEC_CHANNEL_PROXY_DEAD cookie = 4957 mSecChannelProxyCookie = 4957 01-10 22:27:28.932 4257 4257 I hwservicemanager: getTransport: Cannot find entry vendor.samsung.hardware.radio.channel@2.0::ISehChannel/imsd in either framework or device manifest. 01-10 22:27:28.934 5878 5878 E IpcDispatcher<0>: SecChannelProxy getService/setCallback: java.util.NoSuchElementException 01-10 22:27:29.212 7489 8847 I SDHMS:G : -99 > surface_temperature_0 01-10 22:27:29.215 7489 8847 I SDHMS:G : writeSysfs:: path() : /sys/class/audio/amp/surface_temperature_0 exist() : false canWrite() : false 01-10 22:27:29.215 7489 8847 I SDHMS:G : -99 > surface_temperature_1 01-10 22:27:29.216 7489 8847 I SDHMS:G : writeSysfs:: path() : /sys/class/audio/amp/surface_temperature_1 exist() : false canWrite() : false 01-10 22:27:29.216 7489 8847 I SDHMS:G : SIOP:: AP:190(303,60) BAT:237(237,0) USB:0(0,0) CHG:273(273,0) WIFI:256(256,0) BLK:252(252,0) 01-10 22:27:29.708 5133 6661 D BatteryService: Sending ACTION_BATTERY_CHANGED. scale:100, info:{.chargerAcOnline = false, .chargerUsbOnline = true, .chargerWirelessOnline = false, .maxChargingCurrent = 0, .maxChargingVoltage = 0, .batteryStatus = CHARGING, .batteryHealth = GOOD, .batteryPresent = true, .batteryLevel = 74, .batteryVoltage = 3945, .batteryTemperature = 237, .batteryCurrent = -509, .batteryCycleCount = 0, .batteryFullCharge = 7040000, .batteryChargeCounter = 4878080, .batteryTechnology = Li-ion} 01-10 22:27:29.708 5133 6661 D BatteryService: online:5, current avg:-515, charge type:2, POGO powered:false, power sharing:false, high voltage charger:false, charger_type:0, capacity:280000, misc_event:0x10000, current_event:0x8000, current_now:-509 01-10 22:27:29.712 4849 4849 I SurfaceFlinger: SFWD update time=9977350629402 01-10 22:27:29.713 5133 5133 D PhoneWindowManagerExt: ACTION_BATTERY_CHANGED - Level=74, status=2 01-10 22:27:29.716 5133 5133 D SemWifiApBroadcastReceiver: Received : android.intent.action.BATTERY_CHANGED 01-10 22:27:29.722 5133 5256 D MotionRecognitionService: onReceive : ACTION_BATTERY_CHANGED, Plugged: 2 01-10 22:27:29.723 5133 5256 I MotionRecognitionService: [TA] In/out: true, curr state: 1 01-10 22:27:29.726 5474 5474 I PowerUI : BATTERY_HEALTH_CHECK extraHealth=2 mBatteryMiscEvent=65536 01-10 22:27:29.727 5474 5474 D PowerUI : priorPlugType = 2 mPlugType = 2 priorBatteryStatus = 2 mBatteryStatus = 2 01-10 22:27:29.736 5454 5454 D SemBigDataInfoController: Intent : android.intent.action.BATTERY_CHANGED 01-10 22:27:29.740 23190 23190 D TransportListener: Updating 01-10 22:27:29.753 5474 5474 D PowerUI.Notification: showChargingNotice oldChargingType : 7 currentChargingType : 7 oldChargingTime : 56126000 mChargingTime : 56126000 01-10 22:27:29.753 5474 5474 D PowerUI.Notification: There is no change about charging status, so return! 01-10 22:27:29.753 5474 5474 I PowerUI : mBatteryMiscEvent = 65536 01-10 22:27:29.753 5474 5474 D PowerUI : showing power sharing dialogfalse 01-10 22:27:29.756 5474 5474 D KeyguardUpdateMonitor: received broadcast android.intent.action.BATTERY_CHANGED 01-10 22:27:29.757 5474 5474 I AODBatteryManager: updateBatteryData: ACTION_BATTERY_CHANGED 01-10 22:27:29.774 5474 5474 I AODBatteryManager: saveBatteryData : AOD BatteryData [mBatteryLevel=74, mBatteryStatus=CHARGING, mBatteryPlugType=USB, mBatteryPlugged=true, mRemainingChargeTime=56126000, mBatteryChargingType=1, mBatteryChargerType=NORMAL, mBatteryOnline=NOT_DEFINED, mBatterySwellingMode=NONE, mBatteryProtectMode=false] 01-10 22:27:29.783 5474 5474 D KeyguardUpdateMonitor: handleBatteryUpdate 01-10 22:27:29.799 6170 6170 D BoundBrokerSvc: onUnbind: Intent { act=com.google.android.gms.scheduler.ACTION_PROXY_SCHEDULE cmp=com.google.android.gms/.chimera.PersistentInternalBoundBrokerService } 01-10 22:27:30.129 4416 4416 D io_stats: !@ 8,0 r 559707 14759420 w 84821 2568832 d 54025 15319588 f 47621 57238 iot 177876 149387 th 102400 0 0 pt 0 inp 0 0 9977.762 01-10 22:27:30.878 5133 5223 D SensorService: [SO] 9.752 0.237 0.757 01-10 22:27:31.354 5133 7355 I EDMNativeHelperService: isCameraEnabled 01-10 22:27:31.355 5133 7355 D EDMNativeHelper: isCameraEnabled 01-10 22:27:31.356 5133 7355 D EDMNativeHelper: checking for camera in EnterpriseDeviceManagerService 01-10 22:27:31.356 5133 7355 D EnterpriseDeviceManagerService: isCameraEnabledNative 01-10 22:27:31.356 5133 7355 D EnterpriseDeviceManagerService: checking for camera in restriction policy 01-10 22:27:31.356 5133 7355 D RestrictionPolicy: isCameraEnabled ret(true) userId(0) cxtInfo.mCallerUid(10364) cxtInfo.mContainerId(0)
|
By LogViewPlus Support - 11 Jan 2022
Thanks for the update Morty.
I appreciate the help you left for others - nice one! I have applied some additional formatting to make that more clear.
The sample log entries are also really helpful. Unfortunately, I am still not happy with how this file is being parsed as some log entries are not being parsed correctly with the pattern I provided above. I can see that the logger column is sometimes missing and log entries are being joined together:
These files have a very strange format. Sometimes a minimum length is used and sometimes it is not. Format modifiers should probably not be used here because the format does not actually follow any minimum / maximum character rules.
LogViewPlus does not have a good solution for this at the moment. I think what is needed is the ability to say that this field is required. The problem with the empty spaces is that LogViewPlus thinks the field is missing. If I have " %s " and the log entry contains just two spaces at this position, then the field I am looking for is missing. In these logcat files, the field is not missing and we need to keep reading.
So I think we need the ability to tell the parser that this field will never be missing. Just keep reading until you find it. Maybe * would be a good way to indicate this? Something like:
%d %*t %*s{Column1} %p %c: %m%n It is not very pretty, but this is a real edge case. I have never seen it before. I will need to have a think about it and get back to you.
Thanks,
Toby
|
By LogViewPlus Support - 21 Jan 2022
Hi Morty,
Apologies for the delay in getting back to you.
I investigated the solution a bit further. LogViewPlus can parse this file with:
%d{MM-dd %H:mm:ss.fff} %3s{PID} %3s{TID} %p %c: %m%n
In this scenario, we are using format modifiers in an unusual way. We are using them to skip forward and ignore the variable spacing. This is a much cleaner solution than the development work proposed above. It is also backwards compatible with earlier versions of LogViewPlus.
We have also released LogViewPlus v2.5.53 as a BETA release. The new release will treat the 'E' priority level as an error.
Hope that helps,
Toby
|
|