[DONE] Strange trouble while using dd (and sync)

[doktor5000]

@doktor5000; thanks but I'd rather use Linux-only-based solutions

Hum? memtest is under GPL, and included in some of the Mageia installation media. What do you mean?
Or do you mean for multiboot? You can have that with Linux-only too, but have to configure it all manually.
I like a pragmatical approach, use what works best. If the windows tool does a better job, why not use it?
BTW, yumi is also GPL.


Also, your steps for Trikki are superfluous, Mayavimmer and me were already at it, so the steps you proposed
will not achieve anything, and only confuse the OP more, IMHO. Please next time at least read through the thread,
before proposing stuff that was already been done, that is only duplicating efforts uselessly

[doktor5000]

I found out about a book on system logs in general: Logging and Log Management: The Authoritative Guide to Understanding the Concepts Surrounding Logging and Log Management / Anton A. Chuvakin, Kevin J. Schmidt & Christopher Phillips (ISBN 978-1597496353).

Might not be perfect but atleast its something to starts with...

I get the impression you did not grok my explanation but I'll make you a deal: you find anything in that (otherwise good!) book that helps you debug your dd problem and I'll eat my pride and state publicly I was wrong. Take your time, I'll be tracking this thread.

[linuxero]

@doktor5000

I was talking about multiboot of course BTW I have nothing against using whatever technology that one might like or prefer, it's just that I, personally, have no Windows machine and since I am glad with Linux I am not intending to pay money for a system just to do experiments for now..maybe when I have more money When I test Windows, I happen to have a friend's machine using Windows so I have the chance to do things in M$ environment

As for the thread now; I have read it all actually; so I wrote that I got lost because I think that Trikki was missing some steps during the therapy..I always appreciuate your comments and frankñly I learn a lot out of them.

However; I really doubt dd to cause the memory-consumption or even the byte-size to be the problem. IMHO; there should be something else affecting memory I guess so that dd can cause such a problem..

Anyway, sorry again and I'll just stand by the line to learn more..unless something worth saying occurs to me

Thanks again

[doktor5000]

Well, dd will eat your memory like crazy. And if it dies within seconds, your try also won't help much
But let's see ...

[doktor5000]

I get the impression you did not grok my explanation but I'll make you a deal: you find anything in that (otherwise good!) book that helps you debug your dd problem and I'll eat my pride and state publicly I was wrong. Take your time, I'll be tracking this thread.

No need to offer such a deal:

I never asked for a book that would solve my current problem with dd. I was looking for a book on the topic of system logs and logging. And once I found out about one I thought to report it here in case anybody else was also interested in it.

I thought that I made it clear that my guestion about "logs in general" was offtopic, and had nothing to do with the reported dd problem. I asked for a book or website to avoid the risk that the whole topic would turn into a discussion about system logs.

I like to read about things that interest me, even if I would not actually need the information in my everyday life.

Your explanation of logs was excelent, and you really made me see that I had wrong expectation about system logs. Thank you! If you would be willing to write an essay etc. (maybe a wiki page?) that covers some of the many aspects of system logs, I would love to read it! But I guess this is not the right place for such a discussion and within this forum topic we propably should rather concentrate on the dd issue?

[doktor5000]

Please next time do not use fullquotes, but only use the Reply function. Greatly improves clarity and reading flow

[Trikki]

I ran some tests as promised, and here are the results:

The iso I used was Scientific Linux 6.4 LiveDVD 32-bit version. Everything should be ok with the iso:

Code: Select all

