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

Sync: Desktop -> Android: All text after the first NUL character is lost #9909

Open
personalizedrefrigerator opened this issue Feb 8, 2024 · 2 comments
Labels
android bug It's a bug medium Medium priority issues upstream There's a problem with upstream code.

Comments

@personalizedrefrigerator
Copy link
Collaborator

personalizedrefrigerator commented Feb 8, 2024

Operating system

Android

Joplin version

2.14.5

Desktop version info

Joplin 2.14.12 (dev, linux)

Client ID: d8b09c022f7e47aab5531063457d116c
Sync Version: 3
Profile Version: 45
Keychain Supported: No

Revision: caf806f (pr/disable-simple-backup-by-default-in-portable)

Simple Backup: 1.3.5

Current behaviour

  1. Set up sync between Joplin Android and Joplin Desktop (I used Joplin Server, but have also experienced this issue with NextCloud sync)
  2. Create a new note from the following JEX file: NUL_test.jex.gz
  3. Sync

Currently, only the text before the first NUL character shows up on the Android device.

If I then sync with another desktop client, the full note shows up.

Expected behaviour

The full note should sync on Android.

Logs

Adding log statements suggests that the issue is happening **after** data is fetched from the server

diff:

diff --git a/packages/lib/JoplinServerApi.ts b/packages/lib/JoplinServerApi.ts
index 5bf29e310..e6bbf4ccf 100644
--- a/packages/lib/JoplinServerApi.ts
+++ b/packages/lib/JoplinServerApi.ts
@@ -193,6 +193,7 @@ export default class JoplinServerApi {
 			}
 
 			const responseText = await response.text();
