LogViewPlus Support » LogViewPlus Support » Help & Support » How to parsing logcat file

RE: How to parsing logcat file

LogViewPlus Support — Fri, 21 Jan 2022 16:48:01 GMT

Hi Morty,

Apologies for the delay in getting back to you.

I investigated the solution a bit further. LogViewPlus can parse this file with:
[code]%d{MM-dd %H:mm:ss.fff} %3s{PID} %3s{TID} %p %c: %m%n[/code]

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

How to parsing logcat file

Alex — Fri, 21 Jan 2022 16:46:05 GMT

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!

RE: How to parsing logcat file

LogViewPlus Support — Tue, 11 Jan 2022 08:17:26 GMT

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:
[code]%d %*t %*s{Column1} %p %c: %m%n[/code]
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

RE: How to parsing logcat file

morty — Tue, 11 Jan 2022 07:30:39 GMT

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:
[code]adb logcat all > yourfile.txt[/code]
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::[code]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)
[/code]

RE: How to parsing logcat file

LogViewPlus Support — Mon, 10 Jan 2022 07:00:58 GMT

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:
[code]%d %5t %5s{Column1} %p %m%n[/code]

It looks like you could even add the logger with:
[code]%d %5t %5s{Column1} %p %c: %m%n[/code]

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

RE: How to parsing logcat file

morty — Sun, 09 Jan 2022 19:31:19 GMT

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

RE: How to parsing logcat file

LogViewPlus Support — Sat, 22 Aug 2020 10:12:36 GMT

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

RE: How to parsing logcat file

Alex — Sat, 22 Aug 2020 04:14:41 GMT

Hi Toby,

Thanks for your checking and answer, finally I wrote one parser dll and resolved this problem

Have a nice day.

BR
Alex

RE: How to parsing logcat file

LogViewPlus Support — Sat, 15 Aug 2020 05:34:01 GMT

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