Bug 27354 - Isodumper crash after creating persistence
Summary: Isodumper crash after creating persistence
Status: ASSIGNED
Alias: None
Product: Mageia
Classification: Unclassified
Component: RPM Packages (show other bugs)
Version: 7
Hardware: All Linux
Priority: Normal major
Target Milestone: ---
Assignee: papoteur
QA Contact: All Packagers
URL:
Whiteboard: MGA7-64-OK
Keywords: validated_update
Depends on:
Blocks:
 
Reported: 2020-10-04 04:02 CEST by Morgan Leijström
Modified: 2020-10-21 14:17 CEST (History)
3 users (show)

See Also:
Source RPM: isodumper-1.22
CVE:
Status comment:


Attachments

Description Morgan Leijström 2020-10-04 04:02:59 CEST
Description of problem:

After verification isodumper creates persistence partition, then isodumper crash/exits, its window vanishes, log file not written.


Version-Release: isodumper-1.21-1.mga7

How reproducible:
No change if i start it as user or root, and if i put it in USB2 or USB2 port only the speed change.
* This bug do not appear if i do not check the box to make persistence *


Steps to Reproduce:
 System is Mageia 7 64 bit Plasma, fully updated also to testing
 Write mga8b1 live plasma 64 bit iso to stick,  * with persistence *
 After verification, a fraction of a second after display show "100%" isodumper just vanishes.
 In Konsole from where i started isodomper as root, i see:

g-io-error-quark: GDBus.Error:unknown.TypeError: __init__() got an unexpected keyword argument 'sterr' (36)


In journal i see it creates the partition for persistence, then hit that TypeError

okt 04 03:20:59 svarten.tribun magiback[12377]: Välkommen till fdisk (util-linux 2.33.2).
okt 04 03:20:59 svarten.tribun magiback[12377]: Ändringar kommer att förbli endast i minnet, till dess att du beslutar dig för att skriva dem.
okt 04 03:20:59 svarten.tribun magiback[12377]: Var aktsam innan du använder skrivkommandot.
okt 04 03:20:59 svarten.tribun magiback[12377]: Kommando (m för hjälp): Partitionstyp
okt 04 03:20:59 svarten.tribun magiback[12377]:    p   primär (2 primär, 0 utökat, 2 ledigt)
okt 04 03:20:59 svarten.tribun magiback[12377]:    e   utökad (behållare för logiska partitioner)
okt 04 03:20:59 svarten.tribun kernel:  sdd: sdd1 sdd2
okt 04 03:20:59 svarten.tribun magiback[12377]: Välj (standard p): Partitionsnummer (3,4, standardvärde 3): Första sektorn (6773316-60555263, standardvärde 6774784): Sista sektorn, +/-sektorer eller +/-storlek{K,M,G,T,P} (6774784-60555263, standardvärde 60555263):
okt 04 03:20:59 svarten.tribun magiback[12377]: Skapad en ny partition 3 av typen ”Linux” med storlek 25,7 GiB.
okt 04 03:20:59 svarten.tribun kernel:  sdd: sdd1 sdd2 sdd3
okt 04 03:20:59 svarten.tribun magiback[12377]: Kommando (m för hjälp): Partitionstabellen har ändrats.
okt 04 03:20:59 svarten.tribun magiback[12377]: Anropar ioctl() för att läsa om partitionstabellen.
okt 04 03:20:59 svarten.tribun magiback[12377]: Synkroniserar diskar.
okt 04 03:21:00 svarten.tribun plasmashell[11931]: file:///usr/lib64/qt5/qml/QtQuick/Controls/Button.qml:99: TypeError: Type error

But the same TypeError is also in journal five more times in quick succession at an earlier time in same run, without apparent problem.



Sidenote: at the very launch of isodumper, in console it outputs:
<bound method YCheckBox.value of <yui.YCheckBox; proxy of <Swig Object of type 'YCheckBox *' at 0x7f96c16ed510> >>

----------------------------

Output from fdisk -l after run:

Disk /dev/sdd: 28,9 GiB, 31004295168 byte, 60555264 sektorer
Disk-modell: DT Elite G2     
Enheter: sektorer av 1 * 512 = 512 byte
Sektorstorlek (logisk/fysisk): 512 byte / 512 byte
I/O-storlek (minsta/optimal): 512 byte / 512 byte
Disketikettstyp: dos
Diskidentifierare: 0x00000000

