Django showing all migrations as unaplied
wandss opened this issue · 23 comments
-
Operating System Name: Client is running on a RedHat UBI but same issue happened on a Debian based image.
-
db2level output from clidriver if in use:
-
Target Db2 Server Version: Issue happened on 11.5.8 and 11.5.9
-
Python Version: 3.11.10
-
ibm_db version: 3.2.4
-
For non-Windows, output of below commands:
uname: Linux
uname -m: x86_64 -
Value of below environment variables if set:
IBM_DB_HOME: /database/config/aolpatch/sqllib
PATH: /database/config/aolpatch/.local/bin:/database/config/aolpatch/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/database/config/aolpatch/sqllib/bin:/database/config/aolpatch/sqllib/adm:/database
/config/aolpatch/sqllib/misc:/database/config/aolpatch/sqllib/pd:/database/config/aolpatch/sqllib/gskit/bin:/database/config/aolpatch/sqllib/db2tss/bin
LIB/LD_LIBRARY_PATH/DYLD_LIBRARY_PATH: /database/config/aolpatch/sqllib/lib64:/database/config/aolpatch/sqllib/lib64/gskit:/database/config/aolpatch/sqllib/lib32 -
ibm_db_django: 1.5.3
Steps to Reproduce:
- From a django application run manage.py showmigrations all applied migrations in the database will be shown as unaplied.
- Changing the ibm_db to version 3.2.3 and issue the same command will show migrations are applied.
Output using driver version 3.2.3
admin
[X] 0001_initial
[X] 0002_logentry_remove_auto_add
[X] 0003_logentry_add_action_flag_choices
auth
[X] 0001_initial
[X] 0002_alter_permission_name_max_length
[X] 0003_alter_user_email_max_length
[X] 0004_alter_user_username_opts
[X] 0005_alter_user_last_login_null
[X] 0006_require_contenttypes_0002
[X] 0007_alter_validators_add_error_messages
[X] 0008_alter_user_username_max_length
[X] 0009_alter_user_last_name_max_length
[X] 0010_alter_group_name_max_length
[X] 0011_update_proxy_permissions
[X] 0012_alter_user_first_name_max_length contenttypes
[X] 0001_initial
[X] 0002_remove_content_type_name sessions
[X] 0001_initial
Output using driver version 3.2.4
admin
[ ] 0001_initial
[ ] 0002_logentry_remove_auto_add
[ ] 0003_logentry_add_action_flag_choices
auth
[ ] 0001_initial
[ ] 0002_alter_permission_name_max_length
[ ] 0003_alter_user_email_max_length
[ ] 0004_alter_user_username_opts
[ ] 0005_alter_user_last_login_null
[ ] 0006_require_contenttypes_0002
[ ] 0007_alter_validators_add_error_messages
[ ] 0008_alter_user_username_max_length
[ ] 0009_alter_user_last_name_max_length
[ ] 0010_alter_group_name_max_length
[ ] 0011_update_proxy_permissions
[ ] 0012_alter_user_first_name_max_length contenttypes
[ ] 0001_initial
[ ] 0002_remove_content_type_name sessions
[ ] 0001_initial
Other observations:
As I said above, feels to me there's some incompatibility between ibm_db and ibm_db_django.
Please let me know if any other information is required,
Missing information in the question.
(1) db2level output from the driver you are using (looks like you are not using the driver that comes with python ibm_db by default)
(2) pip list output (to see exact versions of other modules).
Please add the unedited clear text output of the command:
/database/config/aolpatch/sqllib/bin/db2level
Please confirm the exact same driver version is used with both ibm_db 3.2.3 and 3.2.4, or if using different drivers per version of ibm_db then explain clearly the different versions.
Hello @imavo thanks for the response.
(1) Could you please explain how I could get this info?
(2)
Pip list from Container running ibm_db version 3.2.3
Package Version
------------------------- -----------
asgiref 3.8.1
attrs 24.3.0
boto3 1.24.96
botocore 1.27.96
certifi 2024.12.14
cffi 1.17.1
charset-normalizer 3.4.0
cryptography 44.0.0
Django 4.2.17
django-cors-headers 4.6.0
django-filter 24.3
django-redis 5.2.0
django-storages 1.13.2
djangorestframework 3.15.2
drf-spectacular 0.28.0
drf-spectacular-sidecar 2024.12.1
gunicorn 22.0.0
ibm_db 3.2.3
ibm-db-django 1.5.3.0
idna 3.10
inflection 0.5.1
jmespath 1.0.1
josepy 1.14.0
jsonschema 4.23.0
jsonschema-specifications 2024.10.1
mozilla-django-oidc 3.0.0
packaging 24.2
pip 24.0
pycparser 2.22
pyOpenSSL 24.3.0
python-dateutil 2.9.0.post0
pytz 2024.2
PyYAML 6.0.2
redis 5.2.1
referencing 0.35.1
regex 2024.11.6
requests 2.32.3
rpds-py 0.22.3
s3transfer 0.6.2
setuptools 65.5.1
six 1.17.0
sqlparse 0.5.3
uritemplate 4.1.1
urllib3 1.26.20
wheel 0.45.1
Pip list from Container running ibm_db version 3.2.4
Package Version
------------------------- -----------
asgiref 3.8.1
attrs 24.3.0
boto3 1.24.96
botocore 1.27.96
certifi 2024.12.14
cffi 1.17.1
charset-normalizer 3.4.0
cryptography 44.0.0
Django 4.2.17
django-cors-headers 4.6.0
django-filter 24.3
django-redis 5.2.0
django-storages 1.13.2
djangorestframework 3.15.2
drf-spectacular 0.28.0
drf-spectacular-sidecar 2024.12.1
gunicorn 22.0.0
ibm_db 3.2.4
ibm-db-django 1.5.3.0
idna 3.10
inflection 0.5.1
jmespath 1.0.1
josepy 1.14.0
jsonschema 4.23.0
jsonschema-specifications 2024.10.1
mozilla-django-oidc 3.0.0
packaging 24.2
pip 24.0
pycparser 2.22
pyOpenSSL 24.3.0
python-dateutil 2.9.0.post0
pytz 2024.2
PyYAML 6.0.2
redis 5.2.1
referencing 0.35.1
regex 2024.11.6
requests 2.32.3
rpds-py 0.22.3
s3transfer 0.6.2
setuptools 65.5.1
six 1.17.0
sqlparse 0.5.3
uritemplate 4.1.1
urllib3 1.26.20
wheel 0.45.1 ``
db2level from DB Container:
[aolpatch@95cfeeb2250d /]$ /database/config/aolpatch/sqllib/bin/db2level
DB21085I This instance or install (instance name, where applicable:
"aolpatch") uses "64" bits and DB2 code release "SQL11058" with level
identifier "0609010F".
Informational tokens are "DB2 v11.5.8.0", "s2209201700", "DYN2209201700AMD64",
and Fix Pack "0".
Product is installed at "/opt/ibm/db2/V11.5".
The db2level output appears if you run that command at a command line as long as it is on the $PATH and also the relevant directories are on the $LD_LIBRARY_PATH.
In any event, I have reproduced the symptom on my test environment, so can confirm there appears to be a regression.
A temporary workaround is to replace the file ibm_db_dbi.py with the release 3.2.3 version of that file.
It seems that some change for the 3.2.4 release of ibm_db_dbi.py contributes to this symptom, as reverting to the 3.2.3 version allows python manage.py showmigrations to work correctly.
Hello. @imavo thanks for sharing the workaround. In our case, stick to version 3.2.3 and wait for a final solution will be better because of how we build and deploy our code base. Still it is good to know that, if we get to the point that we need to move to version 3.2.4, there's this workaround.
@imavo For 3.2.4 release, only below commits have updated ibm_db_dbi.py file:
Could you please apply changes of these commits one by one and find which commit caused it? We see changes related to logging messages only in these commits.
Also, if you could repro the issue using some small test program and share, it will help us lot to figure out root cause. Thanks.
To recreate: no special code needed, just use django tooling, this is what I did in a new empty venv
pip install --upgrade pip
pip install ibm_db_django
django-admin startproject proj1
configure the settings.py to point to a pre-existing database and any other documented changes or required changes for ibm_db_django as mentioned in the ibm_db_django readme.
if django has never touched that database previously then run python manage.py migrate to create the necessary metadata and pre-configured migrations that come with the tooling.
to recreate run python manage.py showmigrations
expect to see a list of applied migrations, one per line, with the first column indicating [X] to show this migration is applied.
BUT in the error situation each migration will show with [ ] (i.e. missing the X, falsely suggesting that the migration is not applied.
I will try to find the change that triggers the error.
Note: I previously verified that the underlying database queries return identical resultSets in both the working and the failing case, which led me to suspect that the trouble might not be in ibm_db alone.
Hello @imavo
Thank you for your message.
As, you said that ibm_db_dbi.py code at #954 (adjusted with f"...{size} in one LogMsg() call) triggers the symptom.
for that the issue #978 was created, and already given fix by the commit c5d823d
Can you please review it once that you are talking about this issue only?
I am aware of 978, i wanted to make clear that the 954 code (with a minor adustment) is enough to trigger to symptom. If I use the code at 978 , it also triggers the symptom (without any adjusting), but that would be the same file version in the present release of 3.2.4 i think.
Trying to narrow it down further.
I find that line number 1857 of the #978 version of ibm_db_dbi.py triggers the symptom.
That line is:
message = f"Fetched {len(self._fetch_helper(size))} rows successfully."
If I remove the expression len(self._fetch_helper(size)) then I do not get the symptom.
Can someone else replicate my finding?
@imavo
Thank you so much.
I will update that line, with different logging message.
As it was success case, so we can ignore that logging part also.
Thank you.
@bchoudhary6415 Can you please explain why that expression could trigger the error symptom? The same expression gets used in the return statement from the function.
@imavo Actually, I followed your instructions to reproduce the issue. I set up Django and tried to reproduce the issue, but I am encountering an error where [ ] displays with each migration (i.e., missing the X), falsely suggesting that the migration has not been applied.
I have tried using ibm_db version 3.2.3 as well as 3.2.4.
I’m unable to reproduce the success case at the moment, so I can't provide a definitive explanation.
I did suspect that others might have difficulty recreating my finding
So you recreated the failure case OK.
Can you confirm that you modified the 3.2.4 ibm_db_dbi.py at the line 1857 to remove the expression that I mentioned above in your effort to get a success case?
I'm using python 3.8.10 on ubuntu x64 18.04 , and the portion of my settings.py for installed_apps is shown below.
I need to recreate on a different environment, different os, different python version, different libc version etc.
It would help if @wandss could check if the same line of code is troublesome on his environment.
`INSTALLED_APPS = [
'django.contrib.sites',
'django.contrib.admin',
'django.contrib.auth',
'django.contrib.contenttypes',
'django.contrib.sessions',
'django.contrib.messages',
'django.contrib.staticfiles',
]
SITE_ID = 1
USE_TZ = False
`
I recreated the failure symptom on ubuntu x64 20.04, with python 3.10.12, again creating an empty venv and populating the settings.py as per original environment.
I then edited the ibm_db_dbi.py to comment out lines 1857 and 1858, saved the changed in situ, and then ran the python manage.py showmigrations again, and this time it also worked.
So the workaround appears to be effective on two different environments, different python versions, different libc etc.
Hopefully others can confirm, but I still seek an explanation for why the troublesome expression should trigger the symptom.
I think the root cause is now clear. The fetch_helper() is supposed to be called only one time per fully-consumed result set. If it gets called more than once (after the result-set has already been fully consumed) then subsequent calls return an empty list, and that is what is happening due to the LogMsg at line 1857.
Additionally the fetch_helper has a couple of early returns (that are not exceptions) that do not have a LogMsg to record that the exit is happening. This seems inadequate, because the log file might then mislead , as it is reasonable to expect the logger to record all function entries and all function exits (unless an exception gets thrown). There may be other functions that exhibit this behaviour so would be worthwhile to check and correct.
Sorry for the delayed message @imavo I will try to reproduce and get back here soon as possible with the results.
The code change for fetchmany looks ok.
Consider also adding LogMsg for the early return statements in function _fetch_helper() viz:
def _fetch_helper(self, fetch_size=-1):
"""
This method is a helper function for fetching fetch_size number of
rows, after executing an SQL statement which produces a result set.
It takes the number of rows to fetch as an argument.
If this is not provided it fetches all the remaining rows.
"""
LogMsg(INFO, "entry _fetch_helper()")
if self.stmt_handler is None:
LogMsg(ERROR, "Please execute an SQL statement in order to get a row from result set.")
self.messages.append(
ProgrammingError("Please execute an SQL statement in order to get a row from result set."))
raise self.messages[len(self.messages) - 1]
if not self._result_set_produced:
LogMsg(ERROR, "The last call to execute did not produce any result set.")
self.messages.append(ProgrammingError("The last call to execute did not produce any result set."))
raise self.messages[len(self.messages) - 1]
row_list = []
rows_fetched = 0
while (fetch_size == -1) or \
(fetch_size != -1 and rows_fetched < fetch_size):
try:
row = ibm_db.fetch_tuple(self.stmt_handler)
except Exception as inst:
if ibm_db.stmt_errormsg() is not None:
error_msg = f"Statement error: {str(ibm_db.stmt_errormsg())}"
LogMsg(ERROR, error_msg)
self.messages.append(Error(str(ibm_db.stmt_errormsg())))
else:
LogMsg(ERROR, f"Error occured : {_get_exception(inst)}")
self.messages.append(_get_exception(inst))
if len(row_list) == 0:
raise self.messages[len(self.messages) - 1]
else:
LogMsg(INFO, "exit _fetch_helper()")
return row_list
if row != False:
if self.FIX_RETURN_TYPE == 1:
row_list.append(self._fix_return_data_type(row))
else:
row_list.append(row)
else:
LogMsg(INFO, "exit _fetch_helper()")
return row_list
rows_fetched = rows_fetched + 1
LogMsg(INFO, "exit _fetch_helper()")
return row_list
Looks OK to me
ibm_db=="3.2.5" released with fix of this issue. Hence, closing it. Thanks.