Register Guidelines E-Books Search Today's Posts Mark Forums Read

Go Back   MobileRead Forums > E-Book Software > Calibre Companion

Notices

Reply
 
Thread Tools Search this Thread
Old 04-05-2018, 09:58 AM   #1
jehrler
Enthusiast
jehrler began at the beginning.
 
Posts: 26
Karma: 10
Join Date: Apr 2018
Device: iphone
"kicking" calibre to wake it up required?

We have Calibre set up on a headless Mac mini in our house and have the content server and wireless device connections active. We access it from our iOS devices via calibre companion remotely as a wireless device with no problem but...

If the Mac mini has not been used for a while and we try to access the following happens:

CCompanion searches for calibre, says it is synching but waiting on calibre...and just sits there waiting...and waiting.

It will not finish the synching until I access the Mac mini remotely to even just look at the lock screen. Then it proceeds and finishes up fine.

Any ideas why CCompanion isn't able to give it the final kick? The Mac mini is set not to sleep and the process does seem to find the server, it just can't get all the way through.

Last edited by jehrler; 04-06-2018 at 10:02 AM.
jehrler is offline   Reply With Quote
Old 04-11-2018, 11:55 PM   #2
jehrler
Enthusiast
jehrler began at the beginning.
 
Posts: 26
Karma: 10
Join Date: Apr 2018
Device: iphone
I used the calibre companion debug to get some log info from that side. At 19:17 began trying to connect using calibre companion via wireless device. At 19:20, while cc was still "waiting for calibre" I accessed the content server via web browser.

At 19:21 I used vpn to connect to the Mac mini but didn't log in. CC immediately connected as wireless device.

Here is the debug log from calibre companion:

Spoiler:
2018-04-11 19:17:07.167 [Default|INFO] Log event: A_ConnectWireless ["MobileDataEnabled": false, "WirelessPortPreset": false, "WirelessIpPreset": false, "WirelessAttemptFailure": false]
2018-04-11 19:17:07.174 [Default|INFO] WirelessDevice: begin scanning
2018-04-11 19:17:07.181 [Default|INFO] ServerScan: Broadcasting on port 54982
2018-04-11 19:17:07.185 [Default|INFO] ServerScan: Broadcasting on port 48123
2018-04-11 19:17:07.187 [Default|INFO] ServerScan: Broadcasting on port 39001
2018-04-11 19:17:07.190 [Default|INFO] ServerScan: Broadcasting on port 44044
2018-04-11 19:17:07.193 [Default|INFO] ServerScan: Broadcasting on port 59678
2018-04-11 19:17:07.197 [Default|INFO] Searching Bonjour
2018-04-11 19:17:07.232 [Default|INFO] Received response from 192.168.0.52 via Bonjour
2018-04-11 19:17:11.204 [Default|INFO] WirelessDevice: Found 1 servers
2018-04-11 19:17:11.211 [Default|INFO] WirelessDevice: Connecting to http://192.168.0.52:9090
2018-04-11 19:17:11.231 [Default|INFO] Communicator connected to host 192.168.0.52 on port 9090
2018-04-11 19:17:21.241 [Default|WARNING] Communicator timed out after 10.0s, extending by another 10 seconds. Has dataHandler: false, combinedDataLength nil
2018-04-11 19:17:26.581 [Default|INFO] Received OpCode: getInitialisationInfo
2018-04-11 19:17:26.586 [Default|INFO] GetInitializationInfo: calibre version: 3, 21, 0
2018-04-11 19:17:26.595 [Default|INFO] GetInitializationInfo: sent sync column info to calibre
2018-04-11 19:17:26.673 [Default|INFO] Received OpCode: getDeviceInformation
2018-04-11 19:17:26.685 [Default|INFO] Received OpCode: setCalibreDeviceInfo
2018-04-11 19:17:27.057 [Default|INFO] Received OpCode: freeSpace
2018-04-11 19:17:27.093 [Default|INFO] Received OpCode: setLibraryInfo
2018-04-11 19:18:17.101 [Default|WARNING] Communicator timed out after 50.0s, extending by another 10 seconds. Has dataHandler: false, combinedDataLength nil
2018-04-11 19:18:27.106 [Default|WARNING] Communicator timed out after 60.0s, extending by another 10 seconds. Has dataHandler: false, combinedDataLength nil
2018-04-11 19:18:37.112 [Default|WARNING] Communicator timed out after 70.0s, extending by another 10 seconds. Has dataHandler: false, combinedDataLength nil
2018-04-11 19:18:47.117 [Default|WARNING] Communicator timed out after 80.0s, extending by another 10 seconds. Has dataHandler: false, combinedDataLength nil
2018-04-11 19:18:57.123 [Default|WARNING] Communicator timed out after 90.0s, extending by another 10 seconds. Has dataHandler: false, combinedDataLength nil
2018-04-11 19:19:07.137 [Default|WARNING] Communicator timed out after 100.0s, extending by another 10 seconds. Has dataHandler: false, combinedDataLength nil
2018-04-11 19:19:17.144 [Default|WARNING] Communicator timed out after 110.0s, extending by another 10 seconds. Has dataHandler: false, combinedDataLength nil
2018-04-11 19:19:27.149 [Default|WARNING] Communicator timed out after 120.0s, extending by another 10 seconds. Has dataHandler: false, combinedDataLength nil
2018-04-11 19:19:37.168 [Default|WARNING] Communicator timed out after 130.0s, extending by another 10 seconds. Has dataHandler: false, combinedDataLength nil
2018-04-11 19:19:47.174 [Default|WARNING] Communicator timed out after 140.0s, extending by another 10 seconds. Has dataHandler: false, combinedDataLength nil
2018-04-11 19:19:57.181 [Default|WARNING] Communicator timed out after 150.0s, extending by another 10 seconds. Has dataHandler: false, combinedDataLength nil
2018-04-11 19:20:07.188 [Default|WARNING] Communicator timed out after 160.0s, extending by another 10 seconds. Has dataHandler: false, combinedDataLength nil
2018-04-11 19:20:17.194 [Default|WARNING] Communicator timed out after 170.0s, extending by another 10 seconds. Has dataHandler: false, combinedDataLength nil
2018-04-11 19:20:27.199 [Default|WARNING] Communicator timed out after 180.0s, extending by another 10 seconds. Has dataHandler: false, combinedDataLength nil
2018-04-11 19:20:37.211 [Default|WARNING] Communicator timed out after 190.0s, extending by another 10 seconds. Has dataHandler: false, combinedDataLength nil
2018-04-11 19:20:47.217 [Default|WARNING] Communicator timed out after 200.0s, extending by another 10 seconds. Has dataHandler: false, combinedDataLength nil
2018-04-11 19:20:57.226 [Default|WARNING] Communicator timed out after 210.0s, extending by another 10 seconds. Has dataHandler: false, combinedDataLength nil
2018-04-11 19:21:07.232 [Default|WARNING] Communicator timed out after 220.0s, extending by another 10 seconds. Has dataHandler: false, combinedDataLength nil
2018-04-11 19:21:17.239 [Default|WARNING] Communicator timed out after 230.0s, extending by another 10 seconds. Has dataHandler: false, combinedDataLength nil
2018-04-11 19:21:27.244 [Default|WARNING] Communicator timed out after 240.0s, extending by another 10 seconds. Has dataHandler: false, combinedDataLength nil
2018-04-11 19:21:37.252 [Default|WARNING] Communicator timed out after 250.0s, extending by another 10 seconds. Has dataHandler: false, combinedDataLength nil
2018-04-11 19:21:43.856 [Default|INFO] Received OpCode: getBookCount
2018-04-11 19:21:43.866 [Default|INFO] Realm instance loaded, schema: 52
2018-04-11 19:21:43.966 [Default|INFO] GetBooks: Total books=334, of which are new=0
2018-04-11 19:21:43.967 [Default|INFO] GetBooks: Asking calibre what metadata it needs
2018-04-11 19:21:43.970 [Default|INFO] GetBooks: Syncing newer books
2018-04-11 19:21:43.972 [Default|INFO] GetBooks: Sending metadata 1. PriKey 1, Dragonfly in Amber - Diana Gabaldon (320).epub
2018-04-11 19:21:44.011 [Default|INFO] GetBooks: Sending metadata 31. PriKey 31, Oathbringer - Brandon Sanderson (506).epub
2018-04-11 19:21:44.050 [Default|INFO] GetBooks: Sending metadata 61. PriKey 61, Promise of Blood_ The Powder Mage Trilogy_ Book 1 - Brian McClellan (452).epub
2018-04-11 19:21:44.088 [Default|INFO] GetBooks: Sending metadata 91. PriKey 91, Ep.#3 - _Resurrection_ (The Frontiers Saga - Part 2_ Rogue Castes) - Ryk Brown (416).epub
2018-04-11 19:21:44.127 [Default|INFO] GetBooks: Sending metadata 121. PriKey 121, Close Your Eyes - Michael Robotham (375).epub
2018-04-11 19:21:44.170 [Default|INFO] GetBooks: Sending metadata 151. PriKey 151, Vital Abyss, The - James S. A. Corey (340).epub
2018-04-11 19:21:44.211 [Default|INFO] GetBooks: Sending metadata 181. PriKey 181, Ivanhoe - Sir Walter Scott (303).epub
2018-04-11 19:21:44.250 [Default|INFO] GetBooks: Sending metadata 211. PriKey 211, In Fire Forged_ Worlds of Honor V - David Weber (203).epub
2018-04-11 19:21:44.288 [Default|INFO] GetBooks: Sending metadata 241. PriKey 241, Shadow of Freedom - David Weber (171).epub
2018-04-11 19:21:44.327 [Default|INFO] GetBooks: Sending metadata 271. PriKey 271, At All Costs - David Weber (126).epub
2018-04-11 19:21:44.365 [Default|INFO] GetBooks: Sending metadata 301. PriKey 301, Antares Victory - Michael McCollum (280).epub
2018-04-11 19:21:44.404 [Default|INFO] GetBooks: Sending metadata 331. PriKey 331, Matter - Iain M. Banks (539).epub
2018-04-11 19:21:44.407 [Default|INFO] GetBooks: Sending metadata 333. PriKey 333, Colony in a Nation, A - Chris Hayes (542).epub
2018-04-11 19:21:44.410 [Default|INFO] GetBooks: Have sent all known book metadata. Books.size=334, including discovered=334
2018-04-11 19:21:44.411 [Default|INFO] GetBooks: Have finished sending placeholders for all discovered books.
2018-04-11 19:21:46.118 [Default|INFO] GetBooks: Number of books needed by Calibre: 0
2018-04-11 19:21:46.124 [Default|INFO] Completed Sending books and paths
2018-04-11 19:21:47.230 [Default|INFO] Received OpCode: sendBooklists
2018-04-11 19:21:47.253 [Default|INFO] SendBookLists: 0 books with updated metadata about to be sent
2018-04-11 19:21:47.776 [Default|INFO] Received OpCode: freeSpace
2018-04-11 19:21:47.802 [Default|INFO] Received OpCode: noOp
2018-04-11 19:21:59.851 [Default|INFO] Received OpCode: noOp
2018-04-11 19:22:12.214 [Default|INFO] Received OpCode: noOp
2018-04-11 19:22:24.300 [Default|INFO] Received OpCode: noOp
2018-04-11 19:22:28.554 [Default|INFO] Received OpCode: noOp
2018-04-11 19:22:30.000 [Default|INFO] Communicator disconnected
2018-04-11 19:22:31.942 [Default|INFO] Log event: A_OpenedExtraMenu [:]
2018-04-11 19:22:34.398 [Default|INFO] Log event: V_Settings [:]
2018-04-11 19:22:39.682 [Default|INFO] Log event: A_EmailLog [:]

