Fails on set library

gbm · 09-30-2016, 02:36 PM

CC fails on SET_LIBRARY_INFO when using my fixed, wired IP address that is out side of dhcp, when using wireless it works.

System using Linux Mint 18 to LG 16c phone Android 4.4.2, cc 5.1.5.3.

This worked until updated cc this week.

calibre debug log.

Spoiler:

Code:

Wired using fixed ip address.

calibre-debug -g
calibre 2.69  embedded-python: True is64bit: True
Linux-4.4.0-21-generic-x86_64-with-debian-stretch-sid Linux ('64bit', 'ELF')
('Linux', '4.4.0-21-generic', '#37-Ubuntu SMP Mon Apr 18 18:33:37 UTC 2016')
Python 2.7.9
Linux: ('debian', 'stretch/sid', '')
Successfully initialized third party plugins: DeDRM (6, 3, 6) && Generate Cover (1, 5, 21) && Quality Check (1, 9, 11) && EpubSplit (2, 1, 2) && Modify ePub (1, 3, 13) && Diaps Editing Toolbag (0, 3, 2) && KindleUnpack - The Plugin (0, 81, 2) && Barnes & Noble (1, 2, 14) && Goodreads (1, 1, 11) && Baen (0, 0, 3) && Hyphenate This! (0, 0, 8)
devicePixelRatio: 1.0
logicalDpi: 96.0 x 96.0
physicalDpi: 95.9867403315 x 53.947835105
Starting up...
libpng warning: iCCP: known incorrect sRGB profile
Failed to create system tray icon, your desktop environment probably does not support the StatusNotifier spec
DEBUG:    0.0 get_baen_id: match_group= None
Started up in 5.49 seconds with 3038 books
SMART_DEV (   0.00:  0.002) _attach_to_port try ip address "" on port 9090
SMART_DEV (   1.02:  0.807) startup_on_demand listening on port 9090
SMART_DEV (   1.14:  0.001) _attach_to_port try ip address "" on port 54982
SMART_DEV (   1.22:  0.000) startup_on_demand broadcast socket listening on port 54982
SMART_DEV (   2.30:  1.003) run All IP addresses {'lo': [{'addr': '127.0.0.1', 'netmask': '255.0.0.0', 'peer': '127.0.0.1'}], 'eth1': [{'addr': '192.168.1.9', 'netmask': '255.255.255.0', 'broadcast': '192.168.1.255'}]}
SMART_DEV (  29.35: 27.029) run received broadcast ('localhost', ('192.168.1.123', 54982)) calibre wireless device client (on xxxxxxx-SDA);8090,9090
SMART_DEV (  33.37:  4.005) run attempt to open device socket
SMART_DEV (  33.40:  0.001) open
SMART_DEV (  33.43:  0.001) _call_client GET_INITIALIZATION_INFO wfr True
SMART_DEV (  33.55:  0.056) open Device can stream books True
SMART_DEV (  33.58:  0.000) open Device can stream metadata True
SMART_DEV (  33.62:  0.000) open Device can receive book binary True
SMART_DEV (  33.66:  0.000) open Device can delete multiple books True
SMART_DEV (  33.69:  0.000) open Device can use cached metadata True
SMART_DEV (  33.72:  0.000) open Cache uses lpaths True
SMART_DEV (  33.81:  0.000) open Can send OK to sendbook True
SMART_DEV (  33.85:  0.000) open Can accept library info True
SMART_DEV (  33.88:  0.000) open Will ask for update books False
SMART_DEV (  33.92:  0.000) open Will set temp mark when syncing read False
SMART_DEV (  33.96:  0.001) open Client device kind LGL16C
SMART_DEV (  34.00:  0.000) open Client device name LGL16C
SMART_DEV (  34.04:  0.000) open Client app name CalibreCompanion
SMART_DEV (  34.09:  0.000) open App version #: 340
SMART_DEV (  34.13:  0.000) open max_book_packet_len 4096
SMART_DEV (  34.17:  0.000) open Device wants UUID file names False
SMART_DEV (  34.22:  0.002) open selected formats [u'epub']
SMART_DEV (  34.26:  0.000) open extension path lengths {u'epub': 74}
SMART_DEV (  34.31:  0.000) open cover height 240
SMART_DEV (  34.34:  0.000) open Device is_read sync col None
SMART_DEV (  34.38:  0.000) open Device is_read_date sync col None
SMART_DEV (  34.46:  0.001) card_prefix
SMART_DEV (  34.54:  0.015) set_progress_reporter
Job: 1 Get device information started
SMART_DEV (  34.60:  0.009) get_device_information
SMART_DEV (  34.66:  0.001) _call_client GET_DEVICE_INFORMATION wfr True
SMART_DEV (  34.87:  0.138) _call_client SET_CALIBRE_DEVICE_INFO wfr True
SMART_DEV (  35.17:  0.230) _read_metadata_cache device uuid f4636fb7-ff88-4b89-b8ae-32a4e5347319
SMART_DEV (  37.45:  2.208) _read_metadata_cache loaded 1259 cache items
SMART_DEV (  37.51:  0.000) card_prefix
SMART_DEV (  37.57:  0.000) free_space
SMART_DEV (  37.62:  0.001) _call_client FREE_SPACE wfr True
DeviceJob: 1 Get device information done, calling callback
DeviceJob: 1 Get device information callback returned
SMART_DEV (  37.72:  0.025) set_progress_reporter
Job: 2 Set library information started
SMART_DEV (  37.79:  0.007) set_library_info Calibre Library cb6f22fc-dca1-4bd5-99c9-5a441c91b638
SMART_DEV (  37.96:  0.001) _call_client SET_LIBRARY_INFO wfr True
Job: 1 Get device information finished
No details available.
SMART_DEV ( 338.22:300.092) _write_metadata_cache
SMART_DEV ( 341.44:  3.089) _write_metadata_cache wrote 1259 entries, purged 0 entries
SMART_DEV ( 341.67:  0.038) _receive_from_client timeout communicating with device
SMART_DEV ( 341.85:  0.005) _call_client other exception
Traceback (most recent call last):
  File "site-packages/calibre/devices/smart_device_app/driver.py", line 613, in _call_client
  File "site-packages/calibre/devices/smart_device_app/driver.py", line 645, in _receive_from_client