Enhet      Start  Början   Slutet Sektorer Storlek Id Typ
/dev/sdd1  *           0  6765123  6765124    3,2G  0 Tom
/dev/sdd2        6765124  6773315     8192      4M ef EFI (FAT-12/16/32)
/dev/sdd3        6774784 60555263 53780480   25,7G 83 Linux
Morgan Leijström 2020-10-04 04:03:32 CEST

Assignee: bugsquad => yves.brungard_mageia

Comment 1 papoteur 2020-10-04 10:08:20 CEST
Hi Morgan,
Thanks for the report.
Yes, I reproduce the crash.
Now, I have to debug it.
Comment 2 Morgan Leijström 2020-10-04 10:27:13 CEST
Good hunting!

Persistance is not working on that stick.
(actually i have never tested persistance before but now i need for another bug)

Was it something more isodumper was supposed to do to the stick, but died before?

I stumbled on key in comment 0:  "USB2 or USB2" -> "USB2 or USB3"
Comment 3 Morgan Leijström 2020-10-04 11:24:24 CEST
Persistance is a major feature -> rising severity

For the persistance functionality:  (and there is a journal of current boot)
Bug 27356 - Live 8b1 Persistance is not working

Severity: normal => major
See Also: (none) => https://bugs.mageia.org/show_bug.cgi?id=27356

Comment 4 papoteur 2020-10-04 16:18:41 CEST
Fixed in git.
Error could be seen in /var/log/magiback.log
Comment 5 Morgan Leijström 2020-10-04 17:02:27 CEST
Thank you. That was agile :)

Did this error affect the result on the memory stick?

If not, there is something else causing Bug 27356.
Comment 6 papoteur 2020-10-04 19:05:12 CEST
Yes, it causes problem. The instruction mkfs.ext is thus not executed.
Comment 7 Morgan Leijström 2020-10-04 21:15:39 CEST
OK
So can you make a new version with this fixed and I can test and use, please?
Comment 8 papoteur 2020-10-05 11:30:59 CEST
I have tagged a release 1.22 of isodumper.
Can someone package it?

CC: (none) => geiger.david68210
QA Contact: (none) => pkg-bugs
Status: NEW => ASSIGNED

Comment 9 David GEIGER 2020-10-05 15:43:33 CEST
Done for both Cauldron and mga7!
Comment 10 papoteur 2020-10-05 21:06:08 CEST
Advisory
=====================================
Isodumper 1.22
The program crashed when making the persistence partition.
The update fix this problem.
=====================================

Assignee: yves.brungard_mageia => qa-bugs

Comment 11 Morgan Leijström 2020-10-06 00:12:53 CEST
It dont crash anymore when making a persistent partition, and i have also tried encryption OK.

 But:

1) The (qt) interface it is not translated anymore

2) For one of the sticks i tried there are lots of I/O errors at the time i think it tries to validate persistent partition (?):

