Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Logging using STDERR of progress bar? #73

Open
Emporea opened this issue Apr 17, 2024 · 3 comments
Open

Logging using STDERR of progress bar? #73

Emporea opened this issue Apr 17, 2024 · 3 comments
Assignees
Labels
need more info question Further information is requested

Comments

@Emporea
Copy link

Emporea commented Apr 17, 2024

temp_log="$(mktemp /tmp/xbackup.XXXXXX)"
exec 2>>"$temp_log"

docker exec nextclouddb /bin/bash -c "mysql2sqlite -V -f /var/lib/mysql/backub.db  -d mariadb -u user --mysql-password 12345
docker exec freshrssdb  /bin/bash -c "mysql2sqlite -V -f /var/lib/mysql/backub.db  -d mariadb -u user --mysql-password 12345
...

I have this bash script. It logs any errors to a file. Executing this file reports an error.
At the end of this script the database got successfully exported, but the error file isn't empty.

Content of log file:

  0%|          | 0/1 [00:00<?, ?it/s]
100%|██████████| 1/1 [00:00<00:00, 777.15it/s]

  0%|          | 0/14 [00:00<?, ?it/s]
  7%|▋         | 1/14 [00:05<01:05,  5.07s/it]
 14%|█▍        | 2/14 [00:10<01:00,  5.03s/it]
 21%|██▏       | 3/14 [00:15<00:55,  5.02s/it]
 29%|██▊       | 4/14 [00:20<00:50,  5.06s/it]
 36%|███▌      | 5/14 [00:25<00:45,  5.09s/it]
 43%|████▎     | 6/14 [00:30<00:40,  5.11s/it]
 50%|█████     | 7/14 [00:35<00:35,  5.12s/it]
 57%|█████▋    | 8/14 [00:40<00:30,  5.12s/it]
 64%|██████▍   | 9/14 [00:46<00:25,  5.18s/it]
 71%|███████▏  | 10/14 [00:51<00:20,  5.16s/it]
 79%|███████▊  | 11/14 [00:56<00:15,  5.14s/it]
 86%|████████▌ | 12/14 [01:01<00:10,  5.14s/it]
 93%|█████████▎| 13/14 [01:06<00:05,  5.12s/it]
100%|██████████| 14/14 [01:08<00:00,  4.07s/it]
100%|██████████| 14/14 [01:08<00:00,  4.87s/it]

  0%|          | 0/1 [00:00<?, ?it/s]
100%|██████████| 1/1 [00:00<00:00, 3454.95it/s]

This is clearly not an error, as its just info.

I looked closely and the first command for a nextcloud db does indeed have this error in console:
2024-04-17 10:40:28 ERROR SQLite transfer failed inserting data into table oc_mediadc_tasks: table oc_mediadc_tasks has no column named name

But this is only logged to the console, it's not caught by bash.
When I run this command with -q, the error is indeed caught by bash and written to the log file.
But this error is more or less just a warning in my case and can be ignored as the sqlite file is still created.

But the expected behaviour here is that all console output marked as ERROR should also have STDERR so that bash can catch it. Also for all errors without using -q, since --quiet should only hide all non-errors, not make errors more prominent.


The second thing is that these progress lines are written to the error file without using -q. This is clearly not the intended behaviour.

At first I thought there might be something wrong with the way I catch errors, and it caught this oc_mediadc_tasks error, but somehow it was outputting the progress bar instead.

But then I looked closely at just the second command for a freshrss db.
Running it did not produce any errors, neither with --debug nor with -q.
But the error log still shows the progress bar as a logged error.

I have tried to look for the logger lines in the src to see if these progress bar outputs use stderr instead of stdout, but have not been able to find anything. So maybe you can help and tell me what is going on as there are several things that needs to be addressed. @techouse

Happy to help with further logs and debugging.

Some more basic info.
host debian
Installed mysql-to-sqlite3 in those docker containers via pip. version 2.1.11
Mariadb 10.6

@Emporea Emporea added the bug Something isn't working label Apr 17, 2024
@techouse
Copy link
Owner

techouse commented Apr 17, 2024

Hey,

The package uses tqdm to output these bars

https://github.com/techouse/mysql-to-sqlite3/blob/ece8c8b4f918dfce3e723f7feaef5c1bdf30f89f/src/mysql_to_sqlite3/transporter.py#L589C36-L589C40

Could maybe this be related? tqdm/tqdm#744

Extracted from the tqdm readme

Perhaps the most wonderful use of tqdm is in a script or on the command line. Simply inserting tqdm (or python -m tqdm) between pipes will pass through all stdin to stdout while printing progress to stderr.

@Emporea
Copy link
Author

Emporea commented Apr 17, 2024

Thanks for the fast reply.
Yeah seems like this could be the case with tqdm. 3 years since last activity. hm.

What about the fact that it only pipes actual errors to the file when using -q?

@techouse
Copy link
Owner

techouse commented Apr 17, 2024

What about the fact that it only pipes actual errors to the file when using -q?

It's not set up that way

The logger will dump anything to a file if provided.

You only want it to log errors?

@techouse techouse added question Further information is requested need more info and removed bug Something isn't working labels Apr 18, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
need more info question Further information is requested
Projects
None yet
Development

No branches or pull requests

2 participants