+			logger.debug('got text', responseText)
 
 			if (this.debugRequests_) {
 				logger.debug('Response', Date.now() - startTime, options.responseFormat, responseText);

Relevant log output:

4:23:28: JoplinServerApi: got text {"items":[{"id":"idhere","item_id":"idhere","item_name":"b19aa70cacec4506b17d91f6bfb855b8.md","type":2,"updated_time":1707506600014,"jop_updated_time":1707506598438,"jopItem":{"user_data":"","master_key_id":"","conflict_original_id":"","is_shared":0,"markup_language":1,"encryption_cipher_text":"","user_updated_time":1707506598438,"user_created_time":1707429220069,"order":0,"application_data":"","source_application":"net.cozic.joplindev-desktop","source":"joplindev-desktop","todo_completed":0,"todo_due":0,"is_todo":0,"source_url":"","author":"","altitude":"0.0000","longitude":"0.123","latitude":"0.456","is_conflict":0,"created_time":1707429220069,"title":"NUL test","body":"This is a test...\n\nNUL: \u0000 After the NUL character.\n\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\n\u0000\u0000\u0000\u0000\u0000\u0000\n\u0000\u0000\u0000\u0000\u0000\u0000\n\u0000\u0000\u0000\u0000\u0000\u0000\n\u0000\u0000\u0000\u0000\u0000\u0000\n\u0000\u0000\u0000\u0000\u0000\u0000\n\u0000\u0000\u0000\u0000\u0000\u0000\n\u0000\u0000\u0000\u0000\u0000\u0000\nAlso after the NUL characters.\n\nfile:///home/builder/test.txt\n\n","id":"b19aa70cacec4506b17d91f6bfb855b8","parent_id":"344352dba573486ba6910459713a5aff","share_id":"","type_":1,"encryption_applied":0,"updated_time":1707506598438}}],"cursor":"cursorhere","has_more":false}
@personalizedrefrigerator personalizedrefrigerator added bug It's a bug android medium Medium priority issues labels Feb 8, 2024
@personalizedrefrigerator
Copy link
Collaborator Author

personalizedrefrigerator commented Feb 10, 2024

With the following diff applied,

diff
diff --git a/packages/lib/JoplinServerApi.ts b/packages/lib/JoplinServerApi.ts
index 5bf29e310..f70b66837 100644
--- a/packages/lib/JoplinServerApi.ts
+++ b/packages/lib/JoplinServerApi.ts
@@ -193,6 +193,7 @@ export default class JoplinServerApi {
 			}
 
 			const responseText = await response.text();
+			logger.debug('got text', responseText)
 
 			if (this.debugRequests_) {
 				logger.debug('Response', Date.now() - startTime, options.responseFormat, responseText);
@@ -216,6 +217,7 @@ export default class JoplinServerApi {
 				if (responseJson_) return responseJson_;
 				responseJson_ = JSON.parse(responseText);
 				if (!responseJson_) throw newError('Cannot parse JSON response', response.status);
+				logger.debug('got response JSON', JSON.stringify(responseJson_));
 				return responseJson_;
 			};
 
diff --git a/packages/lib/Synchronizer.ts b/packages/lib/Synchronizer.ts
index c8701c7a3..c0cbee974 100644
--- a/packages/lib/Synchronizer.ts
+++ b/packages/lib/Synchronizer.ts
@@ -937,6 +937,7 @@ export default class Synchronizer {
 								logger.warn(`Remote has been deleted between now and the delta() call? In that case it will be handled during the next sync: ${path}`);
 								continue;
 							}
+							logger.debug('UpdateLocal:', content);
 							content = ItemClass.filter(content);
 
 							// 2017-12-03: This was added because the new user_updated_time and user_created_time properties were added
@@ -984,6 +985,7 @@ export default class Synchronizer {
 									await MasterKey.save(content);
 								}
 							} else {
+								logger.debug('Saving...', ItemClass.name, '...', ItemClass);
 								await ItemClass.save(content, options);
 							}
 
diff --git a/packages/lib/models/Note.ts b/packages/lib/models/Note.ts
index 6c1416be1..c3b099a1d 100644
--- a/packages/lib/models/Note.ts
+++ b/packages/lib/models/Note.ts
@@ -717,6 +717,7 @@ export default class Note extends BaseItem {
 		const oldNote = !isNew && o.id ? await Note.load(o.id) : null;
 
 		syncDebugLog.info('Save Note: P:', oldNote);
+		this.logger().debug('Save note', { isNew, isProvisional }, o);
 
 		let beforeNoteJson = null;
 		if (oldNote && this.revisionService().isOldNote(o.id)) {
@@ -737,6 +738,7 @@ export default class Note extends BaseItem {
 		syncDebugLog.info('Save Note: N:', o);
 
 		const note = await super.save(o, options);
+		syncDebugLog.info('Saved content:', await Note.load(o.id));
 
 		void ItemChange.add(BaseModel.TYPE_NOTE, note.id, isNew ? ItemChange.TYPE_CREATE : ItemChange.TYPE_UPDATE, changeSource, beforeNoteJson);
 
diff --git a/packages/lib/services/synchronizer/syncDebugLog.ts b/packages/lib/services/synchronizer/syncDebugLog.ts
index 1d2c12312..ad37a1565 100644
--- a/packages/lib/services/synchronizer/syncDebugLog.ts
+++ b/packages/lib/services/synchronizer/syncDebugLog.ts
@@ -4,6 +4,6 @@
 
 import Logger from '@joplin/utils/Logger';
 
-const syncDebugLog = new Logger();
+const syncDebugLog = Logger.create('SyncDebugLog');//new Logger();
 
 export default syncDebugLog;

Note: For easier debugging, I disabled note history. The issue also happens with note history enabled.

I'm getting the following logs:

 INFO  19:03:52: SyncDebugLog: Save Note: N:: {"altitude": "0.0000", "application_data": "", "author": "", "body": "This is a test...

NUL:  After the NUL character.








Also after the NUL characters.
.......

````
  
````", "conflict_original_id": "", "created_time": 1707429220069, "encryption_applied": 0, "encryption_cipher_text": "", "id": "b19aa70cacec4506b17d91f6bfb855b8", "is_conflict": 0, "is_shared": 0, "is_todo": 0, "latitude": "123.00000000", "longitude": "456.00000000", "markup_language": 1, "master_key_id": "", "order": 0, "parent_id": "344352dba573486ba6910459713a5aff", "share_id": "", "source": "joplindev-desktop", "source_application": "net.cozic.joplindev-desktop", "source_url": "", "title": "NUL test", "todo_completed": 0, "todo_due": 0, "type_": 1, "updated_time": 1707523427342, "user_created_time": 1707429180000, "user_data": "", "user_updated_time": 1707523427342}



 INFO  19:03:52: SyncDebugLog: Saved content: {"altitude": "0.0000", "application_data": "", "author": "", "body": "This is a test...

NUL: ", "conflict_original_id": "", "created_time": 1707429220069, "encryption_applied": 0, "encryption_cipher_text": "", "id": "b19aa70cacec4506b17d91f6bfb855b8", "is_conflict": 0, "is_shared": 0, "is_todo": 0, "latitude": "123.00000000", "longitude": "456.00000000", "markup_language": 1, "master_key_id": "", "order": 0, "parent_id": "344352dba573486ba6910459713a5aff", "share_id": "", "source": "joplindev-desktop", "source_application": "net.cozic.joplindev-desktop", "source_url": "", "title": "NUL test", "todo_completed": 0, "todo_due": 0, "type_": 1, "updated_time": 1707523427342, "user_created_time": 1707429180000, "user_data": "", "user_updated_time": 1707523427342}

Notice that the Saved content log doesn't include the NUL characters, but the Save Note: N: log does.

The two most relevant log statements are included in Note.ts like this:

 		syncDebugLog.info('Save Note: N:', o);
 
 		const note = await super.save(o, options);
+		syncDebugLog.info('Saved content:', await Note.load(o.id));

Thus, BaseItem.save is truncating text at the first NUL character on mobile, but not on desktop.

@personalizedrefrigerator
Copy link
Collaborator Author

personalizedrefrigerator commented Feb 10, 2024

This seems to be related to andpor/react-native-sqlite-storage#107. Unfortunately, react-native-sqlite-storage seems to be unmaintained.

According to the linked issue, this SQLite library should have a fix, but it also seems to be unmaintained.

Edit: Note that the upstream issue suggests this is an Android-only issue.

@personalizedrefrigerator personalizedrefrigerator added the upstream There's a problem with upstream code. label Feb 10, 2024
@personalizedrefrigerator personalizedrefrigerator removed their assignment Feb 10, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
android bug It's a bug medium Medium priority issues upstream There's a problem with upstream code.
Projects
None yet
Development

No branches or pull requests

1 participant