okt 05 23:13:17 svarten.tribun magiback[6174]: Skapar ett filsystem med 30521441 4 k-block och 7634944 inoder
okt 05 23:13:17 svarten.tribun magiback[6174]: Filsystems-UUID: a428ce25-b733-413d-a3be-f2af48358cde
okt 05 23:13:17 svarten.tribun magiback[6174]: Superblockkopior lagrade på block:
okt 05 23:13:17 svarten.tribun magiback[6174]:         32768, 98304, 163840, 229376, 294912, 819200, 884736, 1605632, 2654208,
okt 05 23:13:17 svarten.tribun magiback[6174]:         4096000, 7962624, 11239424, 20480000, 23887872
okt 05 23:13:17 svarten.tribun magiback[6174]: [57B blob data]
okt 05 23:13:17 svarten.tribun magiback[6174]: [55B blob data]
okt 05 23:13:20 svarten.tribun magiback[6174]: Skapar journal (131072 block): klar
okt 05 23:13:20 svarten.tribun magiback[6174]: [96B blob data]
okt 05 23:13:20 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#17 device offline or changed
okt 05 23:13:20 svarten.tribun kernel: print_req_error: 60 callbacks suppressed
okt 05 23:13:20 svarten.tribun kernel: blk_update_request: I/O error, dev sdc, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
okt 05 23:13:20 svarten.tribun kernel: buffer_io_error: 7425 callbacks suppressed
okt 05 23:13:20 svarten.tribun kernel: Buffer I/O error on dev sdc, logical block 0, async page read
okt 05 23:13:20 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#18 device offline or changed
okt 05 23:13:20 svarten.tribun kernel: blk_update_request: I/O error, dev sdc, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
okt 05 23:13:20 svarten.tribun kernel: Buffer I/O error on dev sdc, logical block 0, async page read
okt 05 23:13:20 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#19 device offline or changed
okt 05 23:13:20 svarten.tribun kernel: blk_update_request: I/O error, dev sdc, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
okt 05 23:13:20 svarten.tribun kernel: Buffer I/O error on dev sdc, logical block 0, async page read
okt 05 23:13:20 svarten.tribun kernel: ldm_validate_partition_table(): Disk read failed.
okt 05 23:13:20 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#16 device offline or changed
okt 05 23:13:20 svarten.tribun kernel: blk_update_request: I/O error, dev sdc, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
okt 05 23:13:20 svarten.tribun kernel: Buffer I/O error on dev sdc, logical block 0, async page read
okt 05 23:13:20 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#17 device offline or changed
okt 05 23:13:20 svarten.tribun kernel: blk_update_request: I/O error, dev sdc, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
okt 05 23:13:20 svarten.tribun kernel: Buffer I/O error on dev sdc, logical block 0, async page read
okt 05 23:13:20 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#18 device offline or changed
okt 05 23:13:20 svarten.tribun kernel: blk_update_request: I/O error, dev sdc, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
okt 05 23:13:20 svarten.tribun kernel: Buffer I/O error on dev sdc, logical block 0, async page read
okt 05 23:13:20 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#19 device offline or changed
okt 05 23:13:20 svarten.tribun kernel: blk_update_request: I/O error, dev sdc, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
okt 05 23:13:20 svarten.tribun kernel: Buffer I/O error on dev sdc, logical block 0, async page read
okt 05 23:13:20 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#16 device offline or changed
okt 05 23:13:20 svarten.tribun kernel: blk_update_request: I/O error, dev sdc, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
okt 05 23:13:20 svarten.tribun kernel: Buffer I/O error on dev sdc, logical block 0, async page read
okt 05 23:13:20 svarten.tribun kernel:  sdc: unable to read partition table
okt 05 23:13:20 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#19 device offline or changed
okt 05 23:13:20 svarten.tribun kernel: blk_update_request: I/O error, dev sdc, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
okt 05 23:13:20 svarten.tribun kernel: Buffer I/O error on dev sdc, logical block 0, async page read
okt 05 23:13:20 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#16 device offline or changed
okt 05 23:13:20 svarten.tribun kernel: blk_update_request: I/O error, dev sdc, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
okt 05 23:13:20 svarten.tribun kernel: Buffer I/O error on dev sdc, logical block 0, async page read
okt 05 23:13:20 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#17 device offline or changed
okt 05 23:13:20 svarten.tribun kernel: ldm_validate_partition_table(): Disk read failed.
okt 05 23:13:20 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#18 device offline or changed
okt 05 23:13:20 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#19 device offline or changed
okt 05 23:13:20 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#16 device offline or changed
okt 05 23:13:20 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#17 device offline or changed
okt 05 23:13:20 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#18 device offline or changed
okt 05 23:13:20 svarten.tribun kernel:  sdc: unable to read partition table
okt 05 23:13:20 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#22 device offline or changed
okt 05 23:13:20 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#23 device offline or changed
okt 05 23:13:20 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#4 device offline or changed
okt 05 23:13:20 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#5 device offline or changed
okt 05 23:13:20 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#6 device offline or changed

The above happens with stick Corsair voyager GTX 128GB, for both USB2 and USB3 connections
But none of the kernel lines happens with another stick, the Kingston DT Elite G2 32 GB

Another difference between the sticks is that when i insert them, for Kingston kernel tells:
okt 05 23:22:17 svarten.tribun kernel: sd 10:0:0:0: [sdc] No Caching mode page found
okt 05 23:22:17 svarten.tribun kernel: sd 10:0:0:0: [sdc] Assuming drive cache: write through

Maybe that difference is a clue.

Both sticks works, and the partitions also look OK in mageia 8 diskdrake.
But is there some checking going wrong with all that kernel lines in journal, or what is it?
Both sticks are very little used before.

