Scheduler fails to connect

I switched to b48 yesterday. Today the Log reports that it has a problem connecting to the scheduler and subsequently advises that the communications socket is broken (see attachment for full detail). The Activity Monitor however appears happy and is quoting the next run correctly.

A couple of days ago I upgraded to 10.4.10 (because Apple told me that syncing with dotmac wouldn't work correctly if I didn't) and I've noticed that start-up time is longer that it was with 10.4.9. I also have quite a number of log-in items. Maybe the time-out delay is a little too short?

-- Charles

[Thumb - QRecall002.jpg]

Filename QRecall002.jpg

Description Detail from today's Log

Filesize 20 Kbytes

Downloaded 26460 time(s)

[Disk] Download

Hello Charles,

I'd be interested in seeing a copy of your entire log file, especially the period of time that you upgraded.

To be compatible with Leopard, b48 uses a different inter-process communications method. It sounds like it's eventually connecting (since its reporting the correct next action times and I assume that actions are running when they should). But it looks like some trash is getting left behind, possibly between reboots, that's not getting cleaned up.

Log file sent separately. Yes - QRecall is eventually connecting as the back-ups are running as scheduled.

-- Charles

Charles,

I had a chance to review your log files, and I have a few questions.

What the log files are showing me is that everything hums along nicely until about 22:30 in the evening, then the log entries abruptly stop. About 08:30 the next morning processes start up again. But there is no log entries indicating that the old processes were ever shutdown between 22:30 and 08:30.

Are you shutting down your computer at night, or is there some possibility that it simply being turned off or crashed (without going through its complete shutdown procedure)?

What's happening is this: The scheduler creates a semi-permanent communications port that it uses to talk to other processes. When the system boots up in the morning, the port is still there but there's no scheduler process connected to it. QRecall recovers by deleting the port and creating a new one, but not before you get those "Problem connecting to scheduler" warnings.

Most nights I log out leaving the computer on. I got into the habit of doing this when I was using Personal Backup which ran at night with all users logged out. I also have the impression that logging out/in can improve performance if I've updated software during the day, wrongly perhaps?

-- Charles

Then I need to theorize a reason why your log records would stop when you log out. Are you using FileVault by any chance?

The biggest performance gain by logging out, in my experience, is that it forces all of the user processes to quit and restart. This releases all of the stale file references and memory fragmentation that accumulate over time and starts over fresh.

Whether that little bit of extra performance compensates for the time spent logging out and back in is open to debate. But if it helps you, there's certainly nothing wrong with doing that.

I've upgraded to Leopard, and to b48. I have the same problems: Problem connecting to scheduler, Comms socket broken, then eventually okay.

James Bucanek wrote:Then I need to theorize a reason why your log records would stop when you log out. Are you using FileVault by any chance?

No. By the way I don't see the problem when I restart.

-- Charles

I've found out what the problem is.

A recent change to OS X now kills (SIGKILL -- essentially a force quit) any process belonging to the user when they log out. Worse, it kills any background process that tries to start up again.

This change makes it impossible for the scheduler to run while logged out.

I hope to have a solution soon.

James Bucanek wrote:A recent change to OS X now kills (SIGKILL -- essentially a force quit) any process belonging to the user when they log out. Worse, it kills any background process that tries to start up again.

This change makes it impossible for the scheduler to run while logged out.

Just for the record, I get the problem with a restart too. This is with 10.4.10, I didn't see it with 10.4.9.

-- Charles

James Bucanek wrote:I've found out what the problem is.

A recent change to OS X now kills (SIGKILL -- essentially a force quit) any process belonging to the user when they log out. Worse, it kills any background process that tries to start up again.

This change makes it impossible for the scheduler to run while logged out.

I hope to have a solution soon.

I wonder if this explains the problem I've been having on my sever. For several weeks now, QRecall hasn't run at its scheduled time, which is 2:00 AM. Unfortunately, I've been too busy with other things to get too concerned about it, and whenever I do log in, it does the backup within a few minutes after that.

The log is full of entries like this, which repeat every 30 minutes:

2007-10-30 01:29:01.111 -0400 #debug# -[QRUserBSDSocketPath connectPort] /var/tmp/QRecall.501/QRecallScheduler [3.732979.4047.1]
2007-10-30 01:29:02.611 -0400 Failure Communications socket with existing scheduler is broken [3.732979.4047.2]
2007-10-30 01:29:02.612 -0400 Details [NSPortCoder sendBeforeTime:sendReplyPort:] timed out [3.732979.4047.2.1]
2007-10-30 01:29:02.612 -0400 Details NSPortTimeoutException exception [3.732979.4047.2.1.1]
2007-10-30 01:29:02.614 -0400 #debug# -[QRUserBSDSocketPath deleteSocket] /var/tmp/QRecall.501/QRecallScheduler [3.732979.4047.3]
2007-10-30 01:29:02.614 -0400 #debug# -[QRUserBSDSocketPath createPort] /var/tmp/QRecall.501/QRecallScheduler [3.732979.4047.4]

-- Bruce

I wonder if this explains the problem I've been having on my sever.

Very likely.

Version 1.0.0(49) should resolve this problem. It's finished and available on the alpha release feed. It's been undergoing testing here for the past two days. If all goes well, I'll release it to the beta feed tomorrow.

James Bucanek wrote:

I wonder if this explains the problem I've been having on my sever.

Very likely.

Version 1.0.0(49) should resolve this problem. It's finished and available on the alpha release feed. It's been undergoing testing here for the past two days. If all goes well, I'll release it to the beta feed tomorrow.

I'm afraid that the cure hasn't worked for me. The attachment shows the log after installing v49, then logging out/in and finally a restart. The good news is that the Activity Monitor continues to show that QRecall will back-up as scheduled. I have sent this month's log file to James separately.

-- Charles

Attachment failed first time.

[Thumb - QRecall003.jpg]

Filename QRecall003.jpg

Description No description given

Filesize 106 Kbytes

Downloaded 26003 time(s)

[Disk] Download

Charles Watts-Jones wrote:I'm afraid that the cure hasn't worked for me. The attachment shows the log after installing v49, then logging out/in and finally a restart. The good news is that the Activity Monitor continues to show that QRecall will back-up as scheduled. I have sent this month's log file to James separately.

v49 did fix my problem. Now I can log out and scheduled tasks are once again running. But I've got a new problem. Actually, I'm not sure how much of a problem it is. I wouldn't have even known about it had I not looked at the log.

Now, every time I launch QRecall, I get three new lines in the log file:

Problem connecting to scheduler
NSDistantObject access attempted from another thread
NSObjectInaccessibleException exception

But other than that, everything seems to be working. I'll send the log file to James.

-- Bruce


Filename	QRecall002.jpg
Description	Detail from today's Log
Filesize	20 Kbytes
Downloaded	26460 time(s)
Download


Filename	QRecall003.jpg
Description	No description given
Filesize	106 Kbytes
Downloaded	26003 time(s)
Download