Fix handling contents added after header creation

[elbe0046]

If additional contents have been appended to a file after the Header is created but before the file contents are written to the archive the archive can become corrupted.

Such that a tar -tf on the resulting archive reveals the following errors:

OS X

bugreport-3011000408-20220302_222509/logs/hubCoreLog
tar: Damaged tar archive
tar: Retrying...

Linux

bugreport-3011000408-20220303_011636/logs/hubCoreLog
tar: Skipping to next header

Criteria for likelihood of encountering the issue

The closer a process gets to spamming to their log file the more likely this issue is to occur (e.g. hubCore, ncpHost will be top contenders).

Hubs which have a lot of devices, behaviors, drivers, etc. will as a result be more likely to hit this.

Increasing log levels obviously contributes to this.

Inspection of a corrupt archive

Upon inspecting the corrupted archive we see that:

• the header for hubCoreLog starts at 0x0032c400

0032c400  62 75 67 72 65 70 6f 72  74 2d 33 30 31 31 30 30  |bugreport-301100|
0032c410  30 34 30 38 2d 32 30 32  32 30 33 30 32 5f 32 32  |0408-20220302_22|
0032c420  32 35 30 39 2f 6c 6f 67  73 2f 68 75 62 43 6f 72  |2509/logs/hubCor|
0032c430  65 4c 6f 67 00 00 00 00  00 00 00 00 00 00 00 00  |eLog............|
0032c440  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
0032c450  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
0032c460  00 00 00 00 30 31 30 30  36 34 34 00 30 30 30 30  |....0100644.0000|
0032c470  30 30 30 00 30 30 30 30  30 30 30 00 30 30 30 30  |000.0000000.0000|
0032c480  37 31 31 34 34 33 33 00  31 34 32 30 37 37 36 37  |7114433.14207767|
0032c490  33 31 32 00 30 30 31 36  37 33 35 00 30 00 00 00  |312.0016735.0...|

• hubCoreLog file size in octal is 07114433 == 0x1C991B. So the next record should start at 0x4F5E00 (because this calculation is rounded up to the nearest 512 byte alignment).

0032c47c  30 30 30 30 37 31 31 34  34 33 33 00              |00007114433.|

• And yet we see that the hubCoreLog entry exceeds what the header specifies

00526930  20 54 20 7c 20 68 32 20  20 20 20 20 20 20 20 20  | T | h2         |
00526940  7c 20 2d 2d 20 43 6f 6e  6e 65 63 74 69 6f 6e 0a  || -- Connection.|
00526950  32 30 32 32 2d 30 33 2d  30 32 5f 32 32 3a 32 35  |2022-03-02_22:25|
00526960  3a 31 38 2e 37 32 30 20  7c 20 54 20 7c 20 7a 62  |:18.720 | T | zb|
00526970  2e 68 61 6c 20 20 20 20  20 7c 20 48 41 4c 20 77  |.hal     | HAL w|
00526980  72 6f 74 65 20 34 36 20  62 79 74 65 73 3a 20 44  |rote 46 bytes: D|
00526990  31 20 43 35 20 30 30 20  32 45 20 30 30 20 30 38  |1 C5 00 2E 00 08|
005269a0  20 43 36 20 43 35 20 31  37 20 43 35 20 30 30 20  | C6 C5 17 C5 00 |
005269b0  31 36 20 30 36 20 30 30  20 30 30 20 30 30 20 30  |16 06 00 00 00 0|
005269c0  30 20 30 30 20 30 30 20  30 30 20 30 30 20 30 30  |0 00 00 00 00 00|
005269d0  20 30 30 20 30 30 20 30  30 20 30 30 20 30 30 20  | 00 00 00 00 00 |
005269e0  30 30 20 30 30 20 30 30  20 30 30 20 30 30 20 30  |00 00 00 00 00 0|
005269f0  30 20 30 31 20 30 41 20  39 41 20 30 31 20 30 34  |0 01 0A 9A 01 04|
00526a00  20 30 31 20 30 30 20 30  35 20 30 30 20 30 30 20  | 01 00 05 00 00 |
00526a10  30 30 20 30 32 20 30 30  20 0a 00 00 00 00 00 00  |00 02 00 .......|
00526a20  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00526a30  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00526a40  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00526a50  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00526a60  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00526a70  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00526a80  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00526a90  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00526aa0  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00526ab0  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00526ac0  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00526ad0  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00526ae0  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00526af0  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00526b00  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00526b10  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00526b20  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00526b30  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00526b40  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00526b50  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00526b60  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00526b70  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00526b80  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00526b90  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00526ba0  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00526bb0  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00526bc0  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00526bd0  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00526be0  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00526bf0  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00526c00  62 75 67 72 65 70 6f 72  74 2d 33 30 31 31 30 30  |bugreport-301100|
00526c10  30 34 30 38 2d 32 30 32  32 30 33 30 32 5f 32 32  |0408-20220302_22|
00526c20  32 35 30 39 2f 6c 6f 67  73 2f 63 6f 6e 6e 6d 61  |2509/logs/connma|
00526c30  6e 2e 6c 6f 67 00 00 00  00 00 00 00 00 00 00 00  |n.log...........|

Proposed solution

To solve the issue we limit the amount of data that can be read from the file to whatever was available at the time of creating the Header. This doesn't account for if bytes were removed from a file, I think that may be a more involved change but I haven't spent much time considering it. And that is a far less likely scenario to hit in practice.

Testing

I have only been able to intermittently reproduce the issue, but have yet to hit it with this fix. I'll be doing additional testing to get some more data.

https://smartthings.atlassian.net/browse/CHAD-8045

[posborne]

Good find, the fix matches the symptoms and I don't see the loss of data added after header creation to be a problem at all for any of our use cases.

[elbe0046]

PR against upstream: alexcrichton#283.