Assignee: qa-bugs => yves.brungard_mageia
Source RPM: isodumper-1.21-1.mga7.src.rpm => isodumper-1.22

Comment 12 papoteur 2020-10-10 18:35:05 CEST
Advisory
=====================================
Isodumper 1.23
The program crashed when making the persistence partition.
The update fix this problem.
The persistence creation process has now a step of waiting for the partition table to be known by the kernel.
=====================================
papoteur 2020-10-10 18:35:35 CEST

Assignee: yves.brungard_mageia => qa-bugs

Comment 13 Morgan Leijström 2020-10-10 20:42:13 CEST
?  I still get tens of lines of errors like in #11, from line

  sd 10:0:0:0: [sdc] tag#4 device offline or changed

etc

And yes isodumper say it is 1.23

Assignee: qa-bugs => yves.brungard_mageia

Comment 14 papoteur 2020-10-10 22:23:13 CEST
:(
I don't have that here.
Perhaps I must with other sticks.
Can you give the relative timing of the errors?
Comment 15 papoteur 2020-10-10 22:34:08 CEST
No Caching mode page found
Assuming drive cache: write through
doesn't seem to be the trigger.

oct. 10 22:25:42 YZenbook.home kernel: usb 1-3: new high-speed USB device number 10 using xhci_hcd                                                                                            
oct. 10 22:25:42 YZenbook.home kernel: usb 1-3: New USB device found, idVendor=058f, idProduct=6387, bcdDevice= 1.03                                                                          
oct. 10 22:25:42 YZenbook.home kernel: usb 1-3: New USB device strings: Mfr=1, Product=2, SerialNumber=3                                                                                      
oct. 10 22:25:42 YZenbook.home kernel: usb 1-3: Product: Mass Storage                                                                                                                         
oct. 10 22:25:42 YZenbook.home kernel: usb 1-3: Manufacturer: Generic                                                                                                                         
oct. 10 22:25:42 YZenbook.home kernel: usb 1-3: SerialNumber: 7AE7D6C9                                                                                                                        
oct. 10 22:25:42 YZenbook.home kernel: usb-storage 1-3:1.0: USB Mass Storage device detected                                                                                                  
oct. 10 22:25:42 YZenbook.home kernel: scsi host4: usb-storage 1-3:1.0                                                                                                                        
oct. 10 22:25:42 YZenbook.home mtp-probe[18074]: checking bus 1, device 10: "/sys/devices/pci0000:00/0000:00:14.0/usb1/1-3"
oct. 10 22:25:42 YZenbook.home mtp-probe[18074]: bus: 1, device: 10 was not an MTP device
oct. 10 22:25:42 YZenbook.home mtp-probe[18088]: checking bus 1, device 10: "/sys/devices/pci0000:00/0000:00:14.0/usb1/1-3"
oct. 10 22:25:42 YZenbook.home mtp-probe[18088]: bus: 1, device: 10 was not an MTP device
oct. 10 22:25:43 YZenbook.home kernel: scsi 4:0:0:0: Direct-Access     Generic  Flash Disk       8.07 PQ: 0 ANSI: 2
oct. 10 22:25:43 YZenbook.home kernel: sd 4:0:0:0: [sdc] 7823360 512-byte logical blocks: (4.01 GB/3.73 GiB)
oct. 10 22:25:43 YZenbook.home kernel: sd 4:0:0:0: [sdc] Write Protect is off
oct. 10 22:25:43 YZenbook.home kernel: sd 4:0:0:0: [sdc] Mode Sense: 03 00 00 00
oct. 10 22:25:43 YZenbook.home kernel: sd 4:0:0:0: [sdc] No Caching mode page found
oct. 10 22:25:43 YZenbook.home kernel: sd 4:0:0:0: [sdc] Assuming drive cache: write through
oct. 10 22:25:43 YZenbook.home kernel:  sdc: sdc1
oct. 10 22:25:43 YZenbook.home kernel: sd 4:0:0:0: [sdc] Attached SCSI removable disk
oct. 10 22:26:22 YZenbook.home polkitd[3456]: Operator of unix-session:1 successfully authenticated as unix-user:root to gain TEMPORARY authorization for action org.mageia.Magiback.Isodumper.write for system-bus-name::1.146 [python3 isodumper.py] (owned by unix-user:yves)
oct. 10 22:26:59 YZenbook.home kernel:  sdc: sdc1 sdc2
oct. 10 22:27:06 YZenbook.home kernel:  sdc: sdc1 sdc2
oct. 10 22:27:06 YZenbook.home kernel:  sdc: sdc1 sdc2 sdc3
oct. 10 22:27:36 YZenbook.home kernel: sdc: detected capacity change from 4005560320 to 0
Comment 16 Morgan Leijström 2020-10-10 23:20:19 CEST
I forgot to say localisation works again :)