TimeoutError: There was a timeout while communicating with the device in function: Device did not respond in reasonable time
DeviceJob: 2 Set library information done, calling callback
DeviceJob: 2 Set library information callback returned
SMART_DEV ( 342.00:  0.002) set_progress_reporter
Job: 3 Get list of books on device started
SMART_DEV ( 342.07:  0.000) books None
Job: 2 Set library information finished
There was a timeout while communicating with the device in function: Device did not respond in reasonable time
	
	Traceback (most recent call last):
	  File "site-packages/calibre/gui2/device.py", line 87, in run
	  File "site-packages/calibre/gui2/device.py", line 480, in _set_library_information
	  File "site-packages/calibre/devices/smart_device_app/driver.py", line 50, in _synchronizer
	  File "site-packages/calibre/devices/smart_device_app/driver.py", line 1578, in set_library_info
	  File "site-packages/calibre/devices/smart_device_app/driver.py", line 50, in _synchronizer
	  File "site-packages/calibre/devices/smart_device_app/driver.py", line 613, in _call_client
	  File "site-packages/calibre/devices/smart_device_app/driver.py", line 645, in _receive_from_client
	TimeoutError: There was a timeout while communicating with the device in function: Device did not respond in reasonable time

SMART_DEV ( 342.15:  0.002) _call_client GET_BOOK_COUNT wfr True
SMART_DEV ( 342.26:  0.000) books finished getting book metadata
SMART_DEV ( 342.35:  0.000) books carda
SMART_DEV ( 342.43:  0.000) books cardb
DeviceJob: 3 Get list of books on device done, calling callback
DeviceJob: metadata_downloaded: Starting set_books_in_library
DeviceJob: set_books_in_library: books to process= 0
SMART_DEV ( 343.23:  0.689) set_plugboards
DeviceJob: set_books_in_library finished: time= 0.0882170200348
DeviceJob: metadata_downloaded: updating views
DeviceJob: metadata_downloaded: syncing
DeviceJob: metadata_downloaded: refreshing ondevice
DEBUG:  355.6 get_baen_id: match_group= None
DeviceJob: metadata_downloaded: sending metadata_available signal
DeviceJob: 3 Get list of books on device callback returned
SMART_DEV ( 343.48:  0.166) set_progress_reporter
Job: 4 Send metadata to device started
Job: 3 Get list of books on device finished
No details available.
SMART_DEV ( 343.56:  0.001) sync_booklists collection attributes [u'']
DEBUG:  355.8 Starting get_collections: on_connect
DEBUG:  355.8 Renaming rules: {}
DEBUG:  355.8 Formatting template: {value}{category:| (|)}
DEBUG:  355.8 Sorting rules: []
SMART_DEV ( 343.68:  0.002) _call_client SEND_BOOKLISTS wfr False
SMART_DEV ( 343.80:  0.000) _write_metadata_cache
SMART_DEV ( 346.74:  2.848) _write_metadata_cache wrote 1259 entries, purged 0 entries
SMART_DEV ( 346.88:  0.024) card_prefix
SMART_DEV ( 347.00:  0.000) free_space
SMART_DEV ( 347.11:  0.001) _call_client FREE_SPACE wfr True
DeviceJob: 4 Send metadata to device done, calling callback
DeviceJob: 4 Send metadata to device callback returned
SMART_DEV ( 347.23:  0.018) post_yank_cleanup
DEBUG:  359.6 get_baen_id: match_group= None
Job: 4 Send metadata to device finished
No details available.


