MobileRead Forums - View Single Post

chaley · 06-26-2016, 05:32 AM

I have run the following experiments to check if CC and calibre disconnect properly.

In order to avoid any "normal" shutdown processing, in the second through fourth experiments I "disconnected" by removing my WiFi hub from the network. This process ensures that neither CC nor calibre are aware that the network has been cut until something times out.

I include the relevant portions of the calibre debug log for each experiment.

Experiment 1: the baseline -- connect and disconnect normally. As expected, it works; calibre disconnects normally.

Spoiler:

Experiment 2: disconnect during the startup handshake. Calibre disconnects normally. In some cases CC can wait for some hours (the general network keepalive timeout) showing a dialog box waiting for you to tap "Cancel", but this is not the behavior you are describing.

Spoiler:

Code:

Job: 17 Get device information started
SMART_DEV ( 762.65:  0.002) get_device_information
SMART_DEV ( 762.68:  0.024) _call_client GET_DEVICE_INFORMATION wfr True
SMART_DEV ( 781.60: 18.904) _write_metadata_cache
SMART_DEV ( 781.68:  0.061) _write_metadata_cache wrote 6 entries, purged 0 entries
SMART_DEV ( 781.70:  0.002) _receive_from_client device went away
SMART_DEV ( 781.71:  0.000) _call_client other exception
Traceback (most recent call last):
  File "D:\CBH_Data\calibre.git\calibre_dev\src\calibre\devices\smart_device_app\driver.py", line 613, in _call_client
  File "D:\CBH_Data\calibre.git\calibre_dev\src\calibre\devices\smart_device_app\driver.py", line 649, in _receive_from_client
ControlError: Device closed the network connection
DeviceJob: 17 Get device information done, calling callback
Device closed the network connection

Traceback (most recent call last):
  File "D:\CBH_Data\calibre.git\calibre_dev\src\calibre\gui2\device.py", line 87, in run
  File "D:\CBH_Data\calibre.git\calibre_dev\src\calibre\gui2\device.py", line 463, in _get_device_information
  File "D:\CBH_Data\calibre.git\calibre_dev\src\calibre\devices\smart_device_app\driver.py", line 50, in _synchronizer
  File "D:\CBH_Data\calibre.git\calibre_dev\src\calibre\devices\smart_device_app\driver.py", line 1193, in get_device_information
  File "D:\CBH_Data\calibre.git\calibre_dev\src\calibre\devices\smart_device_app\driver.py", line 50, in _synchronizer
  File "D:\CBH_Data\calibre.git\calibre_dev\src\calibre\devices\smart_device_app\driver.py", line 613, in _call_client
  File "D:\CBH_Data\calibre.git\calibre_dev\src\calibre\devices\smart_device_app\driver.py", line 649, in _receive_from_client
ControlError: Device closed the network connection

DeviceJob: 17 Get device information callback returned
SMART_DEV ( 781.78:  0.059) post_yank_cleanup
READING LIST: Device disconnected
Job: 17 Get device information finished
Device closed the network connection

        Traceback (most recent call last):
          File "D:\CBH_Data\calibre.git\calibre_dev\src\calibre\gui2\device.py", line 87, in run
          File "D:\CBH_Data\calibre.git\calibre_dev\src\calibre\gui2\device.py", line 463, in _get_device_information
          File "D:\CBH_Data\calibre.git\calibre_dev\src\calibre\devices\smart_device_app\driver.py", line 50, in _synchronizer
          File "D:\CBH_Data\calibre.git\calibre_dev\src\calibre\devices\smart_device_app\driver.py", line 1193, in get_device_information
          File "D:\CBH_Data\calibre.git\calibre_dev\src\calibre\devices\smart_device_app\driver.py", line 50, in _synchronizer
          File "D:\CBH_Data\calibre.git\calibre_dev\src\calibre\devices\smart_device_app\driver.py", line 613, in _call_client
          File "D:\CBH_Data\calibre.git\calibre_dev\src\calibre\devices\smart_device_app\driver.py", line 649, in _receive_from_client
        ControlError: Device closed the network connection