Below is the output of
 # journalctl -fko short-unix


   Inserting stick into a USB3 port:

1602364196.572838 svarten.tribun kernel: usb 6-1: new SuperSpeed Gen 1 USB device number 4 using xhci_hcd
1602364196.590834 svarten.tribun kernel: usb 6-1: New USB device found, idVendor=1b1c, idProduct=1a0e, bcdDevice= 1.00
1602364196.591165 svarten.tribun kernel: usb 6-1: New USB device strings: Mfr=2, Product=3, SerialNumber=1
1602364196.591646 svarten.tribun kernel: usb 6-1: Product: Voyager GTX
1602364196.591874 svarten.tribun kernel: usb 6-1: Manufacturer: Corsair
1602364196.592085 svarten.tribun kernel: usb 6-1: SerialNumber: 511190606267A0D6018B
1602364196.596881 svarten.tribun kernel: scsi host10: uas
1602364196.597241 svarten.tribun kernel: scsi 10:0:0:0: Direct-Access     Corsair  Voyager GTX      0    PQ: 0 ANSI: 6
1602364196.598840 svarten.tribun kernel: sd 10:0:0:0: [sdc] Spinning up disk...
1602364197.659842 svarten.tribun kernel: .ready
1602364197.659973 svarten.tribun kernel: sd 10:0:0:0: [sdc] 250069680 512-byte logical blocks: (128 GB/119 GiB)
1602364197.660246 svarten.tribun kernel: sd 10:0:0:0: [sdc] Write Protect is off
1602364197.660479 svarten.tribun kernel: sd 10:0:0:0: [sdc] Mode Sense: 43 00 00 00
1602364197.660710 svarten.tribun kernel: sd 10:0:0:0: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
1602364197.660945 svarten.tribun kernel: sd 10:0:0:0: [sdc] Optimal transfer size 33553920 bytes
1602364197.670833 svarten.tribun kernel:  sdc: sdc1 sdc2 sdc3
1602364197.671836 svarten.tribun kernel: sd 10:0:0:0: [sdc] Attached SCSI disk


In isodumper i select that stick, the 8b1 xfce 64 bit iso, and persistent partition, and start it.

   After writing, (start verifying):

1602364255.565836 svarten.tribun kernel:  sdc: sdc1 sdc2



   Appearing after isodumper have verified the stick:

1602364305.020069 svarten.tribun kernel:  sdc: sdc1 sdc2
1602364305.248835 svarten.tribun kernel:  sdc: sdc1 sdc2 sdc3
1602364305.249832 svarten.tribun kernel:  sdc: sdc1 sdc2 sdc3
1602364310.461835 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#28 device offline or changed
1602364310.462578 svarten.tribun kernel: print_req_error: 57 callbacks suppressed
1602364310.463507 svarten.tribun kernel: blk_update_request: I/O error, dev sdc, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
1602364310.463563 svarten.tribun kernel: buffer_io_error: 6913 callbacks suppressed
1602364310.463604 svarten.tribun kernel: Buffer I/O error on dev sdc, logical block 0, async page read
1602364310.465589 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#28 device offline or changed
1602364310.465846 svarten.tribun kernel: blk_update_request: I/O error, dev sdc, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
1602364310.465886 svarten.tribun kernel: Buffer I/O error on dev sdc, logical block 0, async page read
1602364310.466303 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#28 device offline or changed
1602364310.466547 svarten.tribun kernel: blk_update_request: I/O error, dev sdc, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
1602364310.466587 svarten.tribun kernel: Buffer I/O error on dev sdc, logical block 0, async page read
1602364310.466625 svarten.tribun kernel: ldm_validate_partition_table(): Disk read failed.
1602364310.466668 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#28 device offline or changed
1602364310.467195 svarten.tribun kernel: blk_update_request: I/O error, dev sdc, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
1602364310.468420 svarten.tribun kernel: Buffer I/O error on dev sdc, logical block 0, async page read
1602364310.468460 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#28 device offline or changed
1602364310.469093 svarten.tribun kernel: blk_update_request: I/O error, dev sdc, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
1602364310.469131 svarten.tribun kernel: Buffer I/O error on dev sdc, logical block 0, async page read
1602364310.469608 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#28 device offline or changed
1602364310.469901 svarten.tribun kernel: blk_update_request: I/O error, dev sdc, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
1602364310.469946 svarten.tribun kernel: Buffer I/O error on dev sdc, logical block 0, async page read
1602364310.469982 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#28 device offline or changed
1602364310.470234 svarten.tribun kernel: blk_update_request: I/O error, dev sdc, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
1602364310.470574 svarten.tribun kernel: Buffer I/O error on dev sdc, logical block 0, async page read
1602364310.470631 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#28 device offline or changed
1602364310.470890 svarten.tribun kernel: blk_update_request: I/O error, dev sdc, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
1602364310.470933 svarten.tribun kernel: Buffer I/O error on dev sdc, logical block 0, async page read
1602364310.471333 svarten.tribun kernel:  sdc: unable to read partition table
1602364310.471389 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#3 device offline or changed
1602364310.471648 svarten.tribun kernel: blk_update_request: I/O error, dev sdc, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
1602364310.471994 svarten.tribun kernel: Buffer I/O error on dev sdc, logical block 0, async page read
1602364310.472042 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#0 device offline or changed
1602364310.472296 svarten.tribun kernel: blk_update_request: I/O error, dev sdc, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
1602364310.472336 svarten.tribun kernel: Buffer I/O error on dev sdc, logical block 0, async page read
1602364310.472669 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#1 device offline or changed
1602364310.472930 svarten.tribun kernel: ldm_validate_partition_table(): Disk read failed.
1602364310.473000 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#2 device offline or changed
1602364310.473228 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#3 device offline or changed
1602364310.473690 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#0 device offline or changed
1602364310.473914 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#1 device offline or changed
1602364310.474281 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#2 device offline or changed
1602364310.474507 svarten.tribun kernel:  sdc: unable to read partition table
1602364310.481835 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#8 device offline or changed
1602364310.482171 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#9 device offline or changed
1602364310.485835 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#10 device offline or changed
1602364310.486497 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#11 device offline or changed
1602364310.486769 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#8 device offline or changed
Comment 17 Dave Hodgins 2020-10-11 00:37:32 CEST
1602364310.463604 svarten.tribun kernel: Buffer I/O error on dev sdc, logical
block 0, async page read

That looks like either a bad usb stick, or a problem with the connection
somewhere between it and the motherboard.

CC: (none) => davidwhodgins

Comment 18 Morgan Leijström 2020-10-11 01:05:56 CEST
I was also thinking that, but:  There are *no* buffer errors while writing the whole iso file, nor when reading it, or creating partitions. Only after the actual work is done.

And that kind of errors comes only after it have reported device is offline, but that said  have no idea about how synchronous and self aware the handling of USB drives is...

I also tested on a USB2 port, on same machine, identical result except speed.

Also, the stick boot and runs OK also with persistence. (Did not look into the log though)
Comment 19 Morgan Leijström 2020-10-11 01:07:44 CEST
What is isodumper trying to do in the end?
Can i execute some similar commands in CLI, to see if i get similar result in journal?
Comment 20 Dave Hodgins 2020-10-11 01:28:35 CEST
The last journal entry in my test was
Oct 10 19:16:49 magiback[14548]: Syncing disks.

No errors in journal in my test.

Konsole output (I ran it after using su - out of habit) ...
# isodumper
<bound method YCheckBox.value of <yui.YCheckBox; proxy of <Swig Object of type 'YCheckBox *' at 0x7f303bd73510> >>
Target Device: Kingston DT 101 G2 (/dev/sde) 14.912 GiB
Image : /s3/m8/Mageia-8-beta1-Live-Xfce-x86_64/Mageia-8-beta1-Live-Xfce-x86_64.iso
Executing copy from /s3/m8/Mageia-8-beta1-Live-Xfce-x86_64/Mageia-8-beta1-Live-Xfce-x86_64.iso to /dev/sde
Image Mageia-8-beta1-Live-Xfce-x86_64.iso successfully written to /dev/sde
Bytes written: 2810071040

The sha3 sum check is OK and the sum is signed
Added persistent partition