Last edited by chaley; 04-12-2018 at 04:20 AM. Reason: Added "Spoiler" button
jehrler is offline   Reply With Quote
Advert
Old 04-12-2018, 04:19 AM   #3
chaley
CC Android & calibre dev
chaley ought to be getting tired of karma fortunes by now.chaley ought to be getting tired of karma fortunes by now.chaley ought to be getting tired of karma fortunes by now.chaley ought to be getting tired of karma fortunes by now.chaley ought to be getting tired of karma fortunes by now.chaley ought to be getting tired of karma fortunes by now.chaley ought to be getting tired of karma fortunes by now.chaley ought to be getting tired of karma fortunes by now.chaley ought to be getting tired of karma fortunes by now.chaley ought to be getting tired of karma fortunes by now.chaley ought to be getting tired of karma fortunes by now.
 
Posts: 8,903
Karma: 2737684
Join Date: Jan 2010
Location: UK
Device: Many android devices
I don't own a Mac so any opinion I have is suspect, but it does seem clear that something in the Mini is "sleeping".

What I see from that log:
  • Calibre is awake enough to respond to CC's connection request.
  • Calibre starts the sequence of "jobs" to actually connect.
  • Calibre sends several "commands" to CC, and CC successfully responds.
  • Calibre successfully sends CC a command with information about the calibre library.
  • Calibre does not receive CC's reply to the library info command until the Mini is "tickled".
From CC's point of view, calibre went away in the middle of processing the library information command, then came back. I don't see any obvious reason why calibre would pause after sending that command. The networking for that step is exactly the same as what happened successfully in previous steps.

One possibility is that the calibre GUI is being blocked. If this happened then the wireless device networking thread would also be blocked. Various GUI things do happen during connection and CC does continue once the GUI is awakened, so there might be something here.

Getting a calibre debug log might help because it will show what calibre thinks is happening. This FAQ answer explains how to get that log.
chaley is offline   Reply With Quote
Old 04-12-2018, 05:15 AM   #4
jehrler
Enthusiast
jehrler began at the beginning.
 
Posts: 26
Karma: 10
Join Date: Apr 2018
Device: iphone
attached is the debug file
Attached Files
File Type: rtf Untitled.rtf (115.8 KB, 47 views)

