Problem monitoring the output of a stream using subprocess /u/MalygosWizard Python Education

Hi,
I am attempting to create an automated firmware update test for a standalone device running Android 13.
I am communicating with the device from a Linux box using ADB over USB.

My test is broken into 3 sections:
1) Sends the firmware file to the Android device
2) Starts the firmware update process
3) Monitors the firmware update log output to determine its progress, and whether it succeeds or fails.

I’m having a hard time getting “3)” to work.

I am basically attempting to monitor the output from a command like this:

adb -s 0a2b08003755fb0d logcat -b all | grep update_engine 

I am pretty sure I need to use subprocess, but I am most familiar with using subprocess to quickly fire off a program via the shell, and collect its output.
In previous cases, all of my subprocesses blocked until they completed – which was just fine – I just cared about the output when they finished – not during.

With “adb” – I would like to monitor its output as explained above.

I have written some test code based on examples from stackoverflow – such as these:
https://stackoverflow.com/questions/18421757/live-output-from-subprocess-command

I am attempting to modify the last example from the accepted answer to do what I need.
(Using code from the example prefaced with: “Or you can create a reader and a writer file. Pass the writer to the Popen and read from the reader“)

My hacked up version will output properly for about 4-5 minutes – and then start blocking someplace.
It eventually unclogs – and outputs to a point about 6 lines or so from the end of the log output.

At this point it just sits there forever – meanwhile, the success/fail message is never retrieved.

I realize I could simply modify my above adb command to direct all output to a file – and then open the file and read from it – but since the firmware upgrade takes several minutes to run – I was hoping to be able to provide the user with “real time” progress updates.

Here is what I have so far:

import io import time import subprocess import sys command = "adb -s 0a2b08003755fb0d logcat -b all | grep update_engine" filename = "test.log" null_counter = 0 with io.open(filename, "wb") as writer, io.open(filename, "rb") as reader: process = subprocess.Popen(command, shell=True, stdout=writer) while process.poll() is None: something = reader.read().decode("utf-8") if something != "": print(f"something = {something}") null_counter = 0 else: print(".", flush=True, end='') null_counter += 1 time.sleep(0.5) if null_counter == 200: print("null_counter hit 200, trying to read force a read") # Read the remaining sys.stdout.write(reader.read().decode("utf-8")) null_counter = 0 

My changes are primarily debugging oriented as I try to figure out what is stalling.

Some snippets of output:

12-18 11:07:26.004 597 597 I update_engine: [libfs_mgr]Created logical partition system_ext_a-base on device /dev/block/dm-21

12-

.........something = 18 11:07:26.030 597 597 I update_engine: Mapped COW device for system_ext_a at /dev/block/dm-22

12-18 11:07:26.058 597 597 I update_engine: [libfs_mgr]Created logical partition system_ext_a-src on device /dev/block/dm-30

My debug message and periods showing what a typical “stall” looks like.

An example of my trying to force a read failing:

12-18 11:07:43.322 597 597 I update_engine: Successfully unmapped snapshot vendor_a

12-18 11:07:43.327 597 597 I update_engine: Shutdown snapuserd daemon