# blkid /dev/sde*
/dev/sde: UUID="2020-07-19-12-04-36-00" LABEL="Mageia-8-b1-Live-Xfce-x86_64" TYPE="iso9660" PTTYPE="dos"
/dev/sde1: UUID="2020-07-19-12-04-36-00" LABEL="Mageia-8-b1-Live-Xfce-x86_64" TYPE="iso9660" PTTYPE="dos"
/dev/sde2: SEC_TYPE="msdos" LABEL_FATBOOT="MGALIVE-ESP" LABEL="MGALIVE-ESP" UUID="4E93-AEE1" TYPE="vfat"
/dev/sde3: LABEL="mgalive-persist" UUID="cc5d17df-ee66-427b-a549-56ce76f35e10" TYPE="ext4"

]# mount /dev/sde3 /e3
[root@x3 ~]# ll /e3
total 16
drwx------ 2 root root 16384 Oct 10 19:16 lost+found/

You can test a usb using using something like
dd bs=1M if=/dev/urandom of=/dev/sdz

Replace sdz with correct device id. This will write until it fails when the
device is full.
Comment 21 Morgan Leijström 2020-10-11 03:44:49 CEST
Neither dd nor isodumper cause any problem with writing Mageia iso to this usb stick (Corsair Voyager GTX).

Also if i let isodumper only format the stick, there is no error reported.

Now i have realised the problems do not have to do with making persistence; 
I always (for this stick) see the same errors coming at end of isodumper operation with or without that box checked.

Also note there are never errors during writing or verifying the iso - but afterwards - and if it should create persistence it also succeeds with that.

Also note, isodumper dialog say it completed OK.

So maybe all is well regarding isodumper but kernel/whatever is trying to communicate with that stick for other reasons (is it only trying to read partition table and all other errors are results of that?) but the stick is shut down?  Maybe not properly shut down?  Maybe bug in stick? Kernel?

Another detail/bug: if after the failure i keep the stick plugged in and isodumper open, i can in isodumper select the stick in dropdown but it fail if i try to i.e format it.
Comment 22 Morgan Leijström 2020-10-11 04:08:03 CEST
Timing, making a live iso with persistence:


Last part of isodumper log, (and dialogues say it have succeeded):

2020-10-11 03:52:09 DEBUG    Start doing persistence partition
2020-10-11 03:52:09 DEBUG    Persistence thread started
2020-10-11 03:52:10 DEBUG    New partition created
2020-10-11 03:52:14 INFO     Persistent partition done
2020-10-11 03:52:14 DEBUG    Finished
2020-10-11 03:52:14 DEBUG    Starting unmounting
2020-10-11 03:52:14 INFO     Inga partitioner är monterade.   ( = No partitions are mounted )


At the same time, from # journalctl -fko short-iso-precise :

2020-10-11T03:52:14.885834+0200 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#15 device offline or changed
...yes all like before, see i.e comment 16, snipping many lines here...
2020-10-11T03:52:14.914726+0200 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#13 device offline or changed


Could be interesting to have microseconds resolution in isodumper log too.


Anyway, i tend to say isodumper is good to release, 
but you know more about how this works than me :)
Comment 23 Dave Hodgins 2020-10-11 04:24:57 CEST
The hardware errors are clearly being recovered from ok, so validating the
update.

CC: (none) => sysadmin-bugs
Whiteboard: (none) => MGA7-64-OK
Keywords: (none) => validated_update

Comment 24 papoteur 2020-10-11 10:31:53 CEST
For information, when doing persistence, operations are:
fdisk to add a partition in the remaining space;
udevadm settle --timeout=15 to wait for propogation
mkfs.ext4
The message "Persistent partition done" is then printed
unmount partitions of the device
eject the device

What I can do is to add waiting after mkfs and before unmount.
Comment 25 papoteur 2020-10-11 15:28:33 CEST
Hello,
I have pushed on git some modifications that add waiting steps. If you want test them, you have to replace backend/raw_write.py and backend/magiback
then stop magiback.service
I found a problem that encrypted partition is not unmounted with other partitions of the if it is mounted. I look for a method to enumerate it.
Comment 26 Morgan Leijström 2020-10-11 18:31:05 CEST
Thank you for keeping hammering :)
I see commit for microseconds too.

===========================

Sidenote:

http://gitweb.mageia.org/software/isodumper/about/ is empty.
Maybe copy from https://github.com/papoteur-mga/isodumper ?