[root@localhost LiveDVD6_4]# ls
SHA1SUM.txt  SHA256SUM.txt  SL-64-i386-2013-04-17-LiveDVD.iso
[root@localhost LiveDVD6_4]# sha1sum SL-64-i386-2013-04-17-LiveDVD.iso
7c16479db6a3778e78b1583ebfe6f3340a1cfbec  SL-64-i386-2013-04-17-LiveDVD.iso
[root@localhost LiveDVD6_4]# cat SHA1SUM.txt | grep LiveDVD
7c16479db6a3778e78b1583ebfe6f3340a1cfbec  SL-64-i386-2013-04-17-LiveDVD.iso
[root@localhost LiveDVD6_4]# sha256sum SL-64-i386-2013-04-17-LiveDVD.iso
6ad0eaf4117e0536447c1781157de3938849eaa68419d7fa09bea32a4834086a  SL-64-i386-2013-04-17-LiveDVD.iso
[root@localhost LiveDVD6_4]# cat SHA256SUM.txt | grep LiveDVD
6ad0eaf4117e0536447c1781157de3938849eaa68419d7fa09bea32a4834086a  SL-64-i386-2013-04-17-LiveDVD.iso

I did 3 diferent tests:
1. dd if=SL-64-i386-2013-04-17-LiveDVD.iso of=/dev/sdc bs=1M
2. dd if=SL-64-i386-2013-04-17-LiveDVD.iso of=/dev/sdc bs=1M oflag=direct iflag=direct
3. dd if=SL-64-i386-2013-04-17-LiveDVD.iso of=/dev/sdc (another usb-port)

Before every test I checked that the /dev/srX was correct and also that it was not mounted at the time of running dd, by using df -h. The results were the same on all three tests:

Before mounting:

Code: Select all

[root@localhost LiveDVD6_4]# df -h
Filesystem      Size  Used Avail Use% Mounted on
rootfs           12G  4.0G  7.3G  36% /
devtmpfs        1.8G     0  1.8G   0% /dev
tmpfs           1.8G  1.9M  1.8G   1% /dev/shm
tmpfs           1.8G  648K  1.8G   1% /run
/dev/sda1        12G  4.0G  7.3G  36% /
tmpfs           1.8G     0  1.8G   0% /sys/fs/cgroup
/dev/sda6       443G   56G  388G  13% /home

After mounting:

Code: Select all

[root@localhost LiveDVD6_4]# df -h
Filesystem      Size  Used Avail Use% Mounted on
rootfs           12G  4.0G  7.3G  36% /
devtmpfs        1.8G     0  1.8G   0% /dev
tmpfs           1.8G  1.9M  1.8G   1% /dev/shm
tmpfs           1.8G  664K  1.8G   1% /run
/dev/sda1        12G  4.0G  7.3G  36% /
tmpfs           1.8G     0  1.8G   0% /sys/fs/cgroup
/dev/sda6       443G   56G  388G  13% /home
/dev/sdc1       2.4G  2.4G     0 100% /media/SL-64-i386-LiveDVD


After unmounting:

Code: Select all

[root@localhost LiveDVD6_4]# df -h
Filesystem      Size  Used Avail Use% Mounted on
rootfs           12G  4.0G  7.3G  36% /
devtmpfs        1.8G     0  1.8G   0% /dev
tmpfs           1.8G  1.9M  1.8G   1% /dev/shm
tmpfs           1.8G  656K  1.8G   1% /run
/dev/sda1        12G  4.0G  7.3G  36% /
tmpfs           1.8G     0  1.8G   0% /sys/fs/cgroup
/dev/sda6       443G   56G  388G  13% /home

I had tail -f /var/log/messages directed to a text file running on all the test.

I used the same usb stick on all of the tests. It is also the same I used last time the system crashed. Unfortunately this usb-stick does not have a blinking light, so I can not report what is happening with the light.

Test1: dd if=SL-64-i386-2013-04-17-LiveDVD.iso of=/dev/sdc bs=1M

Everything went pretty much the same as last time: within second the system had crashed. After a while the the konsole started working again, so I managed to run some commands to get some more info:

/var/log/messages had multiple oom-killer related messages

Code: Select all

