Making a huge PDF into a reasonably-sized one (by tossing superfluous bits) ... in gs(1)

Short version:

$ gs -o reasonable.pdf -sDEVICE=pdfwrite -r300x300 huge.pdf

or, to turn foo-big.pdf → foo.pdf and save a little typing, bash and some other shells allow:

$ gs -sDEVICE=pdfwrite -r300x300  -o foo{,-big}.pdf

Last week, I wrote an annual update, a family "newsletter" of sorts. This time, because of the baby (our first grandchild) we had more photos than usual. (We briefly considered having him in every photo, but there actually is one where Baby isn't visible.) I did this in OpenOffice, and then, to send to the printer, I clicked on the "PDF" button. The resulting file was, ahem, huge.

-rw-r--r-- 1 collin 19067843 Nov 30 20:01 Dec2014.pdf

Yes, over 19 million bytes; it was probably because the photos in there were too big. I told openoffice to make them about 2 inches high or whatever, but I guess all the bits were still there (the ".odt" file itself was nearly 12 Mbytes). I did a web search on "downsample pdftk" (no quotes), which led me to this hint, briefly

gs \
  -o output.pdf \
  -sDEVICE=pdfwrite \
  -dPDFSETTINGS=/screen \
   input.pdf

I tried this, and the output shrank down to about 70 kbytes. Impressive, but the photos were quite ugly. I mean, they looked OK on the screen, but for printing? Blech. I guess that's what /screen means.

Remembering the old saying, rtfm, I said "man gs" and found:

   Some devices can support different resolutions (densities).  To specify
   the resolution on such a printer, use the "-r" switch:

 gs -sDEVICE= -rx

   For  example,  on a 9-pin Epson-compatible printer, you get the lowest-
   density (fastest) mode with

 gs -sDEVICE=epson -r60x72

"Aha!" I thought. Let me do this:

$ gs -o output.pdf -sDEVICE=pdfwrite -r300x300 Dec2014.pdf

and the result, besides being under 1MB in size, looked great in okular, which is the PDF viewer on my Linux distro.

For my Linguist Daughter: a Cryptoquip

I have this urge to explain things that I learn. Yesterday's “Crypt-quip” gives me that opportunity.

The “cryptoquip” is a substitution cipher, where each letter stands for some other letter. For example, they gave us this clue: “W equals L”—which means that throughout the puzzle, every W stands for an L. Our job is to figure out what the other letters stand for, to reveal a groaner of a pun…

R U   J   A M S I P T   I A P E M   J

L M W Z R L   W J T B X J B M   C R Z F   J

Z F R L E   U S M T L F   J L L M T Z,   R   C P X W Q

L J W W   R Z   B J W W R L   B J M W R L.

Okay, the first thing to notice is that we have two one-letter words, represented by “J” and “R”. These have to be “I” and “a”, in either order. If “R” were “a” then the quip would begin “A_ I blah blah I …”; maybe “As I was walking I noticed…”

To tell the truth, though, I didn't even think of that; I just assumed that it began “If a blah blah a …”; it might also be “In a...” or “Is a…”; I didn't think it started off “It a…,” which isn't grammatical. But let’s go with R⇒I and J⇒A and defer the U for a while.

The clue tells us that “W” represents “L”, so that “LJWW” on the last line is “_ALL”. Experience with these groaners suggests the part after the comma, which so far we know is “I ___l_ _all i_…”, most likely will represent “I would call it….” But even without that knowledge, you could probably guess that LJWW means “call”; it's probably not ball, fall, gall, hall, mall, pall, tall, or wall.

If L⇒C, then what does LMWZRL on the 2nd line mean? C_L_IC—too short for “garlic,” besides starting with the wrong letter; C_LBIC? C_LDIC? Wait, didn't I guess that “LJWW RZ” was “CALL IT” (last line)? If so, then Z⇒T and LMWZRL is C_LTIC.

H'm, Not CALTIC (J⇒A hence we can't have M⇒A). CELTIC maybe? One thing about ALL-CAPS in the cryptoquip is that nothing marks proper nouns (or adjectives in this case). I suppose LMWZRL could also be COLTIC (is that a word?) or CULTIC (still possible).

Suppose it were CELTIC (M⇒E). Then our puzzle would look like this:

 I _   A   _ E _ _ _ _   _ _ _ _ E   A
 R U   J   A M S I P T   I A P E M   J

 C E L T I C   L A _ _ _ A _ E   _ I T _   A
 L M W Z R L   W J T B X J B M   C R Z F   J

 T _ I C _   _ _ E _ C _   A C C E _ T,   I   _ _ _ L _
 Z F R L E   U S M T L F   J L L M T Z,   R   C P X W Q

 C A L L   I T   _ A L L I C   _ A E L I C
 L J W W   R Z   B J W W R L   B J M W R L.

I see “Celtic” in line 2 and “_aelic” in line 4. Gaelic? If B⇒G then we'd have:

 I _   A   _ E _ _ _ _   _ _ _ _ E   A
 R U   J   A M S I P T   I A P E M   J

 C E L T I C   L A _ G _ A G E   _ I T _   A
 L M W Z R L   W J T B X J B M   C R Z F   J

 T _ I C _   _ _ E _ C _   A C C E _ T,   I   _ _ _ L _
 Z F R L E   U S M T L F   J L L M T Z,   R   C P X W Q

 C A L L   I T   G A L L I C   G A E L I C
 L J W W   R Z   B J W W R L   B J M W R L.

Gallic? As in French? Maybe the first word really is “If”, in which case the _ _ E _ C _ really could be “French”? Then U⇒F, S⇒R, T⇒N and F⇒H and we have

 I F   A   _ E R _ _ N   _ _ _ _ E   A
 R U   J   A M S I P T   I A P E M   J

 C E L T I C   L A N G _ A G E   _ I T H   A
 L M W Z R L   W J T B X J B M   C R Z F   J

 T H I C _   F R E N C H   A C C E N T,   I   _ _ _ L _
 Z F R L E   U S M T L F   J L L M T Z,   R   C P X W Q

 C A L L   I T   G A L L I C   G A E L I C
 L J W W   R Z   B J W W R L   B J M W R L.

OK, lines 2 is “Celtic language with a”—right? Then X⇒U and C⇒W. Turning to line 3, a THICK French accent, yes? So E⇒K. Let's see how that looks now.

 I F   A   _ E R _ _ N   _ _ _ K E   A
 R U   J   A M S I P T   I A P E M   J

 C E L T I C   L A N G U A G E   W I T H   A
 L M W Z R L   W J T B X J B M   C R Z F   J

 T H I C K   F R E N C H   A C C E N T,   I   W _ U L _
 Z F R L E   U S M T L F   J L L M T Z,   R   C P X W Q

 C A L L   I T   G A L L I C   G A E L I C
 L J W W   R Z   B J W W R L   B J M W R L.

Line 3: “…I would”, yes? P⇒O, Q⇒D and line 1 reads

 IF A _ER_ON __OKE A

“If a person spoke…”? That's it! A⇒P, I⇒S and we're done:

 I F   A   P E R S O N   S P O K E   A
 R U   J   A M S I P T   I A P E M   J

 C E L T I C   L A N G U A G E   W I T H   A
 L M W Z R L   W J T B X J B M   C R Z F   J

 T H I C K   F R E N C H   A C C E N T,   I   W O U L D
 Z F R L E   U S M T L F   J L L M T Z,   R   C P X W Q

 C A L L   I T   G A L L I C   G A E L I C
 L J W W   R Z   B J W W R L   B J M W R L.

Wasn’t that fun?

Happy-ness

I've been thinking about happiness lately, and some of this has to do with the current sermon series at church—not that my thoughts have been all that spiritual. Many have commented that happiness can't be found by directly pursuing it; rather, happiness comes when we're pursuing something else.

I was thinking about this last night. I had paused from whatever I was doing at the computer (it was so important that I don't even remember what it was) to read to Sheri. I read a sentence or two from The New Machine Age but without context it didn't seem all that good a fit. I switched to The Wisdom of the Sadhu, which worked better, though one of the parables didn't really work for her.

After a while I went to the kitchen, remarking that the dog probably wanted her teeth brushed. I opened the cabinet where her dental supplies are kept, and heard her jump from the couch. Her toenails clicked on the hardwood floor as she sped toward the kitchen, and by the time I had the toothpaste on her toothbrush, her forepaws were on my leg as she expressed her joy.

Her joy was contagious, and I remembered hearing that people live longer if they have someone to care for. Come to think of it, I saw a bumper sticker recently: on one side was a large stylized paw-print, and the words were: "Who rescued who?" or maybe "whom"…

Dishes weren't getting clean in Kenmore Elite dishwasher 665.13422K701

So I noticed that the flatware wasn't getting clean in the dishwasher, and the cups weren't looking so nice either. Things were wet, mostly, but…

I looked at the dishwasher manual for troubleshooting help; no joy. So I did some web searching, and followed their advice (mainly, check for food junk which might impede water flow). The good news was we didn't have food junk impeding the water flow.

So I did some guerilla diagnostics, by which I determined that water was spraying from where it shouldn't (blech). And that the spinning sprayer arms didn't. After getting the kitchen floor quite wet, I noticed a little lever assembly near the axis of the lower spinning sprayer arm; it's in the photo at left. (There's probably a better word for "lever assembly" but I hope you get the idea.)

I zoomed out a bit to take the image at right, which shows the lever in context.