Wireless using dhcp.


calibre-debug -g
calibre 2.69  embedded-python: True is64bit: True
Linux-4.4.0-21-generic-x86_64-with-debian-stretch-sid Linux ('64bit', 'ELF')
('Linux', '4.4.0-21-generic', '#37-Ubuntu SMP Mon Apr 18 18:33:37 UTC 2016')
Python 2.7.9
Linux: ('debian', 'stretch/sid', '')
Successfully initialized third party plugins: DeDRM (6, 3, 6) && Barnes & Noble (1, 2, 14) && EpubSplit (2, 1, 2) && KindleUnpack - The Plugin (0, 81, 2) && Baen (0, 0, 3) && Goodreads (1, 1, 11) && Modify ePub (1, 3, 13) && Hyphenate This! (0, 0, 8) && Quality Check (1, 9, 11) && Diaps Editing Toolbag (0, 3, 2) && Generate Cover (1, 5, 21)
devicePixelRatio: 1.0
logicalDpi: 96.0 x 96.0
physicalDpi: 95.9867403315 x 53.947835105
Starting up...
libpng warning: iCCP: known incorrect sRGB profile
Failed to create system tray icon, your desktop environment probably does not support the StatusNotifier spec
DEBUG:    0.0 get_baen_id: match_group= None
Started up in 5.56 seconds with 3038 books
SMART_DEV (   0.00:  0.001) _attach_to_port try ip address "" on port 9090
SMART_DEV (   0.99:  0.812) startup_on_demand listening on port 9090
SMART_DEV (   1.07:  0.001) _attach_to_port try ip address "" on port 54982
SMART_DEV (   1.15:  0.000) startup_on_demand broadcast socket listening on port 54982
SMART_DEV (   2.23:  1.002) run All IP addresses {'lo': [{'netmask': '255.0.0.0', 'peer': '127.0.0.1', 'addr': '127.0.0.1'}], 'wlan0': [{'netmask': '255.255.255.0', 'broadcast': '192.168.1.255', 'addr': '192.168.1.103'}]}
SMART_DEV (  22.27: 20.023) run received broadcast ('localhost', ('192.168.1.123', 54982)) calibre wireless device client (on xxxxxxx-SDA);8090,9090
SMART_DEV (  25.30:  3.004) run attempt to open device socket
SMART_DEV (  27.30:  1.978) open
SMART_DEV (  27.34:  0.001) _call_client GET_INITIALIZATION_INFO wfr True
SMART_DEV (  27.54:  0.154) open Device can stream books True
SMART_DEV (  27.58:  0.000) open Device can stream metadata True
SMART_DEV (  27.62:  0.000) open Device can receive book binary True
SMART_DEV (  27.65:  0.000) open Device can delete multiple books True
SMART_DEV (  27.69:  0.000) open Device can use cached metadata True
SMART_DEV (  27.72:  0.000) open Cache uses lpaths True
SMART_DEV (  27.76:  0.000) open Can send OK to sendbook True
SMART_DEV (  27.80:  0.000) open Can accept library info True
SMART_DEV (  27.88:  0.000) open Will ask for update books False
SMART_DEV (  27.93:  0.000) open Will set temp mark when syncing read False
SMART_DEV (  27.97:  0.001) open Client device kind LGL16C
SMART_DEV (  28.01:  0.000) open Client device name LGL16C
SMART_DEV (  28.05:  0.000) open Client app name CalibreCompanion
SMART_DEV (  28.08:  0.000) open App version #: 340
SMART_DEV (  28.12:  0.000) open max_book_packet_len 4096
SMART_DEV (  28.16:  0.000) open Device wants UUID file names False
SMART_DEV (  28.19:  0.001) open selected formats [u'epub']
SMART_DEV (  28.23:  0.000) open extension path lengths {u'epub': 74}
SMART_DEV (  28.27:  0.000) open cover height 240
SMART_DEV (  28.30:  0.000) open Device is_read sync col None
SMART_DEV (  28.34:  0.000) open Device is_read_date sync col None
SMART_DEV (  28.38:  0.001) card_prefix
SMART_DEV (  28.47:  0.016) set_progress_reporter
Job: 1 Get device information started
SMART_DEV (  28.54:  0.000) get_device_information
SMART_DEV (  28.61:  0.001) _call_client GET_DEVICE_INFORMATION wfr True
SMART_DEV (  28.77:  0.077) _call_client SET_CALIBRE_DEVICE_INFO wfr True
SMART_DEV (  28.86:  0.013) _read_metadata_cache device uuid f4636fb7-ff88-4b89-b8ae-32a4e5347319
SMART_DEV (  30.79:  1.851) _read_metadata_cache loaded 1259 cache items
SMART_DEV (  30.85:  0.000) card_prefix
SMART_DEV (  30.92:  0.000) free_space
SMART_DEV (  30.98:  0.001) _call_client FREE_SPACE wfr True
DeviceJob: 1 Get device information done, calling callback
DeviceJob: 1 Get device information callback returned
Job: 1 Get device information finished
No details available.
SMART_DEV (  31.55:  0.508) set_progress_reporter
Job: 2 Set library information started
SMART_DEV (  31.61:  0.000) set_library_info Calibre Library cb6f22fc-dca1-4bd5-99c9-5a441c91b638
SMART_DEV (  31.67:  0.001) _call_client SET_LIBRARY_INFO wfr True
DeviceJob: 2 Set library information done, calling callback
DeviceJob: 2 Set library information callback returned
SMART_DEV (  31.87:  0.140) set_progress_reporter
Job: 3 Get list of books on device started
SMART_DEV (  31.96:  0.000) books None
SMART_DEV (  32.08:  0.001) _call_client GET_BOOK_COUNT wfr True
Job: 2 Set library information finished
No details available.
SMART_DEV (  32.43:  0.128) books caching. count= 1259
SMART_DEV (  35.25:  2.657) books received all books. count= 1259
SMART_DEV (  37.34:  2.026) books processed cache. count= 1259
SMART_DEV (  37.40:  0.001) books removed 0 books from caches
SMART_DEV (  37.48:  0.000) books caching. Need count from device 0
SMART_DEV (  37.62:  0.048) books finished getting book metadata
SMART_DEV (  37.69:  0.002) books carda
SMART_DEV (  37.74:  0.000) books cardb
DeviceJob: 3 Get list of books on device done, calling callback
DeviceJob: metadata_downloaded: Starting set_books_in_library
DeviceJob: set_books_in_library: books to process= 1259
SMART_DEV (  38.59:  0.800) set_plugboards
DeviceJob: set_books_in_library finished: time= 0.291136026382
DeviceJob: metadata_downloaded: updating views
DeviceJob: metadata_downloaded: syncing
DeviceJob: metadata_downloaded: refreshing ondevice
DEBUG:   64.9 get_baen_id: match_group= None
DeviceJob: metadata_downloaded: sending metadata_available signal
DeviceJob: 3 Get list of books on device callback returned
SMART_DEV (  38.89:  0.243) set_progress_reporter
Job: 4 Send metadata to device started
SMART_DEV (  39.01:  0.025) sync_booklists collection attributes [u'']
DEBUG:   65.2 Starting get_collections: on_connect
DEBUG:   65.2 Renaming rules: {}
DEBUG:   65.2 Formatting template: {value}{category:| (|)}
DEBUG:   65.2 Sorting rules: []
SMART_DEV (  39.32:  0.176) _call_client SEND_BOOKLISTS wfr False
SMART_DEV (  39.38:  0.000) _write_metadata_cache
Job: 3 Get list of books on device finished
No details available.
SMART_DEV (  41.73:  2.225) _write_metadata_cache wrote 1259 entries, purged 0 entries
SMART_DEV (  41.81:  0.017) card_prefix
SMART_DEV (  41.89:  0.000) free_space
SMART_DEV (  41.97:  0.003) _call_client FREE_SPACE wfr True
DeviceJob: 4 Send metadata to device done, calling callback
DeviceJob: 4 Send metadata to device callback returned
SMART_DEV (  42.40:  0.359) _call_client NOOP wfr True
Job: 4 Send metadata to device finished
No details available.
SMART_DEV (  44.54:  2.018) _call_client NOOP wfr True
SMART_DEV (  46.71:  2.091) _call_client NOOP wfr True
SMART_DEV (  49.10:  2.346) _call_client NOOP wfr True
SMART_DEV (  51.22:  2.067) _call_client NOOP wfr True
SMART_DEV (  53.48:  2.222) _call_client NOOP wfr True
SMART_DEV (  55.96:  2.427) _call_client NOOP wfr True
SMART_DEV (  56.00:  0.001) _receive_from_client protocol error -- empty json string
SMART_DEV (  56.05:  0.000) _call_client other exception
Traceback (most recent call last):
  File "site-packages/calibre/devices/smart_device_app/driver.py", line 613, in _call_client
  File "site-packages/calibre/devices/smart_device_app/driver.py", line 655, in _receive_from_client