May  1 09:34:57 localhost kernel: [ 2595.997242] uname invoked oom-killer: gfp_mask=0x201da, order=0, oom_adj=0, oom_score_adj=0
...
May  1 09:34:57 localhost kernel: [ 2596.026197] Out of memory: Kill process 1923 (plasma-desktop) score 12 or sacrifice child
May  1 09:34:57 localhost kernel: [ 2596.026204] Killed process 1928 (ksysguardd) total-vm:9252kB, anon-rss:524kB, file-rss:836kB
May  1 09:34:58 localhost kernel: [ 2597.933496] dd invoked oom-killer: gfp_mask=0x10200d0, order=0, oom_adj=0, oom_score_adj=0
...
May  1 09:34:58 localhost kernel: [ 2597.965190] Out of memory: Kill process 1923 (plasma-desktop) score 12 or sacrifice child
May  1 09:34:58 localhost kernel: [ 2597.965196] Killed process 1923 (plasma-desktop) total-vm:3025148kB, anon-rss:52604kB, file-rss:36128kB
May  1 09:35:10 localhost kernel: [ 2610.227289] net_applet invoked oom-killer: gfp_mask=0x84d0, order=0, oom_adj=0, oom_score_adj=0
...
May  1 09:35:10 localhost kernel: [ 2610.274886] Out of memory: Kill process 2030 (mysqld) score 9 or sacrifice child
May  1 09:35:10 localhost kernel: [ 2610.274909] Killed process 2030 (mysqld) total-vm:1553824kB, anon-rss:67220kB, file-rss:6604kB
May  1 09:36:58 localhost udevd[280]: worker [4193] timeout, kill it
May  1 09:36:58 localhost udevd[280]: seq 2067 '/devices/pci0000:00/0000:00:12.2/usb3/3-1/3-1:1.0/host4/target4:0:0/4:0:0:0/block/sdc' killed
...


Here is the information gathered after the crash had happened:

Code: Select all

PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
4226  7.2  0.0  12556  1652 pts/2    D+   09:34   0:13 dd if=SL-64-i386-2013-04-17-LiveDVD.iso of=/dev/sdc bs=1M

Code: Select all

             total       used       free     shared    buffers     cached
Mem:       3644936    3492340     152596          0    1858416    1129364
-/+ buffers/cache:     504560    3140376
Swap:      4087272      53844    4033428

Code: Select all

MemTotal:        3644936 kB
MemFree:          151396 kB
Buffers:         1858152 kB
Cached:          1129440 kB
SwapCached:        50908 kB
Active:          1363876 kB
Inactive:        1949108 kB
Active(anon):     269668 kB
Inactive(anon):    73220 kB
Active(file):    1094208 kB
Inactive(file):  1875888 kB
Unevictable:           0 kB
Mlocked:               0 kB
SwapTotal:       4087272 kB
SwapFree:        4033492 kB
Dirty:           1268320 kB
Writeback:         37256 kB
AnonPages:        279624 kB
Mapped:           120192 kB
Shmem:             17496 kB
Slab:             100788 kB
SReclaimable:      73516 kB
SUnreclaim:        27272 kB
KernelStack:        2264 kB
PageTables:        27760 kB
NFS_Unstable:          0 kB
Bounce:                0 kB
WritebackTmp:          0 kB
CommitLimit:     5909740 kB
Committed_AS:     998144 kB
VmallocTotal:   34359738367 kB
VmallocUsed:       99664 kB
VmallocChunk:   34359635332 kB
HardwareCorrupted:     0 kB
AnonHugePages:         0 kB
HugePages_Total:       0
HugePages_Free:        0
HugePages_Rsvd:        0
HugePages_Surp:        0
Hugepagesize:       2048 kB
DirectMap4k:       91136 kB
DirectMap2M:     2643968 kB
DirectMap1G:     1048576 kB

[I notice that the total memory amount is only 3644936 kB so I guess I was wrong when saying I had 4GB of RAM?]

After closing konsole all I had was a black screen with a small panel at the left upper corner.