What I noticed was a lot of water shooting out from the gray plastic thingie directly beneath the lever assembly. A plastic ell enters the "floor" of the dishwasher right near there. The lever ought to keep the ell in the floor. When the lever is out of position, water pressure can force the ell out of its position in the floor, and water sprays from where it shouldn't. This reduces water pressure in the (non)-spinning (non)-sprayer arm, resulting in a poor wash.

---

The next three photos at left show the lever returning to its proper position. Notice the catch, or bracket, that keeps the lever from moving up (vertically).

With the lever locked in place, it holds the ell in its proper position, and the water seems to go where it should, spinning the sprayer arm and giving us clean dishes once again.

I was going to ask why they didn't put that in the manual, but I suspect this lever doesn't get moved very often. Actually, I don't even know how ours got thrown out of whack, but it definitely was.

Network issues solved: replaced D-link DIR-810L by ASUS RT-N66U

Streaming video to our computers, or even audio, was problematic at our house. It had been some months (don't remember how many months exactly), but we had these other issues too:

• ssh to my ISP's shell server, and after a few minutes, response would become glacial. I mean, type "ls" and it's literally minutes. If I did it right after login, it was fine; it was only after a few minutes it would act constipated.
• downloads of any size took "forever". We tried to download a map upgrade so the lovely Carol could update her GPS; eventually I wrote a script to kill the download and restart it (fortunately it could pick up from where it left off). It wasn't as straightforward as "wget -c", because we started the download by clicking on some icon, then hitting some button and… (I hate computers.)

  Fortunately, by saying "ps wwx" or something like this I was able to get the program's parameters. The script I wrote involved monitoring the most recently updated file in the most recently updated directory (many files were getting downloaded, with a new directory getting created every so often), then killing and restarting the download process when it looked like things had paused for more than a minute or two.

We have DSL and are supposed to be able to get something like 5-6 Mbits per second. And we often have; we watch streamed video on netflix without problems. So that puzzled me.

On another occasion, Sheri wanted to download a 200-Mbyte package; it never finished. I thought it was the wireless, so I ran a long cable to her computer—not much better. I got the URL and just said "wget" on my own computer, something like this:

collin@p3:/mnt/home/collin> wget -O frsxprodmg https://dl.dropboxusercontent.com/blahblah/FRSXpro3.5.6installer.dmg
--2014-08-26 21:58:03--  https://dl.dropboxusercontent.com/blahblah/FRSXpro3.5.6installer.dmg
Resolving dl.dropboxusercontent.com (dl.dropboxusercontent.com)... 23.21.100.40, 107.22.226.183, 184.73.171.70, ...
Connecting to dl.dropboxusercontent.com (dl.dropboxusercontent.com)|23.21.100.40|:443... connected.
HTTP request sent, awaiting response... 200 OK
Length: 218103808 (208M) [application/x-apple-diskimage]
Saving to: `frsxprodmg'

21% [=======>                               ] 47,504,787   624K/s  eta 4m 36s  ^C^Cc^C^C^C^Z

It sat there, paused, for quite a while. Then, as you can see, I got frustrated and hit some keys to stop it. I then restarted.

collin@p3:/mnt/home/collin> 
collin@p3:/mnt/home/collin> wget -c -O frsxprodmg https://dl.dropboxusercontent.com/blahblah/FRSXpro3.5.6installer.dmg
--2014-08-26 22:00:18--  https://dl.dropboxusercontent.com/blahblah/FRSXpro3.5.6installer.dmg
Resolving dl.dropboxusercontent.com (dl.dropboxusercontent.com)... 54.225.142.207, 54.221.243.250, 54.225.177.135, ...
Connecting to dl.dropboxusercontent.com (dl.dropboxusercontent.com)|54.225.142.207|:443... connected.
HTTP request sent, awaiting response... 206 PARTIAL CONTENT
Length: 218103808 (208M), 170541677 (163M) remaining [application/x-apple-diskimage]
Saving to: `frsxprodmg'

41% [++++++++=======>                       ] 90,094,310   393K/s  eta 4m 37s  ^C

It hung after another, what, 43 million bytes? I restarted it a few more times, getting varying amounts of data in before the download hung. I was very thankful for "wget -c" but even with that, the experience wasn't pleasant. 18MB, 65MB, 2MB, then about 43MB to finish.

Now I will pause here to remember that we live in an astounding age, where in less than half an hour, we can download something like 200 Mbytes of software and be quite confident that the data were not corrupted during transmission. That said, with all this technology it's supposed to be easier.

It was about at this time that I remembered the issues I'd been having with my ssh (login) sessions to my ISP. Could all this be caused by the router? I asked my ISP's support folks.

They confirmed that yes, this behavior could be caused by a flaky router. In my case it was a D-link DIR-810L, which we've had since October.

They suggested I try without the router. Ooooh, OK, so I logged in as root and unmounted all the NFS. Turned off as many services (xinetd, sshd, etc.) as I could figure out easily, changed the network configuration for DHCP, and connected it directly to the DSL modem (disconnecting the rest of the home network).

But I couldn't connect to anything--had to route add default gw with an "educated" (yeah right) guess. I hate computers.

Once I figured that out, I ran wget and… you guessed it—the entire 207MB+ came down in one shot, about five minutes So it was the old router!

After asking some folks at work, I went shopping. The recommended Buffalo item wasn't available locally, but I was looking for the ASUS RT-N66U dual-band wireless-N900 router. Best Buy (near Home Depot!) had an RT-N66R, but I didn't know what the difference was between 'R' and 'U' so was skittish.

I ended up ordering it from amazon and using "amazon locker" for delivery. This worked quite well. The idea is, rather than having to run over to the UPS office ("What are your hours again?"), I can have it delivered to a nearby 7-11 (open 24 hours a day). Amazon.com emails me a secret code, which I key into the locker thingie, and one of the dozens of doors pops open; inside is my item.

So I got it home and hooked it up. Configuration was a breeze, even though I have a somewhat unusual configuration (default gateway is 192.168.1.254, not .1.1). The router automagically downloaded a firmware upgrade (this operation went quite quickly, which made me feel confident in my purchase). I then tried the 207MB download, and it came in under five minutes. Whee!

Icing on the cake: logins to the server don't go all molasses-in-January-in-Minnesota on me after a few minutes.

One more thing: I naïvely set the SSIDs to the same thing on both the 5GHz and 2.4GHz wireless networks. This seemed to confuse the macbook air's wireless. (Was it cycling between the two networks, which btw also shared the same password?) After I separated the SSIDs, the problem went away.

42% “efficient”

Suppose a team of coders work on a project, and we say we want code reviews, or maybe inspections. We have estimates for how long various parts will take to code -- adding up to 3 engineer-weeks, say. How much effort (engineer-days) should we allocate to cover code reviews, discussion and rework?

Well, that depends of course on how much time we think it will take to review and discuss and rework the code. Let's suppose for a moment that if my colleague spends a week coding and doing some basic testing, then I will stare at the code for two days. Actually, let's say there are two reviewers, so two of us will stare at the code for two days each.

Then we have a day where three of us meet (in the morning, say) and talk about the code for a while. After 1½ or 2 hours, we go back to our desks and think some more about what we heard, and the person who wrote the code makes some changes. We repeat that but at the end of the day we're all happy with the code.

As I write this, that seems like a lot of review time, but if we do it that way, the total engineer-days spent add up thus:

• 5 engr-days coding
• 4 engr-days reviewing (2 reviewers @ 2 days each)
• 3 engr-days discussion and rework (3 participants @ 1 day each)

Twelve (12) days total, for a thing whose coding estimate was 5 days.

That works out to 5/12 ≈ 42%. In other words, if you have 10 engineer-days available, then at the above rates of "overhead" you can spend only 4.2 days coding; the rest is review, discussion, rework. That doesn't include integration or system test, etc.

Perhaps I have the wrong ratio of (review + discussion + rework) to (code and basic test), but I'll confess to being surprised at the result of 42% given the above.

One size fits… one.

Today's Old Testament reading, from the book of Nehemiah, shows an interesting contrast in the way different people experience God. In chapter 1 of his book, Nehemiah tells us that he was cupbearer (or wine-taster) for the king in Babylon. He heard about the condition of Jerusalem and was very upset that the walls were broken down and the gates destroyed.

In chapter 2, he asks the king to send him “to the city in Judah where my fathers are buried so that I can rebuild it.” He doesn't mention the name Jerusalem (there probably was some sensitivity about that particular city), but the part I found particularly interesting is what came next:

I also said to him, “If it pleases the king, may I have letters to the governors of Trans-Euphrates, so that they will provide me safe-conduct until I arrive in Judah? And may I have a letter to Asaph, keeper of the king's forest, so he will give me timber to make beams for the gates of the citadel by the temple and for the city wall and for the residence I will occupy?”

And because the gracious hand of my God was upon me, the king granted my requests. So I went to the governors of Trans-Euphrates and gave them the king's letters. The king had also sent army officers and cavalry with me.

Nehemiah 2:7-9

What's so interesting about that? Well, maybe not so much in itself, but what I noticed was the contrast with Ezra, which was in the readings from some days past. The part of Ezra I'm thinking of was this:

There, by the Ahava Canal, I proclaimed a fast, so that we might humble ourselves before our God and ask him for a safe journey for us and our children, with all our possessions. I was ashamed to ask the king for soldiers and horsemen to protect us from enemies on the road, because we had told the king, "The gracious hand of our God is on everyone who looks to him, but his great anger is against all who forsake him."

So we fasted and petitioned our God about this, and he answered our prayer.

Ezra 8:21-23

What I take from these two men of God is not that Ezra trusted God and Nehemiah trusted in military escorts. And it's not that Nehemiah was bold and Ezra was timid. What I get is that God deals with us in a way that's suited to us. He knows us individually, knows our personalities and inclinations and strengths and weaknesses (besides our joys and tears and aspirations and disappointments).

He does not treat us like interchangeable parts; he knows us and cares for each one of us. And the way we honor him is something that's unique to each one of us too. How do I love my children? I love each one for who she is. And that gives me a little picture, a little sense of appreciation for how God loves me—he loves me in a way that's different from the way he loves you, and our paths will be different, and that's okay; indeed, it is very good.

Disable new user signups (registration spam) on a wordpress blog

The lovely Carol has a wordpress blog. She's been getting lots of "new user registrations," and she spends too much time deleting these new "users". These are not real people; they're more likely "spammers wanting to take control of the system through multiple user registrations" according to this site.

I did a web search on "wordpress new users" or something like this (no quotation marks) and found an article titled “How to Disable New User Registration on WordPress Using PhpMyAdmin,” which was useful, except I don't have PhpMyAdmin. And I don't have cPanel either. And that was the most promising of the links that came up. Bummer.

What's a geek to do? well, this:

$ ls
dec24.html                 wp-config-sample.php
fire-safe-box/             wp-content/
INDEX.HTML.oneclickbackup  wp-cron.php
index.php                  wp-includes/
license.txt                wp-links-opml.php
md5sums.txt                wp-load.php
readme.html                wp-login.php
wp-activate.php            wp-mail.php
wp-admin/                  wp-settings.php
wp-blog-header.php         wp-signup.php
wp-comments-post.php       wp-trackback.php
wp-config.php              xmlrpc.php
$ 

H'm, wp-signup.php you say? That looked promising. I noticed this:

 30 if ( !is_multisite() ) {
 31         wp_redirect( site_url('wp-login.php?action=register') );
 32         die();
 33 }
"wp-signup.php" [readonly]

THAT looked promising. I looked in wp-login.php and searched for "register"; I found this:

646         if ( !get_option('users_can_register') ) {
647                 wp_redirect( site_url('wp-login.php?registration=disabled') );
648                 exit();
649         }
"wp-login.php" [readonly] 921 lines

O-kay! So we want to kill off the option 'users_can_register'.

By looking around, I discovered that get_option() gets things from the cache. I searched wordpress.org for "get_option" and landed at http://wordpress.org/search/get_option, which refers to the options database table. Somehow I got the idea of looking in wp-config.php where I discovered this:

// ** MySQL settings ** //
define('DB_NAME', 'bedrockdb');    // The name of the database
define('DB_USER', 'fred_flint');     // Your MySQL username
define('DB_PASSWORD', 'yabbadabbadoo'); // ...and password
define('DB_HOST', 'hanna.bar.be.ra');    // 99% chance you won't need to change this value

(Of course the names are changed to protect… well, myself.) In another window, I typed:

$ mysql
ERROR 2002 (HY000): Can't connect to local MySQL server through socket '/tmp/mysql.sock' (111)

D'oh! I had to fill in the hostname and the username and…

$ mysql -h 'hanna.bar.be.ra' -u 'fred_flint' -p
Enter password: <here I typed “yabbadabbadoo”>
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 24209555 to server version: 5.5.37-35.1-log

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

mysql> use bedrockdb
Database changed
mysql> show tables;
+-----------------------+
| Tables_in_bedrockdb   |
+-----------------------+
| wp_commentmeta        |
| wp_comments           |
| wp_links              |
| wp_options            |
| wp_postmeta           |
| wp_posts              |
| wp_subscribe2         |
| wp_term_relationships |
| wp_term_taxonomy      |
| wp_terms              |
| wp_usermeta           |
| wp_users              |
+-----------------------+
12 rows in set (0.02 sec) 

Okay, that's good. Now which table? wp_options? Yes! And according to the above article, I want wp_options. So I said:

mysql> describe wp_options;
+--------------+---------------------+------+-----+---------+----------------+
| Field        | Type                | Null | Key | Default | Extra          |
+--------------+---------------------+------+-----+---------+----------------+
| option_id    | bigint(20) unsigned | NO   | PRI | NULL    | auto_increment |
| option_name  | varchar(64)         | NO   | UNI |         |                |
| option_value | longtext            | NO   |     | NULL    |                |
| autoload     | varchar(20)         | NO   |     | yes     |                |
+--------------+---------------------+------+-----+---------+----------------+
4 rows in set (0.01 sec)

mysql> select * from wp_options where option_name = 'users_can_register'; 
+-----------+--------------------+--------------+----------+
| option_id | option_name        | option_value | autoload |
+-----------+--------------------+--------------+----------+
|         6 | users_can_register | 1            | yes      |
+-----------+--------------------+--------------+----------+
1 row in set (0.02 sec)

It's been a while since I updated a table in MySQL. Naturally I went to a web search to find a list of SQL commands. This one told me what I needed, down in "Data Commands."

Let's see, I wanted to change the option_value from 1 to 0 where… OK, I tried this.

mysql> update wp_options set option_value = 0 where option_name = 'users_can_register';
Query OK, 1 row affected (0.01 sec)
Rows matched: 1  Changed: 1  Warnings: 0

Wow, it worked the first time! How often does that happen? Just to be sure, I typed this:

mysql> select * from wp_options where option_name = 'users_can_register';
+-----------+--------------------+--------------+----------+
| option_id | option_name        | option_value | autoload |
+-----------+--------------------+--------------+----------+
|         6 | users_can_register | 0            | yes      |
+-----------+--------------------+--------------+----------+
1 row in set (0.01 sec)

mysql> quit
Bye

Now for the acid test. I went to the sign-up page "wp-signup.php" and got: "User registration is currently not allowed."

And that's what I'll do next time.

CSV to QIF transformation with Python3

This evening I discovered that the folks at my bank, or more probably the folks running the online banking website, have "upgraded" the user interface, and they no longer support downloading transactions to the "old" Quicken file format (i.e., "QIF"). Instead, they (mostly) support "export"ing transactions to CSV.

Fortunately, a format conversion from CSV to QIF isn't that hard. I first did a web search, which yielded

• a website (upload your csv and we'll give you a qif file),
• some Windows (I guess) software--free to download and try, but I guess they want money for it, and
• maybe something else that I didn't think would work for me

so I decided to just hack something together. Of course it would be in Python, and probably python3.

I remembered that there was a module that knew how to read and write CSV files; a quick look at the library reference showed that the module is called, oddly enough, "csv"; the result is described here (produced by "pydoc3 -w csv_to_qif")

csv_to_qif

index /mnt/home/collin/projects/csv-qif/csv_to_qif.py

transform a "csv" file on stdin to a "qif" file on stdout.

Modules
		csv os sys

Functions
		main(infile, outfile) Read infile -- we expect valid entries to have 9 fields: xaction#, date, descr, memo, amt debit, amt credit, bal, check#, fees   Write an outfile that looks like...     !Type:Bank     C*     Dmm/dd/yyyy     T<amount> (negative for withdrawal)     N###      (## = checkNumber)     P<descr>  (description...)     ^ Each entry begins with "C" and ends with "^".

Here's the code. It is Copyright©2014 by me, but you are free to use, redistribute and or modify it under the terms of GPL2; see below.

#!/usr/bin/python3 -utt
# vim:et
'''transform a "csv" file on stdin to a "qif" file on stdout.'''

# This program is free software: you can redistribute it and/or modify
# it under the terms of the GNU General Public License as published by
# the Free Software Foundation, version 2.
# NO WARRANTY express or implied.

import csv
import os
import sys

def main(infile, outfile):
    '''Read infile -- we expect valid entries to have 9 fields:
    xaction#, date, descr, memo, amt debit, amt credit, bal, check#, fees
    
    Write an outfile that looks like...
        !Type:Bank
        C*
        Dmm/dd/yyyy
        T (negative for withdrawal)
        N###      (## = checkNumber)
        P  (description...)
        ^
    Each entry begins with "C" and ends with "^".'''

    outfile.write('!Type:Bank\n')

    reader = csv.reader(infile)
        
    for arow in reader:
        if len(arow) == 1:
            continue                    # a couple of title lines
        if len(arow) != 9:
            print("I don't grok this row with len=%d:\n\t'%s'" %
                        (len(arow), "',".join(arow)), outfile=sys.stderr)
            continue
        trans_num, date, descr, memo, deb, cred, bal, cnum, fees = arow
        if date.startswith('Date'):
            continue                    # that's the header line
        outfile.write('C*\n')
        outfile.write('D%s\n' % date)
        if deb:
            outfile.write('T%s\n' % deb)
        else:
            outfile.write('T%s\n' % cred)
        if cnum:
            outfile.write('N%s\n' % cnum)
        outfile.write('P%s\n' % descr)
        outfile.write('^\n')
    sys.exit(0)

if __name__ == '__main__':
    try:
        infile = open(sys.argv[1], 'r')
        outfile = open(sys.argv[2], 'w')
    except:
        print('usage: %s INFILE OUTFILE' % os.path.basename(sys.argv[0]))
    main(infile, outfile)

UPDATE 2014-06-24: Added a "C*" at the beginning of each entry. Without this, my quicken "check register" wasn't showing the "checks" as being Cleared.

Rejoice with me!

The petite woman was about to get into her car, but she was smiling and looking at me as I walked my little dog down her street. "Good morning," I said.

"Good morning!" she replied. "I was so happy…" she began, and I wondered where this was going. "… because my dog ran away, but he came back just now. I was getting ready to go to work, and there he was!" She wiggled a bit to show me how he'd greeted her.

"That's wonderful!" I said. I knew what it felt like to lose track of a pet, or a child, and to find them again.

She went on to tell me about how the dog has run away in the past, but the tag on his collar has her phone number—this time, though, she had cut his hair and left his collar off. She spoke of her futile visit to the Humane Society, and of her other dog's despondency—he had missed his buddy. "But then there he was!" she said. She could not contain her joy.

"Congratulations!" I said. "That's a great thing." We said good-bye, and I thought of a story Jesus told nearly two thousand years ago.

⁴“Suppose one of you has a hundred sheep and loses one of them. Does he not leave the ninety-nine in the open country and go after the lost sheep until he finds it? ⁵And when he finds it, he joyfully puts it on his shoulders and goes home. Then he calls his friends and neighbors together and says, ⁶‘Rejoice with me; I have found my lost sheep.’ ⁷I tell you that in the same way there will be more rejoicing in heaven over one sinner who repents than over ninety-nine righteous persons who do not need to repent.

Luke 15:4-7

The story has two points: one is that there is rejoicing in heaven when someone repents (no, really!). Our experience of joy on earth is both an echo of our Creator's joy and a hint of future joys in heaven, even as the love I feel toward my children points to the love my heavenly father feels toward me. As Merton writes,

All nature is meant to make us think of paradise. Woods, fields, valleys, hills, the rivers and the sea, the clouds traveling across the sky, light and darkness, sun and stars, remind us that the world was created as a paradise … Heaven is even now mirrored in created things.

No Man Is an Island 6.15 (p. 115)

Heaven is indeed mirrored in created things—and not just in things we can see, but also in love and joy.

The parable has a barb: The Pharisees and teachers of the law did not rejoice when "tax collectors and sinners" were listening to Jesus and presumably repenting; hence they were no friends of heaven.

The second point, and probably the reason Jesus told the parable, is this: Friends and neighbors rejoice together. That is, if someone is happy because a lost sheep or coin (or dog) is found, friends and neighbors are the ones who rejoice with them. That is, both here and in the parable of the lost coin (Luke 15:8-10), the finder calls friends and neighbors together to celebrate.

I had a chance that morning to be a neighbor to this woman, if not a friend, by rejoicing with her. Come to think of it, I'm glad we had a chance to talk, because it reminded me of the Great Shepherd's joy, which I can share in, and of the many good gifts he gives me daily.

I want to be this guy

I've been thinking for a while about that prayer that begins, …asking God to fill you with the knowledge of his will through all spiritual wisdom and understanding. And we pray this in order that you may live a life worthy of the Lord and may please him in every way… (Colossians 1:9-10). Last night I opened Merton's No Man Is an Island more or less at random, where I found this:

If we have the Spirit of God in our hearts, we will live by His law of charity, inclined always to peace rather than dissension, to humility rather than arrogance, to obedience rather than rebellion, to purity and temperance, to simplicity and quietness and calm, to strength, generosity, and wisdom, to prudence and all-embracing justice, and we will love others more than ourselves, for it is the commandment of Jesus that we should love one another as he has loved us (John 15:12).

Thomas Merton, No Man Is an Island 4.9 (p. 61)

Now there is a picture of the kind of guy I want to be. It's not a lot different from the description of the Spirit's fruit from Galatians 5 (love, joy, peace, patience…) but the wording is fresh (some 1900 years newer). But as with the fruit of the Spirit, this sort of life is the fruit (the result) of the Spirit; that is, it's supernatural, as Merton also explains:

None of these things can be done without prayer, and we must turn to prayer first of all, not only to discover God's will but above all to gain the grace to carry it out with all the strength of our desire.

ibid.

This put me in mind of Hebrews 4, where the author tells us that

Therefore, since we have a great high priest who has passed through the heavens, Jesus, the Son of God, let us hold fast our confession. For we do not have a high priest who cannot sympathize with our weaknesses, but one who has been tested in all things as we are, yet without sin. Therefore, let us draw near with confidence to the throne of grace, that we may receive mercy and may find grace to help in time of need.

Hebrews 4:14-16

As the old hymn says, I need thee every hour, which is a great encouragement to me to pray all the time.

How death helped me focus on hope in life

Uncle Harry died on February; he was about 95. On hearing that news, his brother Gilbert, nearly 97, took a nosedive and died two weeks later.

I sat with my father at Gilbert's viewing. "Every day's a gift, isn't it?" It made me think about what I hope for my final years.

Both Harry and Gilbert had had strokes; they were wheelchair-bound and had not been in good health for some years. My aunt, their younger sister, has been losing her memory for some time. If I am fortunate enough to live to 95 or 97, what do I wish for that time?

Most likely my physical condition won't be great. Even if I don't fall 10' onto a concrete floor, as Dad has, I won't be doing 20- or 30-mile bike rides at that age. And a lot of my memory will probably be gone, too; already the kids remember lots of things I have long forgotten.

David Brinkner asks, "If you could choose just one word to describe what you want people to know about you, what would it be?" What indeed? What do you or I want people to know about us—and related to that, what kind of person do you or I want to be? Putting aside the question of what remains when our memories are gone, what kind of person do I want to be?

Other than "forty years younger", what comes to mind is that I hope to finish well. I want my life to be characerized by love, joy, peace, patience, kindness, goodness and generosity, gentleness, self-control and courage. Sound like a plan? The question is, what am I doing now about it?

One important thing is to practice some of those things.

I wrote that a year ago, and since then, my brother-in-law Danny also died. He was not much older than I am today, and I wrote about him at the time. Who am I becoming? What am I doing for others? These are much more important questions than "what's my bank balance?" or "what's my raise or bonus this year?"

Here's another good one: "What am I waiting for?" We had a great sermon the other day, where our pastor pointed out that many people in the Bible had excuses, reasons they weren't "ready" for God's call: Jeremiah was too young, Abraham was too old, Moses was a poor public speaker, and so on. God uses people who aren't ready, and who fits that description better than I?

FreeBSD 8.1 issignal() passes uninitialized ksi_flags to sigqueue_add(), causing later segfault

Note: This is a long and extremely detailed account of an esoteric problem. You have been warned.

What is it like to debug a kernel panic? Well, it’s a technical and intellectual challenge, and it’s also emotional, with the frustration of not knowing what happened, the thrill of feeling like you’ve got it licked, and the disappointment of seeing the symptom reappear after your so-called "fix."

When I’ve done this in the past, the experience could be shared only with my fellow employees, because typically the problem lay in proprietary software. On a recent occasion, though, I found a problem in FreeBSD 8.1-RELEASE; its source code is public, so at last I can share one of these with a wider audience.

My colleagues and I were running a program, maytag.Rd, under gdb, on FreeBSD virtual machines (VMs), and the kernel was panicking frequently. This meant that all programs running in that VM would stop working, and the VM would then have to be restarted. This was particularly annoying when it happened after a long sequence of operations to get the maytag into a certain state, because the maytag couldn't be resumed; all the setup operations needed repeating.

There was nothing special about the maytag; it didn't run as superuser or anything shady like that, so the frequent crashes were puzzling. It did use SIGALRM, but that shouldn't be able to crash the kernel. I kept hitting the panic, and asked my colleagues about their experience; yes, they also hit it frequently. Rather than continuing to put up with it, I decided to take a run at solving it.

The first step in debugging this problem was getting a dump of main memory. Our excellent support staff created a VM instance for me with enough disk-backed "swap" to dump primary memory, or "core," and I ran the program on that VM, under gdb. After a short while, I was rewarded with a coredump. I then ran the kernel debugger, kgdb:

NOTE: Material in the green boxes is taken verbatim from notes/updates in the software defect report.

% kgdb /boot/kernel/kernel.symbols /var/crash/vmcore.0 
GNU gdb 6.1.1 [FreeBSD]
Copyright 2004 Free Software Foundation, Inc. 
(…FSF license info elided…)

Unread portion of the kernel message buffer:


Fatal trap 12: page fault while in kernel mode
cpuid = 0; apic id = 00
fault virtual address = 0x1e
fault code  = supervisor read data, page not present
instruction pointer = 0x20:0xffffffff805a83cf
stack pointer         = 0x28:0xffffff8077025af0
frame pointer         = 0x28:0xffffff8077025b40
code segment  = base 0x0, limit 0xfffff, type 0x1b
   = DPL 0, pres 1, long 1, def32 0, gran 1
processor eflags = interrupt enabled, resume, IOPL = 0
current process  = 1418 (initial thread)
trap number  = 12
panic: page fault
cpuid = 0
Uptime: 37m21s
Physical memory: 4081 MB
Dumping 1639 MB: 1624 1608 1592 1576 1560 1544 …you get the idea… 88 72 56 40 24 8

Reading symbols from /boot/modules/vmxnet.ko...done.
Loaded symbols for /boot/modules/vmxnet.ko
Reading symbols from /boot/modules/vmmemctl.ko...done.
Loaded symbols for /boot/modules/vmmemctl.ko
#0  doadump () at pcpu.h:223
223 pcpu.h: No such file or directory.
 in pcpu.h
(kgdb) bt
#0  doadump () at pcpu.h:223
#1  0xffffffff805a4d29 in boot (howto=260)
    at /usr/src/sys/kern/kern_shutdown.c:416
#2  0xffffffff805a515c in panic (fmt=0xffffffff80964764 "%s")
    at /usr/src/sys/kern/kern_shutdown.c:590
#3  0xffffffff8088b928 in trap_fatal (frame=0xffffff0001e00000,
                                      eva=Variable "eva" is not available.)
    at /usr/src/sys/amd64/amd64/trap.c:777
#4  0xffffffff8088bcf4 in trap_pfault (frame=0xffffff8077025a40, usermode=0)
    at /usr/src/sys/amd64/amd64/trap.c:693
#5  0xffffffff8088c53a in trap (frame=0xffffff8077025a40)
    at /usr/src/sys/amd64/amd64/trap.c:451
#6  0xffffffff80871f03 in calltrap ()
    at /usr/src/sys/amd64/amd64/exception.S:223
#7  0xffffffff805a83cf in sigqueue_get (sq=0xffffff0001e00080, signo=14, 
    si=0xffffff8077025b70) at /usr/src/sys/kern/kern_sig.c:295