Experiment 3: disconnect after CC and calibre finish all startup processing. CC is waiting for commands from calibre. Calibre notices the disconnect after some 20 seconds and disconnects. CC may or may not notice at approximately the same time. If CC does notice then it shows a dialog. If it does not notice then it waits until you manually disconnect (CC's menu). As mentioned above CC should time out in a few hours but I didn't wait that long.

Spoiler:

Experiment 4: disconnect while calibre and CC are negotiating about syncing books. Calibre noticed and disconnected. Usually the disconnect happened in seconds, but during two runs of the experiment it took all of the 300 seconds (5 minutes) allowed by the calibre wireless driver.

However, there is a problem on the CC side. CC does not notice for hours (the network "keepalive timeout") and there is no way to cancel the process other than to force-stop CC. A similar case was reported in the past but I didn't find the cause. Now I have it and the fix will be in the next release. In any event, this isn't the problem you are reporting because it is obvious that CC thinks it is still connected and waiting for books to be transferred.

Spoiler:

Code:

SMART_DEV (2627.01:  0.216) _create_upload_path lengths mobi 189 21 87
SMART_DEV (2627.03:  0.000) upload_books lpath xxx.mobi
SMART_DEV (2627.06:  0.011) _json_encode series sort =  1632
SMART_DEV (2646.33: 19.256) _send_byte_string socket error [Errno 10054] An existing connection was forcibly closed by t
he remote host 10054
SMART_DEV (2646.36:  0.000) _write_metadata_cache
SMART_DEV (2646.43:  0.046) _write_metadata_cache wrote 6 entries, purged 0 entries
DeviceJob: 38 Upload 4 books to device:1633, xxx done,
 calling callback
[Errno 10054] An existing connection was forcibly closed by the remote host

Traceback (most recent call last):
  File "D:\CBH_Data\calibre.git\calibre_dev\src\calibre\gui2\device.py", line 87, in run
  File "D:\CBH_Data\calibre.git\calibre_dev\src\calibre\gui2\device.py", line 584, in _upload_books
  File "D:\CBH_Data\calibre.git\calibre_dev\src\calibre\devices\smart_device_app\driver.py", line 50, in _synchronizer
  File "D:\CBH_Data\calibre.git\calibre_dev\src\calibre\devices\smart_device_app\driver.py", line 1452, in upload_books
  File "D:\CBH_Data\calibre.git\calibre_dev\src\calibre\devices\smart_device_app\driver.py", line 689, in _put_file
  File "D:\CBH_Data\calibre.git\calibre_dev\src\calibre\devices\smart_device_app\driver.py", line 575, in _send_byte_string
error: [Errno 10054] An existing connection was forcibly closed by the remote host

DeviceJob: 38 Upload 4 books to device:1633, Book with lower case author, xxx callback returned
SMART_DEV (2646.50:  0.050) post_yank_cleanup
READING LIST: Device disconnected
Job: 38 Upload 4 books to device:1633, xxx finished
[Errno 10054] An existing connection was forcibly closed by the remote host
        Traceback (most recent call last):
          File "D:\CBH_Data\calibre.git\calibre_dev\src\calibre\gui2\device.py", line 87, in run
          File "D:\CBH_Data\calibre.git\calibre_dev\src\calibre\gui2\device.py", line 584, in _upload_books
          File "D:\CBH_Data\calibre.git\calibre_dev\src\calibre\devices\smart_device_app\driver.py", line 50, in _synchronizer
          File "D:\CBH_Data\calibre.git\calibre_dev\src\calibre\devices\smart_device_app\driver.py", line 1452, in upload_books
          File "D:\CBH_Data\calibre.git\calibre_dev\src\calibre\devices\smart_device_app\driver.py", line 689, in _put_file
          File "D:\CBH_Data\calibre.git\calibre_dev\src\calibre\devices\smart_device_app\driver.py", line 575, in _send_byte_string
        error: [Errno 10054] An existing connection was forcibly closed by the remote host

Experiment 5: Force-close CC while leaving the WiFi connected. This checks that Android correctly closes the network sockets. Calibre noticed the disconnect very quickly.

Spoiler:

As you can see, none of these experiments repeat the behavior you report. I don't deny that you are seeing the behavior you describe but I can't fix anything until I can reliably repeat it.

You might try producing a calibre debug log, which might give some clue(s) about what it happening.