techouse / mysql-to-sqlite3

Transfer data from MySQL to SQLite
https://techouse.github.io/mysql-to-sqlite3/
MIT License
211 stars 32 forks source link

Logging using STDERR of progress bar? #73

Open Emporea opened 5 months ago

Emporea commented 5 months ago
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

techouse commented 5 months ago

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? https://github.com/tqdm/tqdm/issues/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 commented 5 months ago

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 commented 5 months ago

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

It's not set up that way https://github.com/techouse/mysql-to-sqlite3/blob/ece8c8b4f918dfce3e723f7feaef5c1bdf30f89f/src/mysql_to_sqlite3/transporter.py#L154

The logger will dump anything to a file if provided.

You only want it to log errors?