This was a very good test because I managed to replicate the results of the previous insident. Though crashing my system is never all that pleasant.

Test2: dd if=SL-64-i386-2013-04-17-LiveDVD.iso of=/dev/sdc bs=1M oflag=direct iflag=directed

This time no problems what so ever. I send a USR1 signal to dd, but unfortunately I closed the konsole before copying the output, but since nothing out of the ordinary was happening I guess it's not a great loss.

There were no OOM messages or any other error mesages in the log this time.

Test3: dd if=SL-64-i386-2013-04-17-LiveDVD.iso of=/dev/sdc (another usb-port)

I still wanted to do one more test, this time just the dd without any flags etc. and also using another usb port.

This time everything started out fine. I send the USR1 signal to dd and everything seemed fine...until after 5 minutes: everything started crashing!

In the log there are once again many OOM messages.

Code: Select all

May  1 10:14:50 localhost kernel: [ 4986.788099] X invoked oom-killer: gfp_mask=0x280d0, order=0, oom_adj=0, oom_score_adj=0
...
May  1 10:14:51 localhost kernel: [ 4986.835040] Out of memory: Kill process 4870 (plasma-desktop) score 11 or sacrifice child
May  1 10:14:51 localhost kernel: [ 4986.835052] Killed process 4875 (ksysguardd) total-vm:9252kB, anon-rss:520kB, file-rss:836kB
May  1 10:15:27 localhost kernel: [ 5023.718081] dd invoked oom-killer: gfp_mask=0x10200d0, order=0, oom_adj=0, oom_score_adj=0
...
May  1 10:15:27 localhost kernel: [ 5023.762197] Out of memory: Kill process 4870 (plasma-desktop) score 11 or sacrifice child
May  1 10:15:27 localhost kernel: [ 5023.762210] Killed process 7008 (ksysguardd) total-vm:9264kB, anon-rss:536kB, file-rss:832kB
May  1 10:15:27 localhost kernel: [ 5023.793253] dd invoked oom-killer: gfp_mask=0x10200d0, order=0, oom_adj=0, oom_score_adj=0
...
May  1 10:15:27 localhost kernel: [ 5023.823321] Out of memory: Kill process 4870 (plasma-desktop) score 11 or sacrifice child
May  1 10:15:27 localhost kernel: [ 5023.823327] Killed process 4870 (plasma-desktop) total-vm:3011776kB, anon-rss:40280kB, file-rss:37068kB
May  1 10:18:56 localhost udevd[280]: worker [6466] timeout, kill it
May  1 10:18:56 localhost udevd[280]: seq 2180 '/devices/pci0000:00/0000:00:12.2/usb3/3-2/3-2:1.0/host8/target8:0:0/8:0:0:0/block/sdc' killed

Here are some more information:

Code: Select all

USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root      6540 15.9  0.0  11520   776 pts/1    D+   10:06   0:32 dd if=SL-64-i386-2013-04-17-LiveDVD.iso of=/dev/sdc
root      6540 15.8  0.0  11520   776 pts/1    D+   10:06   0:54 dd if=SL-64-i386-2013-04-17-LiveDVD.iso of=/dev/sdc
root      6540 11.9  0.0  11520   776 pts/1    D+   10:06   1:31 dd if=SL-64-i386-2013-04-17-LiveDVD.iso of=/dev/sdc

Code: Select all

             total       used       free     shared    buffers     cached
Mem:       3644936    3506400     138536          0    1486764    1429652
-/+ buffers/cache:     589984    3054952
Swap:      4087272      12064    4075208


Code: Select all