===========================

   Not familiar with git, i downloaded the files...
   
http://gitweb.mageia.org/software/isodumper/plain/backend/magiback
http://gitweb.mageia.org/software/isodumper/plain/backend/raw_write.py
 ( to /home/morgan/Hämtningar/ )

   ...and figured out what to do with them:

# mv /usr/bin/magiback /usr/bin/magiback_1.23
# mv /home/morgan/Hämtningar/magiback /usr/bin/magiback
# chown root:root /usr/bin/magiback
# chmod +x /usr/bin/magiback

# cd /usr/lib/python3.7/site-packages/isodumper/
# mv raw_write.py raw_write.py_1.23
# mv /home/morgan/Hämtningar/raw_write.py .
# chown root:root raw_write.py

# systemctl stop magiback.service

===========================

# isodumper

I selected the 64 bit 8b1 xfce live, persistence, not encrypted.
Same stick as before.
Isodumper dialogue reported success.
Same errors in journal, starting 18 milliseconds after isodumper logs it start unmounting.
Strange: it logs it start unmounting, then the same *micro* second ! , it logs no partitions are mounted?!

    Last part of /var/log/magiback.log

2020-10-11 17:52:04,351 DEBUG    signature checked
2020-10-11 17:52:04,352 DEBUG    Start checking
2020-10-11 17:52:50,028 DEBUG    last read 0
2020-10-11 17:52:50,250 INFO     
The sha3 sum check is OK and the sum is signed
2020-10-11 17:52:51,038 DEBUG    Start doing persistence partition
2020-10-11 17:52:51,038 DEBUG    Persistence thread started
2020-10-11 17:52:52,194 DEBUG    New partition created
2020-10-11 17:52:56,005 INFO     Persistent partition done
2020-10-11 17:52:56,513 DEBUG    Finished
2020-10-11 17:52:56,516 DEBUG    Starting unmounting
2020-10-11 17:52:56,516 INFO     Inga partitioner är monterade.


    From # journalctl -fko short-iso-precise :

2020-10-11T17:52:51.216184+0200 svarten.tribun kernel:  sdc: sdc1 sdc2
2020-10-11T17:52:51.506131+0200 svarten.tribun kernel:  sdc: sdc1 sdc2 sdc3
2020-10-11T17:52:51.509131+0200 svarten.tribun kernel:  sdc: sdc1 sdc2 sdc3
2020-10-11T17:52:56.534536+0200 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#14 device offline or changed
2020-10-11T17:52:56.534915+0200 svarten.tribun kernel: blk_update_request: I/O error, dev sdc, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
2020-10-11T17:52:56.534983+0200 svarten.tribun kernel: Buffer I/O error on dev sdc, logical block 0, async page read
2020-10-11T17:52:56.535032+0200 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#15 device offline or changed
2020-10-11T17:52:56.535331+0200 svarten.tribun kernel: blk_update_request: I/O error, dev sdc, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
2020-10-11T17:52:56.535367+0200 svarten.tribun kernel: Buffer I/O error on dev sdc, logical block 0, async page read
2020-10-11T17:52:56.535399+0200 svarten.tribun kernel: sd 10:0:0:0: [sdc] tag#16 device offline or changed
   ...Etc, etc, like earlier.
Comment 27 papoteur 2020-10-19 11:30:45 CEST
Hello,
There is now a 1.24 release.
I have re-factored the unmounting phase, now using udisks. Previously, encrypted partition couldn't be unmounted.
I have also added waiting step after each operation.
The modification of unmounting phase is also for format operation.
Comment 28 Morgan Leijström 2020-10-21 14:17:16 CEST
Thank you

1)

Again no translation, all is in english like comment#11.


2)

For the same stick like before, from a quick view I still see same errors in journal, except i do not see the "sdc: sdc1 sdc2 sdc3" lines.

Also tried a USB SSD disk, Seagate  M3 Portable 1TB, same errors but the lines  "sd 10:0:0:0: [sdc] tag#19 device offline or changed" are about three times more repeated.  I have verified the result is bootable and persistence working.


I wonder if kernel or something else treats some storage media differently than others, and tries to exercise them some way after isodumper have unmounted them?  Some "aggressive" automounting?  Based on storage capacity, or operating mode details maybe?

Note You need to log in before you can comment on or make changes to this bug.