ControlError: Device responded with incorrect information
SMART_DEV (  56.10:  0.000) _write_metadata_cache
SMART_DEV (  57.76:  1.597) _write_metadata_cache wrote 1259 entries, purged 0 entries
SMART_DEV (  57.82:  0.011) post_yank_cleanup
DEBUG:   84.3 get_baen_id: match_group= None

Sent you the cc log from my gmx email, if my brian had been working would have attached the calibre log to the email.

email address in pm.
bernie

chaley · 09-30-2016, 03:07 PM

What the two debug logs show is:

From CC's point of view:

CC thinks calibre went away after the FREE_SPACE command.
CC never received the SET_LIBRARY_INFO command

From calibre's point of view:

Calibre received CC's response to the FREE_SPACE command.
Calibre sent the SET_LIBRARY_INFO command
calibre waited 5 minutes for an answer that never arrived.

This is strange. What it looks like is that some security SW decided that the conversation was "evil" and blocked further packets, in particular the outgoing SET_LIBRARY_INFO command packet. Is this something that could happen on Mint?

gbm · 09-30-2016, 04:39 PM

Quote:

Originally Posted by chaley

What the two debug logs show is:

From CC's point of view:

CC thinks calibre went away after the FREE_SPACE command.
CC never received the SET_LIBRARY_INFO command