MemTotal:        3644936 kB
MemFree:          112472 kB
Buffers:         1542308 kB
Cached:          1399124 kB
SwapCached:        10428 kB
Active:          1591748 kB
Inactive:        1765960 kB
Active(anon):     356832 kB
Inactive(anon):    74472 kB
Active(file):    1234916 kB
Inactive(file):  1691488 kB
Unevictable:           0 kB
Mlocked:               0 kB
SwapTotal:       4087272 kB
SwapFree:        4075208 kB
Dirty:           1532856 kB
Writeback:             0 kB
AnonPages:        408504 kB
Mapped:           130300 kB
Shmem:             14820 kB
Slab:              94996 kB
SReclaimable:      70312 kB
SUnreclaim:        24684 kB
KernelStack:        2528 kB
PageTables:        27992 kB
NFS_Unstable:          0 kB
Bounce:                0 kB
WritebackTmp:          0 kB
CommitLimit:     5909740 kB
Committed_AS:    1563972 kB
VmallocTotal:   34359738367 kB
VmallocUsed:       99664 kB
VmallocChunk:   34359635332 kB
HardwareCorrupted:     0 kB
AnonHugePages:         0 kB
HugePages_Total:       0
HugePages_Free:        0
HugePages_Rsvd:        0
HugePages_Surp:        0
Hugepagesize:       2048 kB
DirectMap4k:       91136 kB
DirectMap2M:     2643968 kB
DirectMap1G:     1048576 kB


What was interesting though that although the system had crashed I could still use the konsole I had running and also acording to the USR1 signal dd was still writing (what follows is the output after the crash) :

Code: Select all

1415332352 bytes (1.4 GB) copied, 316.278 s, 4.5 MB/s
2982513+0 records in
2982513+0 records out
1527046656 bytes (1.5 GB) copied, 341.295 s, 4.5 MB/s
3205673+0 records in
3205673+0 records out
1641304576 bytes (1.6 GB) copied, 366.303 s, 4.5 MB/s
3413697+0 records in
3413697+0 records out
1747812864 bytes (1.7 GB) copied, 391.316 s, 4.5 MB/s
3591193+0 records in
3591193+0 records out
1838690816 bytes (1.8 GB) copied, 416.328 s, 4.4 MB/s
3766529+0 records in
3766529+0 records out
1928462848 bytes (1.9 GB) copied, 441.361 s, 4.4 MB/s
3909393+0 records in
3909393+0 records out
2001609216 bytes (2.0 GB) copied, 468.305 s, 4.3 MB/s
3979009+0 records in
3979009+0 records out
2037252608 bytes (2.0 GB) copied, 507.002 s, 4.0 MB/s
4137481+0 records in
4137481+0 records out
2118390272 bytes (2.1 GB) copied, 532.129 s, 4.0 MB/s
4222473+0 records in
4222473+0 records out
2161906176 bytes (2.2 GB) copied, 557.148 s, 3.9 MB/s
4322577+0 records in
4322577+0 records out
2213159424 bytes (2.2 GB) copied, 582.131 s, 3.8 MB/s
4478481+0 records in
4478481+0 records out
2292982272 bytes (2.3 GB) copied, 607.144 s, 3.8 MB/s
4631305+0 records in
4631305+0 records out
2371228160 bytes (2.4 GB) copied, 632.242 s, 3.8 MB/s
4789769+0 records in
4789769+0 records out
2452361728 bytes (2.5 GB) copied, 657.273 s, 3.7 MB/s
i4946577+0 records in
4946577+0 records out
2532647424 bytes (2.5 GB) copied, 682.179 s, 3.7 MB/s

I let it run until it seemed to stop to that last message.

And once again after closing the konsole I had a black screen with a small panel on the upper left corner. Interestingly I was able to take a screenshot of it! (Unfortunately I could not figure out how to include the picture here, but it really is not all that important.)
---

So it seems that if I do not use the oflag=direct iflag=directed my system memory will run out. But why is this happening, that is still unclear to me? The only guess I can make is that my harware is broken in some way?

[doktor5000]

Well, that's interesting, Also looking back at the earlier logs, it seems the oom-killer tries to kill your KDE desktop (plasma-desktop) as the best candidate to free up some RAM, and dd will still continue to run.