#8  0xffffffff805a855f in postsig (sig=14) at /usr/src/sys/kern/kern_sig.c:2717
#9  0xffffffff805e2777 in ast (framep=0xffffff8077025c80)
    at /usr/src/sys/kern/subr_trap.c:234
#10 0xffffffff80872ec9 in doreti_ast ()
    at /usr/src/sys/amd64/amd64/exception.S:633
#11 0x0000000000000002 in ?? ()
…

(Frame 11 is certainly wrong, so I elided everything after it.)

I felt pretty happy about this. I caught the system in the act of doing something really stupid. Now if I could figure out how we got to this silly place, there would be…well, if not fame and fortune exactly, at least some panic-free runs for my colleagues and me.

(bt is the gdb command to do a "backtrace". Here's what I mean by that: when some code calls a routine, the called routine usually writes a "stack frame" into memory, which has information about where the caller was, parameters, etc. A backtrace is the output that comes from tracing back through those frames. In other words, find the routine that was running, and see what routine called it, then see what routine called that, and so on. The convention in gdb is that the current frame is numbered zero; its caller is described in frame 1, and so on.)

We hit the trap while in frame 7, frame 6 being the trap marker. By the way, everybody was hitting the same trap ("Fatal trap 12: page fault while in kernel mode") at the same place (instruction pointer = 0x20:0xffffffff805a83cf). It was nice to know that I'd hit the same panic on the machine with the modified configuration. What's happening in that instruction?

0xffffffff805a83b5 <sigqueue_get+85>: mov    0x20(%r15),%rsi
0xffffffff805a83b9 <sigqueue_get+89>: test   %rsi,%rsi
0xffffffff805a83bc <sigqueue_get+92>: jne    0xffffffff805a83cf <sigqueue_get+111>
0xffffffff805a83be <sigqueue_get+94>: jmpq   0xffffffff805a848a <sigqueue_get+298>
0xffffffff805a83c3 <sigqueue_get+99>: test   %r12,%r12
0xffffffff805a83c6 <sigqueue_get+102>: mov    %r12,%rsi
0xffffffff805a83c9 <sigqueue_get+105>: je     0xffffffff805a848a <sigqueue_get+298>
0xffffffff805a83cf <sigqueue_get+111>: cmp    %r13d,0x10(%rsi)
0xffffffff805a83d3 <sigqueue_get+115>: mov    (%rsi),%rdx
0xffffffff805a83d6 <sigqueue_get+118>: mov    %rdx,%r12
0xffffffff805a83d9 <sigqueue_get+121>: jne    0xffffffff805a83c3 <sigqueue_get+99>
0xffffffff805a83db <sigqueue_get+123>: test   %r14d,%r14d
0xffffffff805a83de <sigqueue_get+126>: jne    0xffffffff805a8466 <sigqueue_get+262>
…
(kgdb) info reg
rax            0x0 0
rbx            0xffffff8077025b70 -547759170704
rcx            0xffffff0001e72860 -1099479701408
rdx            0xe 14
rsi            0xe 14
rdi            0xffffff00018542a0 -1099486117216
rbp            0xffffff8077025b40 0xffffff8077025b40
rsp            0xffffff8077025b00 0xffffff8077025b00
r8             0x0 0
r9             0x2000 8192
r10            0x0 0
r11            0x0 0
r12            0xe 14
r13            0xe 14
r14            0x1 1
r15            0xffffff0001e00080 -1099480170368
rip            0xffffffff805a83cf 0xffffffff805a83cf <sigqueue_get+111>

(Note: To get the list of assembly instructions above, I typed "disass sigqueue_get"; "info reg" means "show me the registers." Assembly instructions can be decrypted by looking at a document downloadable from Intel. For those who aren't sure about the direction of Intel instructions, gdb seems to print them with "left-to-right" semantics—e.g., "mov %r12,%rsi" means "copy the contents of %r12 into %rsi.")

So we seem to be comparing the contents of %r13d vs. the memory located at (%rsi+0x10), highlighted like this; since %rsi has 0xe, we'd expect the faulting address to be 0x1e, as indeed it is (search backward for "fault virtual address"). That's the smoking gun, and it's always nice to see that the machine is consistent with itself, even in crashes. That was progress, but not nearly enough. What are we doing there? The backtrace says we're at line 295:

(kgdb) f 7
#7  0xffffffff805a83cf in sigqueue_get (sq=0xffffff0001e00080, signo=14, 
    si=0xffffff8077025b70) at /usr/src/sys/kern/kern_sig.c:295
295  TAILQ_FOREACH_SAFE(ksi, &sq->sq_list, ksi_link, next) {
(kgdb) ptype sq->sq_list
type = struct {
    struct ksiginfo *tqh_first;
    struct ksiginfo **tqh_last;
}
(kgdb) x/2xg &sq->sq_list
0xffffff0001e000a0: 0xffffff8077025b80 0xffffff8077025b80

I thought this was weird, since tqh_last is supposed to be pointer-to-pointer. (Actually, my intuition was completely wrong about that; in this particular queue, it's perfectly OK for them to have the same value.) More to the point, though, this piece of memory doesn't look like a struct ksiginfo:

(kgdb) x/16xg 0xffffff8077025b80
0xffffff8077025b80: 0x000000000000000e 0x0000000000010006
0xffffff8077025b90: 0x0000000000000000 0x0000000000000000
0xffffff8077025ba0: 0x0000000000000000 0x0000000000000000
0xffffff8077025bb0: 0x0000000000000000 0x0000000000000000
0xffffff8077025bc0: 0x0000000000000000 0x0000000000000000
0xffffff8077025bd0: 0x0000000000000000 0x0000000000000000
0xffffff8077025be0: 0x0000000000000010 0x0000000000000246
0xffffff8077025bf0: 0x0000000000002000 0x0000000000000000
(kgdb) p *sq->sq_list.tqh_first
$8 = {ksi_link = {tqe_next = 0xe, tqe_prev = 0x10006}, ksi_info = {
    si_signo = 0, si_errno = 0, si_code = 0, si_pid = 0, si_uid = 0, 
    si_status = 0, si_addr = 0x0, si_value = {sival_int = 0, sival_ptr = 0x0, 
      sigval_int = 0, sigval_ptr = 0x0}, _reason = {_fault = {_trapno = 0}, 
      _timer = {_timerid = 0, _overrun = 0}, _mesgq = {_mqd = 0}, _poll = {
        _band = 0}, __spare__ = {__spare1__ = 0, __spare2__ = {0, 0, 0, 0, 0, 
          0, 0}}}}, ksi_flags = 16, ksi_sigq = 0x246}
(kgdb) 

When I saw this, I was pretty unhappy. It looked like the whole structure was trashed, not just one part of it. How was I going to figure this out?

Clearly 0xffffff8077025b80 was a bad pointer, or perhaps memory there got corrupted. I needed to see how we got into this mess.

(kgdb) p count
$10 = 1
(kgdb) l sigqueue_get
278 static int
279 sigqueue_get(sigqueue_t *sq, int signo, ksiginfo_t *si)
280 {
281  struct proc *p = sq->sq_proc;
282  struct ksiginfo *ksi, *next;
283  int count = 0;
284 
…
290  if (SIGISMEMBER(sq->sq_kill, signo)) {
291   count++;
292   SIGDELSET(sq->sq_kill, signo);
293  }
294 
295  TAILQ_FOREACH_SAFE(ksi, &sq->sq_list, ksi_link, next) {
296   if (ksi->ksi_signo == signo) {
297    if (count == 0) {
298     TAILQ_REMOVE(&sq->sq_list, ksi, ksi_link);
299     ksi->ksi_sigq = NULL;
300     ksiginfo_copy(ksi, si);
301     if (ksiginfo_tryfree(ksi) && p != NULL)
302      p->p_pendingcnt--;
303    }
304    if (++count > 1)
305     break;
306   }
307  }
count=1 (assuming gdb is telling the truth) says that either:
1. we ran 291; or
2. we ran 297-303 once, removing an element from the queue;
    then we bumped count in 304.  That's how we panicked 
    2nd time around in 295.

I reject #1 because the queue is plainly not what it was when we entered.

Why did I think I knew this? Because if it had been, we would have panicked the first time through, or so I thought. Was I right? I suppose so; some hours later I was sure that we executed line 300.

Now when we entered, we had si==0xffffff8077025b70 I guess.
At that time we would have assigned ksi to... umm, that value?
(kgdb) p *si
$16 = {ksi_link = {tqe_next = 0x0, tqe_prev = 0x0}, ksi_info = {si_signo = 14, 
    si_errno = 0, si_code = 65542, si_pid = 0, si_uid = 0, si_status = 0, 
    si_addr = 0x0, si_value = {sival_int = 0, sival_ptr = 0x0, sigval_int = 0, 
      sigval_ptr = 0x0}, _reason = {_fault = {_trapno = 0}, _timer = {
        _timerid = 0, _overrun = 0}, _mesgq = {_mqd = 0}, _poll = {_band = 0}, 
      __spare__ = {__spare1__ = 0, __spare2__ = {0, 0, 0, 0, 0, 0, 0}}}}, 
  ksi_flags = 0, ksi_sigq = 0x0}

Now THAT looks completely reasonable.

But somehow we ended up like this??
(kgdb) p sq->sq_list
$15 = {tqh_first = 0xffffff8077025b80, tqh_last = 0xffffff8077025b80}

At this point I was completely stumped. I hadn't yet noticed that 0xffffff8077025b80 was exactly si+0x10 (i.e., a location inside *si), so I concocted a bunch of theories about how si->ksi_link.tqe_next might have been 0xffffff8077025b80, etc.

The above came from a report filed at 12:46pm Monday; within eleven minutes, I had looked at the caller, in frame 8 of the backtrace.

(kgdb) up
#8  0xffffffff805a855f in postsig (sig=14) at /usr/src/sys/kern/kern_sig.c:2717
2717  if (sigqueue_get(&td->td_sigqueue, sig, &ksi) == 0 &&

2700 int
2701 postsig(sig)
2702     register int sig;
2703 {
2704     struct thread *td = curthread;
2705     register struct proc *p = td->td_proc;
2706     struct sigacts *ps;
2707     sig_t action;
2708     ksiginfo_t ksi;
2709     sigset_t returnmask, mask;
2710 
2711     KASSERT(sig != 0, ("postsig"));
2712 
2713     PROC_LOCK_ASSERT(p, MA_OWNED);
2714     ps = p->p_sigacts;
2715     mtx_assert(&ps->ps_mtx, MA_OWNED);
2716     ksiginfo_init(&ksi);
2717     if (sigqueue_get(&td->td_sigqueue, sig, &ksi) == 0 &&
2718         sigqueue_get(&p->p_sigqueue, sig, &ksi) == 0)
2719         return (0);
"/usr/src/sys/kern/kern_sig.c" [readonly]

The thing I observed here was that ksi was on-stack. It was, in fact, at the address noted earlier (0xffffff8077025b70). Somebody must have added an on-stack element some time earlier, I thought. But I was at a loss as to how that could have happened.

It would be another two hours before I noticed this; at 2:56pm I updated the report:

 340 static int
 341 sigqueue_add(sigqueue_t *sq, int signo, ksiginfo_t *si)
 342 {
…
 354     /* directly insert the ksi, don't copy it */
 355     if (si->ksi_flags & KSI_INS) {
 356         if (si->ksi_flags & KSI_HEAD)
 357             TAILQ_INSERT_HEAD(&sq->sq_list, si, ksi_link);
 358         else
 359             TAILQ_INSERT_TAIL(&sq->sq_list, si, ksi_link);
 360         si->ksi_sigq = sq;
 361         goto out_set_bit;
 362     }

The key thing here is that we would insert the element only if KSI_INS is set in ksi_flags. I suspected at this time that KSI_INS might have been set erroneously. Quoting from the report:

sigqueue_add() is called by tdsignal() and issignal().

Sure enough, issignal() has an on-stack ksi whose flags are not initialized.

2490 static int
2491 issignal(struct thread *td, int stop_allowed)
2492 {
2493         struct proc *p;
2494         struct sigacts *ps;
2495         struct sigqueue *queue;
2496         sigset_t sigpending;
2497         ksiginfo_t ksi;
...
2570                                 if (ksi.ksi_signo != 0) {
2571                                         ksi.ksi_flags |= KSI_HEAD;
2572                                         if (sigqueue_add(&td->td_sigqueue, sig,
2573                                             &ksi) != 0)
2574                                                 ksi.ksi_signo = 0;
2575                                 }
2576                                 if (ksi.ksi_signo == 0)
2577                                         sigqueue_add(&td->td_sigqueue, sig,
2578                                             NULL);

Nothing modifies ksi.ksi_flags between 2497 and 2570. That's an invitation to disaster, because whatever random value happens to be in ksi_flags is the value that will be interpreted by the callee. In particular, though line 2570 sets the KSI_HEAD bit, we have no idea whether any other bit is set.

Half an hour later, I decided that was wrong—at 3:25pm I posted this:

NEVERMIND --- if we get to 2572 it means ksi_signo is nonzero,
which means we must have done 2541 and maybe 2543:

2540             ksi.ksi_signo = 0;
2541             if (sigqueue_get(queue, sig, &ksi) == 0) {
2542                 queue = &p->p_sigqueue;
2543                 sigqueue_get(queue, sig, &ksi);
2544             } 

sigqueue_get() always zaps the flags (killing KSI_INS) if setting
ksi_signo.

static __inline void
ksiginfo_copy(ksiginfo_t *src, ksiginfo_t *dst)
{
        (dst)->ksi_info = src->ksi_info;
        (dst)->ksi_flags = (src->ksi_flags & KSI_COPYMASK);
} 

Another 90 minutes later, about 5:00pm, I decided I was wrong yet again:

Dang, that's not quite true.  sigqueue_get() can update ksi_signo
without updating ksi_flags.

I think if one does a sigqueue_add(sq, SIGALRM, NULL);
then we'll SIGADDSET(sq->sq_kill, SIGALRM) then 
SIGADDSET(sq->sq_signals, SIGALRM) then return 0. 

Much as I'd like to tell you that the process is orderly and methodical, proceeding from what's known to what's unknown through a sequence of logical steps, the truth is that it usually starts with some observations, followed by some hypotheses. The hypotheses are investigated, but at various points, important details go unnoticed; tentative conclusions are then reversed, and so on. So it was in this case.

My 5pm update continued:

Now the maytag.Rd process is traced, which means we could enter this part of
issignal():

2505         int traced = (p->p_flag & P_TRACED) || (p->p_stops & S_SIG);
...
2532         if (p->p_flag & P_TRACED && (p->p_flag & P_PPWAIT) == 0) {
2533             /*
2534              * If traced, always stop.
2535              * Remove old signal from queue before the stop.
2536              * XXX shrug off debugger, it causes siginfo to
2537              * be thrown away.
2538              */
2539             queue = &td->td_sigqueue;
2540             ksi.ksi_signo = 0;
2541             if (sigqueue_get(queue, sig, &ksi) == 0) {
2542                 queue = &p->p_sigqueue;
2543                 sigqueue_get(queue, sig, &ksi);
2544             }
...
2565                 sigqueue_add(queue, sig, NULL);
2566                 if (SIGISMEMBER(td->td_sigmask, sig))
2567                     continue;
2568                 signotify(td);

The sigqueue_get() might not find anything in
the queue, but just find the bit set.

(kgdb) p/x p->p_flag
$2 = 0x10004882
566 #define P_CONTROLT  0x00002 /* Has a controlling terminal. */
572 #define P_HADTHREADS    0x00080 /* Has had threads (no cleanup shortcuts) */
576 #define P_TRACED    0x00800 /* Debugged process being traced. */
579 #define P_EXEC      0x04000 /* Process called exec. */
593 #define P_INMEM     0x10000000 /* Loaded into memory. */

What that last part means is that sure enough, P_TRACED is set but P_PPWAIT is clear, so we likely did enter the block starting at 2539.

At this point, i.e., at 5pm Monday, I had only a rough idea of how everything happened, but I felt quite sure that the bad code in issignal() (that is, random bits in ksi->ksi_flags) had something to do with it. It was easy enough to create a kernel modified as follows:

 2540             ksi.ksi_signo = 0;
 2540             ksiginfo_init(&ksi);

I ran some experiments and proved that this change made the symptom go away. So here's where I was at that point:

• I'd found some code that was definitely bad;
• I had a plausible explanation, albeit an incomplete one, for how that bad code might have resulted in an on-stack ksiginfo_t to be added to the current thread's queue (and thus caused the panic);
• I had devised a fix and tried it. The symptom, which I formerly could reproduce at will, disappeared convincingly after the aforementioned bad code was corrected.

In other words, I was done.

---

Looking at all of this today, though, over 1½ years later, I was somewhat more anxious to work out a more complete explanation of the original problem. Here's today's shot at it: The problem happens because issignal() erroneously adds an on-stack structure to a thread's td_sigqueue, then returns. Shortly afterward, postsig() is called, which called sigqueue_get(); the latter routine copied one siginfo_t into postsig()'s local variable, corrupting the bogus siginfo_t enqueued by issignal(). In particular, ksi_link.tqe_next was corrupted, causing a queue-scanning loop to dereference an invalid pointer and panicking the box. Specifically:

1. ast() calls cursig() (which in turn calls issignal()), then postsig(), in rapid succession:

       229         if (flags & TDF_NEEDSIGCHK || p->p_pendingcnt > 0 ||
       230             !SIGISEMPTY(p->p_siglist)) {
       231                 PROC_LOCK(p);
       232                 mtx_lock(&p->p_sigacts->ps_mtx);
       233                 while ((sig = cursig(td, SIG_STOP_ALLOWED)) != 0)
       234                         postsig(sig);
       235                 mtx_unlock(&p->p_sigacts->ps_mtx);
       236                 PROC_UNLOCK(p);
       237         }

2. issignal() calls sigqueue_get(), passing its ksi struct with its uninitialized (random) flags. The KSI_INS flag happens to be unintentionally set to 1.

   Now, sigqueue_get() may set si->ksi_signo (parameter si, i.e., issignal()'s local variable ksi), without touching anything else in the struct—that is, leaving ksi.ksi_flags with random bits set.

   Which signal was it? I'm not sure. I was going to say something other than SIGALRM (maybe SIGTRAP?) but I didn't look that far because I was hot on the trail—or so I hoped!

3. The trap (sorry) is now set: we have ksi.ksi_signo nonzero. By the way, I believe sq->sq_list had one other element on it, an element whose address we no longer have. Probably that element was the SIGALRM (14 or 0xe).

   Now we execute 2570-2573 in issignal():

      2550                         if (sig != newsig) {
   ...
      2569                         } else {
      2570                                 if (ksi.ksi_signo != 0) {
      2571                                         ksi.ksi_flags |= KSI_HEAD;
      2572                                         if (sigqueue_add(&td->td_sigqueue, sig,
      2573                                             &ksi) != 0)
      2574                                                 ksi.ksi_signo = 0;
      2575                                 }

   Now sigqueue_add() will oblige us by... well, you can see it:

       340 static int
       341 sigqueue_add(sigqueue_t *sq, int signo, ksiginfo_t *si)
       342 {
   ...
       354         /* directly insert the ksi, don't copy it */
       355         if (si->ksi_flags & KSI_INS) {
       356                 if (si->ksi_flags & KSI_HEAD)
       357                         TAILQ_INSERT_HEAD(&sq->sq_list, si, ksi_link);
       358                 else
       359                         TAILQ_INSERT_TAIL(&sq->sq_list, si, ksi_link);
       360                 si->ksi_sigq = sq;

   In particular, ksi (the local variable of issignal()) could very well have been at 0xffffff8077025b80.
4. As noted in step 1 above, ast() soon calls postsig(14); which in turn calls sigqueue_get(&td->td_sigqueue, sig, &ksi), where ksi was located at 0xffffff8077025b70. sigqueue_get() I guess did the following:
   1. examined sq->sq_kill (line 290) and concluded we didn't have a match; thus skipped 291;
   2. at 295–296, found the first element, which matched;
   3. with count==0, executed 298 to remove this element from the list, and crucially 300, copying the contents of the mystery element into the struct pointed to by (parameter) si; in doing this, we overwrote whatever had been at 0xffffff8077025b80

       290         if (SIGISMEMBER(sq->sq_kill, signo)) {
       291                 count++;
       292                 SIGDELSET(sq->sq_kill, signo);
       293         }
       294  
       295         TAILQ_FOREACH_SAFE(ksi, &sq->sq_list, ksi_link, next) {
       296                 if (ksi->ksi_signo == signo) {
       297                         if (count == 0) {
       298                                 TAILQ_REMOVE(&sq->sq_list, ksi, ksi_link);
       299                                 ksi->ksi_sigq = NULL;
       300                                 ksiginfo_copy(ksi, si);
       301                                 if (ksiginfo_tryfree(ksi) && p != NULL)
       302                                         p->p_pendingcnt--;
       303                         }
       304                         if (++count > 1)
       305                                 break;
       306                 }
       307         }

5. We continued to 304 and incremented count, then looped around to returned to 295 in sigqueue_get().
6. Still in sigqueue_get(), we went to the next element in the queue (which we knew from before was 0xffffff8077025b80) and repeated the test of line 296. This failed because si_signo didn't match:

   $8 = {ksi_link = {tqe_next = 0xe, tqe_prev = 0x10006}, ksi_info = {
           si_signo = 0, si_errno = 0, si_code = 0, si_pid = 0, si_uid = 0, 
           si_status = 0, si_addr = 0x0, si_value = {sival_int = 0, sival_ptr = 0x0, 
             sigval_int = 0, sigval_ptr = 0x0}, _reason = {_fault = {_trapno = 0}, 
             _timer = {_timerid = 0, _overrun = 0}, _mesgq = {_mqd = 0}, _poll = {
               _band = 0}, __spare__ = {__spare1__ = 0, __spare2__ = {0, 0, 0, 0, 0, 
                 0, 0}}}}, ksi_flags = 16, ksi_sigq = 0x246}

   so we went to the next element in the queue.
7. But of course, ksi_link.tqe_next has been corrupted, and so when we try to load ksi->ksi_signo, we get the segfault.

One thing remains unexplained: In issignal(), we have to execute 2572–2573 I think, so that sigqueue_add() gets called with the address of (local variable) ksi. However, to get there, we must have executed 2571, which would force the new element (the one I think was incorrectly inserted) to be inserted at the head of the queue (sigqueue_add() lines 356–357 above).

Perhaps the bad element was inserted some time ago, and we're only now corrupting the queue? Or we did two of them, one after another, with the good one... second? I'm not quite sure, but I think we've gotten a little further than I had in 2012. Has this been debugged enough? Well, in one sense it was debugged enough in 2012: I saw bad code, I had a plausible if incomplete explanation of how it could have caused the symptom, and so on. If I had to stand in front of a classroom and explain that this is absolutely what happened, I couldn't give a complete explanation.

We could go further—for example, we could look at the stack frame sizes and local variable layouts for issignal() and sigqueue_get() to see if they're consistent with the idea that ksi in one routine could be 0x10 bytes from ksi in the other. But I think you've got the idea, and this post is too long already.

Saved—from what?

Evangelicals—at least evangelicals in the ’60s and ’70s—were fond of asking, "Are you saved?" They would probably be perplexed at this 2010 comment from Barbara Brown Taylor: “The problem is, many of the people in need of saving are in churches, and at least part of what they need saving from is the idea that God sees the world the same way they do” (from An Altar in the World: A Geography of Faith).

I saw this quote a year or two ago on the big screen at church. It was provocative then, and I remembered it recently when thinking about Colossians 2, which says that man-made rules—“Do not handle! Do not taste! Do not touch!” (2:20)—lack any value in restraining sensual indulgence (2:23). The passage brought up for me the question of what it means to be saved. Why? Because it suggests that we at least need saving from sensual indulgence. And Taylor's remark makes me wonder, what should we talk about, when we talk about being saved?

The Apostle Paul writes that we were once "foolish, disobedient, led astray, slaves to various passions and pleasures, spending our days in malice and envy…" (Titus 3) but that God saved us by his goodness and mercy. He also writes that God has saved us from the power of darkness (Colossians 1:13) and brought us into the kingdom of his dear son. In 2 Timothy 1, Ephesians 2 and elsewhere, Paul writes again and again of salvation as an accomplished fact.

But Paul also writes that Jesus saves us from the wrath to come (1 Thessalonians 1:10); he says that God "will rescue me from this body of death" (Romans 7:24–25), and that we eagerly await the redemption of our bodies (8:23–25). All this is about the future. Indeed, the Lord Jesus Christ himself said, "He who stands firm to the end will be saved." (Matthew 24). And in 2 Corinthians 3:18, we read that we are being transformed into his (Christ's) likeness with ever-inceasing glory, which is something that continues throughout our lives here on earth. Which brings me to Colossians 1:9-12:

⁹For this reason, since the day we heard about you, we have not stopped praying for you and asking God to fill you with the knowledge of his will through all spiritual wisdom and understanding. ¹⁰And we pray this in order that you may live a life worthy of the Lord and may please him in every way: bearing fruit in every good work, growing in the knowledge of God, ¹¹being strengthened with all power according to his glorious might so that you may have great endurance and patience, and joyfully ¹²giving thanks to the Father, who has qualified you to share in the inheritance of the saints in the kingdom of light.

Colossians 1:9-12 NIV

Now there's a picture of a good life: fruitful in good works, knowing God more and more, and so on. Something I notice about this passage is that Paul doesn't simply say: "Live this way"; rather, he prays for God to do something to make the God-pleasing life even possible.

What that tells me is that this kind of life isn't just difficult; without help from God it's impossible. Put differently, we need to be saved from the life of ignorance of God's will, the life of folly and fruitlessness, of distraction and impatience—the joyless life of the spoiled and entitled child.

Besides all that, I also need to be saved from my foolish impulses and tendencies. It is true that the fruit of the Spirit (Galatians 5) includes "self-control" (other versions say "sober-mindedness" and the like), but the promise around temptation is that God will provide a way of escape (1 Corinthians 10:13). This suggests that our self-control is limited, that willpower is overrated.

But I need more than just a way of escape when tempted, more than just protection from doing something stupid. What I need is to be transformed, to be changed. I want to be the kind of person who isn't tempted in the first place. I want my mind and heart to be filled with the knowledge of God's will so that I naturally give my heart to heavenly things (Colossians 3:1–2).

Returning to Colossians 2:23 and the need for restraining sensual indulgence, I think Paul is telling us that sensual indulgence isn't just some activity we do or don't do; rather, it's a force that, if unrestrained, will halt our spiritual growth so that we remain children permanently, infants tossed back and forth by the waves, and blown here and there by every wind of teaching and by the cunning and craftiness of men in their deceitful scheming (Ephesians 4:14). We need to be saved from these waves and winds.

And do we sit by idly while being saved from these things? A better idea would be to follow Paul's example and press on toward the goal to win the prize for which God has called me heavenward (Philippians 3:14). And, as the author of Hebrews tells us, to

…throw off everything that hinders and the sin that so easily entangles, and…run with perseverance the race marked out for us. ²Let us fix our eyes on Jesus, the author and perfecter of our faith, who for the joy set before him endured the cross, scorning its shame, and sat down at the right hand of the throne of God. ³Consider him who endured such opposition from sinful men, so that you will not grow weary and lose heart.

from Hebrews 12:1-3

Paul gives us a terrific encouragement along these lines, from Philippians: “[W]ork out your salvation with fear and trembling, for it is God who works in you to will and to act according to his good purpose” (from Philippians 2:12–13). In other words, as we press on toward the goal, as we throw off everything that hinders and run with perseverance, God works in us to want to keep going, as he also saves us from the useless life we might otherwise live.

Being strengthened with all power…

[continued from my earlier post]

Colossians 1:9-12 says that as we are filled with the knowledge of God's will, among other things, we'll be strengthened with all power according to his glorious might so that we may have great endurance and patience.

One thing I've noticed about this is the purpose for all this strength. Paul doesn't pray that we can be strengthened with all power (etc.) so that we can perform miracles, or win thousands of souls to Christ, or some other spectacular thing. No, his prayer is that we can be strengthened with all power so that we can have great endurance and patience. It reminds me that He who is slow to anger is better than the mighty, and he who rules his spirit than he who captures a city (Proverbs 16:32).

Paul prays that for the Colossians (and hence I think it's a good prayer for you and me); how does it happen? How does being filled with the knowledge of God's will give us strength to have great endurance and patience?

Paul also wrote about this in 2 Corinthians 4. After describing some issues (hard pressed on every side… persecuted… struck down, 4:8-9) he writes:

Therefore we do not lose heart. Though outwardly we are wasting away, yet inwardly we are being renewed day by day. For our light and momentary troubles are achieving for us an eternal glory that far outweighs them all. So we fix our eyes not on what is seen, but on what is unseen. For what is seen is temporary, but what is unseen is eternal.

2 Corinthians 4:15-18, NIV

Two passages come to mind right away: one from Paul, in Romans chapter 5:

¹Therefore, since we have been justified through faith, we have peace with God through our Lord Jesus Christ, ²through whom we have gained access by faith into this grace in which we now stand. And we rejoice in the hope of the glory of God. ³ Not only so, but we also rejoice in our sufferings, because we know that suffering produces perseverance; ⁴perseverance, character; and character, hope. ⁵And hope does not disappoint us, because God has poured out his love into our hearts by the Holy Spirit, whom he has given us.

Romans 5:1-4

If I could consistently rejoice in suffering, then I'd have more endurance and patience than I do today. But how can I rejoice in suffering?

In my admittedly limited experience, it works like this: As the verse says, God desires to use suffering to produce perseverance, character and hope in my life. When I remember this fact, trials become more bearable. The sooner I remember it, the gladder I am that God is working through whatever suffering comes.

What if I were filled with the knowledge of God's will? What if I woke to and ate and lived and breathed the knowledge that God is using everything in my life—the pleasant and the painful, the joyous and the tragic—to make me a better person, one filled with character and hope and love and joy and peace…? Might I be able to rejoice even in the midst of suffering?

I don't really desire suffering. But when it comes, I want to see the good things God will work in my life through it. And perhaps to rejoice.

The second passage that came to mind is from James 1. After encouraging us to consider it all joy when we meet various trials (1:2) and encouraging us in much the same direction Paul does, he writes: Blessed is the man who perseveres under trial, for when he has stood the test he will receive the crown of life that God has promised to those who love him (1:12).

I find this fascinating. The one who perseveres under trial receives a crown promised to those who… who persevere under trial, right? No, the text says "…to those who love him." In other words, those who love God are the ones who persevere under trial. How does that work?

I can't prove it, but Jesus himself may have given us the answer in John 14. Here Jesus says those who obey him are those who love him. And, he says, "He who loves me will be loved by my father, and I will love him and disclose myself to him" (from John 14:21, NASB). A little later, he goes on to say, "If anyone loves me… [m]y father will love him, and we will come to him and make our home with him" (14:23, NIV). The whole paragraph is worth reading, actually.

But what I think he's saying is this: he fills us with the knowledge of his will. We don't resist him (1 Thessalonians 5:19) and indeed we ask for spiritual wisdom (James 1:5). We love and obey him (John 14:21-23) and he reveals more of himself to us and even makes his home in us.

And that's power to strengthen us according to his glorious might, so that we can have great endurance and patience.

A life worthy of the Lord—part 2

[continued from my earlier post]

Thinking about Colossians 1:9-12 and what it means to live a life worthy of the Lord and to please him in every way, I mused on the question of how we grow in the knowledge of God. Various teachers say that knowing God is different from knowing about God. Could we say that knowing about God is kind of superficial? Maybe we'd say that knowing about God would imply the ability to list a bunch of adjectives: eternal, all-knowing, etc., whereas knowing God himself implies knowing what kinds of things he does and doesn't do, what he likes and dislikes, what he cares about and so on.

If that's a helpful distinction, I suppose the latter is more relevant. Would it please God if I had a clear understanding of what he would and wouldn't do, what he cares about, what he likes and such? The short answer would be "yes," and it's not hard to find passages in the Bible that support this. Jeremiah 9:23–24 for example—let not the wise man boast of his wisdom (etc.) but let him who boasts boast … that he understands and knows me, that I am the Lord who exercises kindness, justice and righteousness on earth, for in these things I delight.

And Jeremiah 31:34—I was going to just give you a link, but I just saw something that's got me so excited that I want to give you the text here. Look at the last verse (34):

³¹“The time is coming,” declares the Lord, “when I will make a new covenant with the house of Israel and with the house of Judah. ³²It will not be like the covenant I made with their forefathers when I took them by the hand to lead them out of Egypt, because they broke my covenant, though I was a husband to them,” declares the Lord. ³³“This is the covenant I will make with the house of Israel after that time,” declares the Lord. “I will put my law in their minds and write it on their hearts. I will be their God, and they will be my people. ³⁴No longer will a man teach his neighbor, or a man his brother, saying, ‘Know the Lord,’ because they will all know me, from the least of them to the greatest,” declares the Lord. “For I will forgive their wickedness and will remember their sins no more.”

Jeremiah 31:31-34 (NIV)

Do you see it? What is it that makes it possible for them (or us) to know the Lord? He doesn't say "They will all know me… for they will reach that place in their cultural and intellectual evolution…" Nor does he say, "for they will finally decide to provide universal education." They (or we) will all know him, “For I will forgive their wickedness and will remember their sins no more.”

How does that work? He forgives his people and somehow they automatically know him? I think something else is probably involved. Prophets often speak elliptically and this is no exception. This reminded me of the time Jesus visited the home of Simon the Pharisee (Luke 7:36-50), where he explains that people love much when they're forgiven much, but “he who has been forgiven little loves little.”

As even a casual reading of Matthew 5 will show, every one of us stands in much need of forgiveness, because we sin in various (numerous) ways: we're angry unreasonably (5:22), we nurse inappropriate desires (5:28), we divorce each other (5:32), we ignore the poor (5:42), we don't love our enemies (5:44). If all our sins are forgiven, then much has been forgiven. So what does Jesus mean in Luke 7:47?

I think it's this: the more I understand just how much I've been forgiven, the more I'll love and know God. I find it fascinating that when God talks about knowing him, the first thing he talks about is knowing his great mercy: did you notice the order of attributes the Lord uses when he talks about himself in Jeremiah 9:24 above? … that I am the Lord, who exercises kindness, justice and righteousness on earth, for in these I delight,” declares the Lord. Note the first word: kindness. This is the way God identifies himself throughout the Bible in the overwhelming majority of cases.

The so-called “sinful woman” in Luke 7:37 knew that her sin was great, and when she experienced forgiveness she knew that the forgiveness was great: she knew something about God's kindness and mercy that Simon the Pharisee did not.

Two more things on this topic, both from this weekend as it turns out: first, the sermon recounted a conversation Moses had with the Lord in Exodus 33:18-19. Moses says, “Now show me your glory,” and the Lord replies, “I will cause all my goodness to pass in front of you”—I find this remarkable. His glory, he says, is shown in his goodness. The very next thing he says is, “I will proclaim my name… in your presence. I will have mercy on whom I will have mercy…” Again: goodness and mercy are the first things he talks about.

The second thing from this weekend is that we had someone come to our church and say he wanted to follow Jesus. Why did he decide to follow Jesus? Because he understood that Jesus was kind.

So: one way—not the only way, but an important way—we grow in our knowledge of God is by remembering and thinking about his kindness and goodness and mercy. Of course the Lord has other attributes; as we read in Jeremiah 9, he “exercises kindness, justice and righteousness,” and he has many other attributes. But kindness first.