From calibre's point of view:

Calibre received CC's response to the FREE_SPACE command.
Calibre sent the SET_LIBRARY_INFO command
calibre waited 5 minutes for an answer that never arrived.

This is strange. What it looks like is that some security SW decided that the conversation was "evil" and blocked further packets, in particular the outgoing SET_LIBRARY_INFO command packet. Is this something that could happen on Mint?

Its funny can not even get the content server when using the set up I have been using for years, but when I turn off the wired connection and use wireless everything works. The only change I can find is that samba updated on Wednesday. I will back that update out sometime this weekend or when I get a to it, and try again.

bernie

chaley · 09-30-2016, 05:37 PM

Also check if there were any changes to the router. It sounds like something is interfering with cabled-to-wifi connections.

gbm · 10-10-2016, 11:05 PM

My station 1 router had to be reset, reflashed and settings restored from backup

bernie

09-30-2016, 03:07 PM	#2
chaley Grand Sorcerer Posts: 12,447 Karma: 8012886 Join Date: Jan 2010 Location: Notts, England Device: Kobo Libra 2	What the two debug logs show is: From CC's point of view: CC thinks calibre went away after the FREE_SPACE command. CC never received the SET_LIBRARY_INFO command From calibre's point of view: Calibre received CC's response to the FREE_SPACE command. Calibre sent the SET_LIBRARY_INFO command calibre waited 5 minutes for an answer that never arrived. This is strange. What it looks like is that some security SW decided that the conversation was "evil" and blocked further packets, in particular the outgoing SET_LIBRARY_INFO command packet. Is this something that could happen on Mint?

Similar Threads
Thread	Thread Starter	Forum	Replies	Last Post
Opening Library fails	htchd2	Calibre	8	04-10-2015 06:27 AM
Library creation on empty drive fails	sasilk	Library Management	3	08-13-2011 01:53 AM
sony reader library fails to load	geoffrichards	Sony Reader	4	05-14-2010 10:53 PM
Sony eBook Library update fails w/Vista	petercreasey	Sony Reader	2	10-06-2009 12:03 PM
Sony eBook Library update fails w/Vista	petercreasey	Sony Reader	1	10-06-2009 12:02 PM

09-30-2016, 05:37 PM	#4
chaley Grand Sorcerer Posts: 12,447 Karma: 8012886 Join Date: Jan 2010 Location: Notts, England Device: Kobo Libra 2	Also check if there were any changes to the router. It sounds like something is interfering with cabled-to-wifi connections.

10-10-2016, 11:05 PM	#5
gbm Wizard Posts: 2,188 Karma: 8888888 Join Date: Jun 2010 Device: Kobo Clara HD,Hisence Sero 7 Pro RIP, Nook STR, jetbook lite	My station 1 router had to be reset, reflashed and settings restored from backup bernie

Advert

Advert