12-18 11:07:43.331 597 597 I update_engine: [INFO:postinstall_runner_action.cc(4

........................................................................................................................................................................................................null_counter hit 200, trying to read force a read

..............................

And finally, the actual end of the log – as extracted from the device under test itself – showing the part never retrieved by subprocess:

12-18 11:07:43.322 597 597 I update_engine: Successfully unmapped snapshot vendor_a

12-18 11:07:43.327 597 597 I update_engine: Shutdown snapuserd daemon

12-18 11:07:43.331 597 597 I update_engine: [INFO:postinstall_runner_action.cc(454)] Unmapped all partitions.

12-18 11:07:43.335 597 597 I update_engine: [INFO:postinstall_runner_action.cc(470)] All post-install commands succeeded

12-18 11:07:43.339 597 597 I update_engine: [INFO:action_processor.cc(116)] ActionProcessor: finished last action PostinstallRunnerAction with code ErrorCode::kSuccess

12-18 11:07:43.343 597 597 I update_engine: [INFO:update_attempter_android.cc(565)] Processing Done.

12-18 11:07:43.347 597 597 I update_engine: [INFO:update_attempter_android.cc(810)] Writing update complete marker.

12-18 11:07:43.353 597 597 I update_engine: [INFO:update_attempter_android.cc(580)] Update successfully applied, waiting to reboot.

I’ve tried modifying a bunch of examples I have found – and this was the closest I ever came to succeeding.

Any help/advice is appreciated.

submitted by /u/MalygosWizard
[link] [comments]

​r/learnpython Hi, I am attempting to create an automated firmware update test for a standalone device running Android 13. I am communicating with the device from a Linux box using ADB over USB. My test is broken into 3 sections: 1) Sends the firmware file to the Android device 2) Starts the firmware update process 3) Monitors the firmware update log output to determine its progress, and whether it succeeds or fails. I’m having a hard time getting “3)” to work. I am basically attempting to monitor the output from a command like this: adb -s 0a2b08003755fb0d logcat -b all | grep update_engine I am pretty sure I need to use subprocess, but I am most familiar with using subprocess to quickly fire off a program via the shell, and collect its output. In previous cases, all of my subprocesses blocked until they completed – which was just fine – I just cared about the output when they finished – not during. With “adb” – I would like to monitor its output as explained above. I have written some test code based on examples from stackoverflow – such as these: https://stackoverflow.com/questions/18421757/live-output-from-subprocess-command I am attempting to modify the last example from the accepted answer to do what I need. (Using code from the example prefaced with: “Or you can create a reader and a writer file. Pass the writer to the Popen and read from the reader”) My hacked up version will output properly for about 4-5 minutes – and then start blocking someplace. It eventually unclogs – and outputs to a point about 6 lines or so from the end of the log output. At this point it just sits there forever – meanwhile, the success/fail message is never retrieved. I realize I could simply modify my above adb command to direct all output to a file – and then open the file and read from it – but since the firmware upgrade takes several minutes to run – I was hoping to be able to provide the user with “real time” progress updates. Here is what I have so far: import io import time import subprocess import sys command = “adb -s 0a2b08003755fb0d logcat -b all | grep update_engine” filename = “test.log” null_counter = 0 with io.open(filename, “wb”) as writer, io.open(filename, “rb”) as reader: process = subprocess.Popen(command, shell=True, stdout=writer) while process.poll() is None: something = reader.read().decode(“utf-8”) if something != “”: print(f”something = {something}”) null_counter = 0 else: print(“.”, flush=True, end=”) null_counter += 1 time.sleep(0.5) if null_counter == 200: print(“null_counter hit 200, trying to read force a read”) # Read the remaining sys.stdout.write(reader.read().decode(“utf-8”)) null_counter = 0 My changes are primarily debugging oriented as I try to figure out what is stalling. Some snippets of output: 12-18 11:07:26.004 597 597 I update_engine: [libfs_mgr]Created logical partition system_ext_a-base on device /dev/block/dm-21 12- ………something = 18 11:07:26.030 597 597 I update_engine: Mapped COW device for system_ext_a at /dev/block/dm-22 12-18 11:07:26.058 597 597 I update_engine: [libfs_mgr]Created logical partition system_ext_a-src on device /dev/block/dm-30 My debug message and periods showing what a typical “stall” looks like. An example of my trying to force a read failing: 12-18 11:07:43.322 597 597 I update_engine: Successfully unmapped snapshot vendor_a 12-18 11:07:43.327 597 597 I update_engine: Shutdown snapuserd daemon 12-18 11:07:43.331 597 597 I update_engine: [INFO:postinstall_runner_action.cc(4 ………………………………………………………………………………………………………………………………………………………………………………..null_counter hit 200, trying to read force a read ………………………… And finally, the actual end of the log – as extracted from the device under test itself – showing the part never retrieved by subprocess: 12-18 11:07:43.322 597 597 I update_engine: Successfully unmapped snapshot vendor_a 12-18 11:07:43.327 597 597 I update_engine: Shutdown snapuserd daemon 12-18 11:07:43.331 597 597 I update_engine: [INFO:postinstall_runner_action.cc(454)] Unmapped all partitions. 12-18 11:07:43.335 597 597 I update_engine: [INFO:postinstall_runner_action.cc(470)] All post-install commands succeeded 12-18 11:07:43.339 597 597 I update_engine: [INFO:action_processor.cc(116)] ActionProcessor: finished last action PostinstallRunnerAction with code ErrorCode::kSuccess 12-18 11:07:43.343 597 597 I update_engine: [INFO:update_attempter_android.cc(565)] Processing Done. 12-18 11:07:43.347 597 597 I update_engine: [INFO:update_attempter_android.cc(810)] Writing update complete marker. 12-18 11:07:43.353 597 597 I update_engine: [INFO:update_attempter_android.cc(580)] Update successfully applied, waiting to reboot. I’ve tried modifying a bunch of examples I have found – and this was the closest I ever came to succeeding. Any help/advice is appreciated. submitted by /u/MalygosWizard [link] [comments] 