As i mentioned earlier, what happens when you try to write a large iso image with dd witout any flags (and using a larger blocksize than the default 4k, 1 megabyte in your first example) immediately after starting it dd reads the image into RAM, allocating how much space it needs. This also can slow larger systems to a crawl, as mentioned at work i've got 8GB RAM, and maybe 6GB available under normal conditions, and a fast CPU.

Still, when trying to write an 12GB image to a flash drive, the system slows down to a crawl, short of making it unusable for during the time it takes to write the image.

The behaviour here always depends on the kernel, the blocksize used for dd, and the flags.

[Mayavimmer]

I never asked for a book that would solve my current problem with dd. I was looking for a book on the topic of system logs and logging. And once I found out about one I thought to report it here in case anybody else was also interested in it.

...and I never objected to your search for a logging book. I only objected to the more general problem of seeking a general understanding of logging which, I repeat, is wrongheaded. You then found an otherwise interesting book, thanks for pointing it out, which you think will provide that impossible understanding. Using that particular logging book to solve your particular dd problem is only an instance of the general impossible problem I referred to earlier. I only used this instance as an example after you didn't grok my explanation of the general rule.

...Which you still don't:

Your explanation of logs was excelent, and you really made me see that I had wrong expectation about system logs. Thank you! If you would be willing to write an essay etc. (maybe a wiki page?) that covers some of the many aspects of system logs, I would love to read it!

Thank you for your flattering remarks! But I evidently do not deserve them since my "excellent" explanation of logs was trying to prove the very impossibility of writing the essay you would like me to!

Back to your interesting problem. Recapping, it seems that the dd always eventually comes to a successful completion, though often consuming more resources than it would seem entitled to. I have never experienced this problem though writing a big image to a particularly slow USB device would seem to pose a great challenge to the kernel. What would you do if you were the kernel, with an eye to maximizing throughput? Read as much of the source file into RAM expecting then to quickly empty it out into the USB device? What if the device is much slower than presumed? Can you reasonably expect to roll back the file pointer in order to free some RAM should pressing requests be made without oomkilling anyone? No! You have to preserve semantic correctness in some corner cases! (Would the re-read be idempotent?) I honestly don't know how the kernel guys solved (have they?) this problem.

I never took the trouble to understand the details of block device caching but if you care you could try to ask on the kernel-dev list, or use iostat to watch buffers being used by dd, or enlarge your mind as I have not in wonderful places like http://haifux.org/lectures/253/alice_and_bob_in_io_land/alice_and_bob_in_io_land.html. Of course do gather more info before bothering those guys: try different OS' on you USB drive and possibly different hardware. Got me curious now.

[Trikki]

@Mayavimmer: I read again what you wrote earlier, and I think I get your point now. In that light it seems rather pointless to bother with the book... I guess I'll save my money for something more usefull...

But anyways...getting back to the dd issue...

It's interesting that the whole thing is obviously not a fault or an error as such in a purely technical way, considering the way how the system works: the kernel is just doing what it is programed to do when it sees that memory is overloading, and thus the whole system is in danger of crashing. The only unfortunate thing is that one of the first thing it decides to kill to free some memory is my GUI, which is not very good thing for a desktop computer (well a laptop, but meaning that it's not a server etc...).

As it seems that this dd problem is caused by the way the kernel is handling things, and because I can avoid the problem by using the "direct" flags (thanks for the tip doktor5000) I am going to call this one solved (without a "?").

Thank you all for your help! I have learned a lot of new stuff, and I guess that is the bright side of these kinds of problems: you get to learn much more by trying to solve things than you would if everything was always free of any kind of problems.

[doktor5000]

I am going to call this one solved (without a "?").

You could also mark it [DONE] if it's not really solved, but if a workaround exists.

[Trikki]

Ok, perhaps that would be more appropriate. Now changed status to [DONE].