Last edited by jehrler; 04-12-2018 at 05:54 AM.
jehrler is offline   Reply With Quote
Old 04-12-2018, 07:13 AM   #5
chaley
CC Android & calibre dev
chaley ought to be getting tired of karma fortunes by now.chaley ought to be getting tired of karma fortunes by now.chaley ought to be getting tired of karma fortunes by now.chaley ought to be getting tired of karma fortunes by now.chaley ought to be getting tired of karma fortunes by now.chaley ought to be getting tired of karma fortunes by now.chaley ought to be getting tired of karma fortunes by now.chaley ought to be getting tired of karma fortunes by now.chaley ought to be getting tired of karma fortunes by now.chaley ought to be getting tired of karma fortunes by now.chaley ought to be getting tired of karma fortunes by now.
 
Posts: 8,903
Karma: 2737684
Join Date: Jan 2010
Location: UK
Device: Many android devices
Quote:
Originally Posted by jehrler View Post
attached is the debug file
That debug log shows two connects. The first connect worked without pause.

The second, around 9 minutes after the first, had a 2.5 minute pause at the point just after the device was detected (CC connected and exchanged network traffic) and before calibre asks CC if it has appropriate memory. When the pause happens calibre is informing its GUI and any interested plugins that a device has connected. CC is waiting for calibre at that point and cannot be involved in the pause.

This sequence demonstrates that the problem is in the Mini. It argues that something on the Mini is preventing the calibre GUI (or something connected to the GUI such as some kind of tray notifier) from running. I have no idea what that "something" might be, nor do I have any idea whether there is some setting that affects it.

FWIW: it seems that this "pause" is at a different place than the one indicated by the CC debug log. If that is indeed the case then whatever is happening on the Mini doesn't consistently happen at the same time.
chaley is offline   Reply With Quote
Advert
Old 04-12-2018, 12:39 PM   #6
theducks
Well trained by Cats
theducks ought to be getting tired of karma fortunes by now.theducks ought to be getting tired of karma fortunes by now.theducks ought to be getting tired of karma fortunes by now.theducks ought to be getting tired of karma fortunes by now.theducks ought to be getting tired of karma fortunes by now.theducks ought to be getting tired of karma fortunes by now.theducks ought to be getting tired of karma fortunes by now.theducks ought to be getting tired of karma fortunes by now.theducks ought to be getting tired of karma fortunes by now.theducks ought to be getting tired of karma fortunes by now.theducks ought to be getting tired of karma fortunes by now.
 
theducks's Avatar
 
Posts: 22,775
Karma: 23579576
Join Date: Aug 2009
Location: (The original) Silicon Valley, USA
Device: K4NT, Galaxy Tab A, Kobo Aura2
Does the HD on the mini sleep?
Chaley: does the initial CC just rely on what is in Calibres memory and the failing bit, need some stuff from the HD?
theducks is online now   Reply With Quote
Old 04-12-2018, 12:46 PM   #7
jehrler
Enthusiast
jehrler began at the beginning.
 
Posts: 26
Karma: 10
Join Date: Apr 2018
Device: iphone
Quote:
Originally Posted by theducks View Post
Does the HD on the mini sleep?
Chaley: does the initial CC just rely on what is in Calibres memory and the failing bit, need some stuff from the HD?
Good question. I did have the hard drive set to sleep. With all the other server functions on the mini (vpn, Plex) this has not been an issue but I will change it to see.

BTW, I have also turned change the preference so Calibre now turns off animations in case that was an issue.

Lastly, have used the terminal to turn of dock bouncing for alerts/launching. I have seen the dock icon for calibre bouncing when connecting via wireless device so that is now off too.

Here's hoping...
jehrler is offline   Reply With Quote
Old 04-12-2018, 01:37 PM   #8
jehrler
Enthusiast
jehrler began at the beginning.
 
Posts: 26
Karma: 10
Join Date: Apr 2018
Device: iphone
Issue remains. Oh well.
jehrler is offline   Reply With Quote
Reply

Thread Tools Search this Thread
Search this Thread:

Advanced Search

Forum Jump

Similar Threads
Thread Thread Starter Forum Replies Last Post
Calibre-generated epub (from .docx) gives "e21027" "multiple opf files" on KindleGen GhostRider Conversion 0 12-22-2017 09:06 AM
Generic "Sending to Device" template not kicking in on Folder Device At_Libitum Library Management 2 11-01-2013 07:12 AM
Checking for required libs. Exporting Binaries "easily" twobob Kindle Developer's Corner 28 10-13-2013 10:57 PM
"White Spaces Are Required"...PLEASE HELP! UntreedReads ePub 12 07-22-2010 03:47 PM
PDF "Kicking" iliad Havard iRex 1 10-24-2009 10:34 AM


All times are GMT -4. The time now is 08:24 PM.


MobileRead.com is a privately owned, operated and funded community.