Hi,
I am attempting to create an automated firmware update test for a standalone device running Android 13.
I am communicating with the device from a Linux box using ADB over USB.

My test is broken into 3 sections:
1) Sends the firmware file to the Android device
2) Starts the firmware update process
3) Monitors the firmware update log output to determine its progress, and whether it succeeds or fails.

I’m having a hard time getting “3)” to work.

I am basically attempting to monitor the output from a command like this:

adb -s 0a2b08003755fb0d logcat -b all | grep update_engine 

I am pretty sure I need to use subprocess, but I am most familiar with using subprocess to quickly fire off a program via the shell, and collect its output.
In previous cases, all of my subprocesses blocked until they completed – which was just fine – I just cared about the output when they finished – not during.

With “adb” – I would like to monitor its output as explained above.

I have written some test code based on examples from stackoverflow – such as these:
https://stackoverflow.com/questions/18421757/live-output-from-subprocess-command

I am attempting to modify the last example from the accepted answer to do what I need.
(Using code from the example prefaced with: “Or you can create a reader and a writer file. Pass the writer to the Popen and read from the reader“)

My hacked up version will output properly for about 4-5 minutes – and then start blocking someplace.
It eventually unclogs – and outputs to a point about 6 lines or so from the end of the log output.

At this point it just sits there forever – meanwhile, the success/fail message is never retrieved.

I realize I could simply modify my above adb command to direct all output to a file – and then open the file and read from it – but since the firmware upgrade takes several minutes to run – I was hoping to be able to provide the user with “real time” progress updates.

Here is what I have so far:

import io import time import subprocess import sys command = "adb -s 0a2b08003755fb0d logcat -b all | grep update_engine" filename = "test.log" null_counter = 0 with io.open(filename, "wb") as writer, io.open(filename, "rb") as reader: process = subprocess.Popen(command, shell=True, stdout=writer) while process.poll() is None: something = reader.read().decode("utf-8") if something != "": print(f"something = {something}") null_counter = 0 else: print(".", flush=True, end='') null_counter += 1 time.sleep(0.5) if null_counter == 200: print("null_counter hit 200, trying to read force a read") # Read the remaining sys.stdout.write(reader.read().decode("utf-8")) null_counter = 0 

My changes are primarily debugging oriented as I try to figure out what is stalling.

Some snippets of output:

12-18 11:07:26.004 597 597 I update_engine: [libfs_mgr]Created logical partition system_ext_a-base on device /dev/block/dm-21

12-

.........something = 18 11:07:26.030 597 597 I update_engine: Mapped COW device for system_ext_a at /dev/block/dm-22

12-18 11:07:26.058 597 597 I update_engine: [libfs_mgr]Created logical partition system_ext_a-src on device /dev/block/dm-30

My debug message and periods showing what a typical “stall” looks like.

An example of my trying to force a read failing:

12-18 11:07:43.322 597 597 I update_engine: Successfully unmapped snapshot vendor_a

12-18 11:07:43.327 597 597 I update_engine: Shutdown snapuserd daemon

12-18 11:07:43.331 597 597 I update_engine: [INFO:postinstall_runner_action.cc(4

........................................................................................................................................................................................................null_counter hit 200, trying to read force a read

..............................

And finally, the actual end of the log – as extracted from the device under test itself – showing the part never retrieved by subprocess:

12-18 11:07:43.322 597 597 I update_engine: Successfully unmapped snapshot vendor_a

12-18 11:07:43.327 597 597 I update_engine: Shutdown snapuserd daemon

12-18 11:07:43.331 597 597 I update_engine: [INFO:postinstall_runner_action.cc(454)] Unmapped all partitions.

12-18 11:07:43.335 597 597 I update_engine: [INFO:postinstall_runner_action.cc(470)] All post-install commands succeeded

12-18 11:07:43.339 597 597 I update_engine: [INFO:action_processor.cc(116)] ActionProcessor: finished last action PostinstallRunnerAction with code ErrorCode::kSuccess

12-18 11:07:43.343 597 597 I update_engine: [INFO:update_attempter_android.cc(565)] Processing Done.

12-18 11:07:43.347 597 597 I update_engine: [INFO:update_attempter_android.cc(810)] Writing update complete marker.

12-18 11:07:43.353 597 597 I update_engine: [INFO:update_attempter_android.cc(580)] Update successfully applied, waiting to reboot.

I’ve tried modifying a bunch of examples I have found – and this was the closest I ever came to succeeding.

Any help/advice is appreciated.

submitted by /u/MalygosWizard
[link] [comments] 

Leave a Reply

Your email address will not be published. Required fields are marked *