[ 11.189483] systemd-journald[943]: varlink-22: Changing state processed-method → idle-server [ 11.190633] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 11.190705] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 11.191385] systemd-journald[943]: varlink-22: Got POLLHUP from socket. [ 11.191389] systemd-journald[943]: varlink-22: Changing state idle-server → pending-disconnect [ 11.191392] systemd-journald[943]: varlink-22: Changing state pending-disconnect → processing-disconnect [ 11.191395] systemd-journald[943]: varlink-22: Changing state processing-disconnect → disconnected [ 11.200993] VFIO - User Level meta-driver version: 0.3 [ 11.224375] qeth 0.0.bd00: CHID: 1a0 CHPID: 98 [ 11.229256] qeth 0.0.bd02: qdio: OSA on SC 2624 using AI:1 QEBSM:0 PRI:1 TDD:1 SIGA: W [ 11.250189] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 11.258763] qeth 0.0.bd00: Device is a OSD Express card (level: 0165) with link type OSD_10GIG. [ 11.259261] qeth 0.0.bd00: The device represents a Bridge Capable Port [ 11.262376] qeth 0.0.bd00: MAC address b2:96:9c:49:aa:e9 successfully registered [ 11.269654] qeth 0.0.bd00: MAC address 06:c6:b5:7d:ee:63 successfully registered [ 11.272060] qeth 0.0.bd00 encbd00: renamed from eth0 [ 11.310918] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 11.323102] dasdconf.sh Warning: 0.0.627c is already online, not configuring [ 11.343058] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 11.347561] zram0: detected capacity change from 0 to 16777216 [ 11.359549] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 11.377984] Adding 8388604k swap on /dev/zram0. Priority:100 extents:1 across:8388604k SSDsc [ 11.381599] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 11.390605] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 11.397956] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 11.552967] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 11.569530] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 11.575683] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 11.605458] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 11.611661] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 11.615960] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 11.714654] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 11.716630] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 11.743224] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 11.745027] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 11.746763] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 11.751180] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 11.752995] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 11.920342] dasd-eckd 0.0.627f: A channel path to the device has become operational [ 11.920856] dasd-eckd 0.0.627f: A channel path to the device has become operational [ 11.928668] dasd-eckd 0.0.627f: New DASD 3390/0C (CU 3990/04) with 30051 cylinders, 15 heads, 224 sectors [ 11.941252] zfcp 0.0.1900: qdio: ZFCP on SC 61 using AI:1 QEBSM:0 PRI:1 TDD:1 SIGA: W [ 11.948281] dasd-eckd 0.0.627f: DASD with 4 KB/block, 21636720 KB total size, 48 KB/track, compatible disk layout [ 11.949271] dasdb:VOL1/ 0X627F: dasdb1 dasdb2 [ 11.970413] scsi host0: scsi_eh_0: sleeping [ 11.970560] scsi host0: zfcp [ 12.028341] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 12.032979] zfcp 0.0.1900: FC Endpoint Security of connection to remote port 0x500507630910d435 enabled: Encryption [ 12.035107] scsi 0:0:0:0: scsi scan: INQUIRY pass 1 length 36 [ 12.035239] scsi 0:0:0:0: scsi scan: INQUIRY successful with code 0x0 [ 12.035246] scsi 0:0:0:0: scsi scan: INQUIRY pass 2 length 164 [ 12.035345] scsi 0:0:0:0: scsi scan: INQUIRY successful with code 0x0 [ 12.035350] scsi 0:0:0:0: scsi scan: peripheral device type of 31, no device added [ 12.035679] scsi 0:0:0:0: scsi scan: Sending REPORT LUNS to (try 0) [ 12.036992] scsi 0:0:0:0: scsi scan: REPORT LUNS successful (try 0) result 0x0 [ 12.036994] scsi 0:0:0:0: scsi scan: REPORT LUN scan [ 12.037241] scsi 0:0:0:1084113024: scsi scan: INQUIRY pass 1 length 36 [ 12.037394] scsi 0:0:0:1084113024: scsi scan: INQUIRY successful with code 0x0 [ 12.037399] scsi 0:0:0:1084113024: scsi scan: INQUIRY pass 2 length 164 [ 12.037496] scsi 0:0:0:1084113024: scsi scan: INQUIRY successful with code 0x0 [ 12.037502] scsi 0:0:0:1084113024: Direct-Access IBM 2107900 .102 PQ: 0 ANSI: 6 [ 12.038919] scsi 0:0:0:1084113024: alua: supports implicit TPGS [ 12.038922] scsi 0:0:0:1084113024: alua: device naa.6005076309ffd435000000000000809e port group 0 rel port 203 [ 12.038952] sd 0:0:0:1084113024: sg_alloc: dev=0 [ 12.038982] sd 0:0:0:1084113024: Attached scsi generic sg0 type 0 [ 12.039272] scsi 0:0:0:1084178560: scsi scan: INQUIRY pass 1 length 36 [ 12.039319] sd 0:0:0:1084113024: Power-on or device reset occurred [ 12.039325] sd 0:0:0:1084113024: [sda] tag#640 Done: ADD_TO_MLQUEUE Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s [ 12.039328] sd 0:0:0:1084113024: [sda] tag#640 CDB: Test Unit Ready 00 00 00 00 00 00 [ 12.039330] sd 0:0:0:1084113024: [sda] tag#640 Sense Key : Unit Attention [current] [ 12.039333] sd 0:0:0:1084113024: [sda] tag#640 Add. Sense: Power on, reset, or bus device reset occurred [ 12.039384] scsi 0:0:0:1084178560: scsi scan: INQUIRY successful with code 0x0 [ 12.039404] scsi 0:0:0:1084178560: scsi scan: INQUIRY pass 2 length 164 [ 12.039505] scsi 0:0:0:1084178560: scsi scan: INQUIRY successful with code 0x0 [ 12.039510] scsi 0:0:0:1084178560: Direct-Access IBM 2107900 .102 PQ: 0 ANSI: 6 [ 12.040890] scsi 0:0:0:1084178560: alua: supports implicit TPGS [ 12.040892] scsi 0:0:0:1084178560: alua: device naa.6005076309ffd435000000000000809f port group 0 rel port 203 [ 12.040956] sd 0:0:0:1084178560: sg_alloc: dev=1 [ 12.040983] sd 0:0:0:1084178560: Attached scsi generic sg1 type 0 [ 12.041244] scsi 0:0:0:1084113025: scsi scan: INQUIRY pass 1 length 36 [ 12.041362] sd 0:0:0:1084178560: Power-on or device reset occurred [ 12.041367] sd 0:0:0:1084178560: [sdb] tag#3264 Done: ADD_TO_MLQUEUE Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s [ 12.041369] sd 0:0:0:1084178560: [sdb] tag#3264 CDB: Test Unit Ready 00 00 00 00 00 00 [ 12.041371] sd 0:0:0:1084178560: [sdb] tag#3264 Sense Key : Unit Attention [current] [ 12.041373] sd 0:0:0:1084178560: [sdb] tag#3264 Add. Sense: Power on, reset, or bus device reset occurred [ 12.041405] scsi 0:0:0:1084113025: scsi scan: INQUIRY successful with code 0x0 [ 12.041410] scsi 0:0:0:1084113025: scsi scan: INQUIRY pass 2 length 164 [ 12.041580] scsi 0:0:0:1084113025: scsi scan: INQUIRY successful with code 0x0 [ 12.041585] scsi 0:0:0:1084113025: Direct-Access IBM 2107900 .102 PQ: 0 ANSI: 6 [ 12.042960] scsi 0:0:0:1084113025: alua: supports implicit TPGS [ 12.042962] scsi 0:0:0:1084113025: alua: device naa.6005076309ffd435000000000000819e port group 0 rel port 203 [ 12.043005] sd 0:0:0:1084113025: sg_alloc: dev=2 [ 12.043063] sd 0:0:0:1084113025: Attached scsi generic sg2 type 0 [ 12.043298] scsi 0:0:0:1084178561: scsi scan: INQUIRY pass 1 length 36 [ 12.043309] sd 0:0:0:1084113025: Power-on or device reset occurred [ 12.043312] sd 0:0:0:1084113025: [sdc] tag#641 Done: ADD_TO_MLQUEUE Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s [ 12.043314] sd 0:0:0:1084113025: [sdc] tag#641 CDB: Test Unit Ready 00 00 00 00 00 00 [ 12.043316] sd 0:0:0:1084113025: [sdc] tag#641 Sense Key : Unit Attention [current] [ 12.043317] sd 0:0:0:1084113025: [sdc] tag#641 Add. Sense: Power on, reset, or bus device reset occurred [ 12.043423] scsi 0:0:0:1084178561: scsi scan: INQUIRY successful with code 0x0 [ 12.043428] scsi 0:0:0:1084178561: scsi scan: INQUIRY pass 2 length 164 [ 12.043531] scsi 0:0:0:1084178561: scsi scan: INQUIRY successful with code 0x0 [ 12.043536] scsi 0:0:0:1084178561: Direct-Access IBM 2107900 .102 PQ: 0 ANSI: 6 [ 12.044875] scsi 0:0:0:1084178561: alua: supports implicit TPGS [ 12.044877] scsi 0:0:0:1084178561: alua: device naa.6005076309ffd435000000000000819f port group 0 rel port 203 [ 12.044927] scsi 0:0:0:1084178561: sg_alloc: dev=3 [ 12.044950] scsi 0:0:0:1084178561: Attached scsi generic sg3 type 0 [ 12.045107] sd 0:0:0:1084113024: scsi scan: device exists on 0:0:0:1084113024 [ 12.045243] sd 0:0:0:1084178561: Power-on or device reset occurred [ 12.045244] sd 0:0:0:1084178560: scsi scan: device exists on 0:0:0:1084178560 [ 12.045247] sd 0:0:0:1084178561: [sdd] tag#3265 Done: ADD_TO_MLQUEUE Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s [ 12.045250] sd 0:0:0:1084178561: [sdd] tag#3265 CDB: Test Unit Ready 00 00 00 00 00 00 [ 12.045252] sd 0:0:0:1084178561: [sdd] tag#3265 Sense Key : Unit Attention [current] [ 12.045254] sd 0:0:0:1084178561: [sdd] tag#3265 Add. Sense: Power on, reset, or bus device reset occurred [ 12.045305] sd 0:0:0:1084113025: scsi scan: device exists on 0:0:0:1084113025 [ 12.045373] sd 0:0:0:1084178561: scsi scan: device exists on 0:0:0:1084178561 [ 12.050288] sd 0:0:0:1084113024: [sda] 41943040 512-byte logical blocks: (21.5 GB/20.0 GiB) [ 12.050294] sd 0:0:0:1084113024: alua: transition timeout set to 60 seconds [ 12.050309] sd 0:0:0:1084113024: alua: port group 00 state A preferred supports tolusnA [ 12.050393] sd 0:0:0:1084113024: [sda] Write Protect is off [ 12.050395] sd 0:0:0:1084113024: [sda] Mode Sense: ed 00 00 08 [ 12.050571] sd 0:0:0:1084113024: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA [ 12.050678] sd 0:0:0:1084113024: [sda] tag#648 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s [ 12.050680] sd 0:0:0:1084113024: [sda] tag#648 CDB: Report supported operation codes a3 0c 01 12 00 00 00 00 00 0a 00 00 [ 12.050682] sd 0:0:0:1084113024: [sda] tag#648 Sense Key : Illegal Request [current] [ 12.050684] sd 0:0:0:1084113024: [sda] tag#648 Add. Sense: Invalid field in cdb [ 12.052828] sd 0:0:0:1084113024: [sda] tag#651 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s [ 12.052830] sd 0:0:0:1084113024: [sda] tag#651 CDB: Inquiry 12 01 b9 00 04 00 [ 12.052832] sd 0:0:0:1084113024: [sda] tag#651 Sense Key : Illegal Request [current] [ 12.052833] sd 0:0:0:1084113024: [sda] tag#651 Add. Sense: Invalid field in cdb [ 12.054252] sda: sda1 [ 12.059079] sd 0:0:0:1084113024: [sda] Attached SCSI disk [ 12.060240] sd 0:0:0:1084113025: [sdc] 41943040 512-byte logical blocks: (21.5 GB/20.0 GiB) [ 12.060242] sd 0:0:0:1084178561: [sdd] 41943040 512-byte logical blocks: (21.5 GB/20.0 GiB) [ 12.060287] sd 0:0:0:1084178561: alua: transition timeout set to 60 seconds [ 12.060290] sd 0:0:0:1084178561: alua: port group 00 state A preferred supports tolusnA [ 12.060294] sd 0:0:0:1084113025: alua: transition timeout set to 60 seconds [ 12.060295] sd 0:0:0:1084178560: [sdb] 41943040 512-byte logical blocks: (21.5 GB/20.0 GiB) [ 12.060296] sd 0:0:0:1084113025: alua: port group 00 state A preferred supports tolusnA [ 12.060330] sd 0:0:0:1084178560: alua: transition timeout set to 60 seconds [ 12.060334] sd 0:0:0:1084113025: [sdc] Write Protect is off [ 12.060334] sd 0:0:0:1084178560: alua: port group 00 state A preferred supports tolusnA [ 12.060336] sd 0:0:0:1084178561: [sdd] Write Protect is off [ 12.060336] sd 0:0:0:1084113025: [sdc] Mode Sense: ed 00 00 08 [ 12.060339] sd 0:0:0:1084178561: [sdd] Mode Sense: ed 00 00 08 [ 12.060397] sd 0:0:0:1084178560: [sdb] Write Protect is off [ 12.060398] sd 0:0:0:1084178560: [sdb] Mode Sense: ed 00 00 08 [ 12.060544] sd 0:0:0:1084113025: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA [ 12.060544] sd 0:0:0:1084178561: [sdd] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA [ 12.060588] sd 0:0:0:1084178560: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA [ 12.060692] sd 0:0:0:1084178560: [sdb] tag#1226 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s [ 12.060695] sd 0:0:0:1084178560: [sdb] tag#1226 CDB: Report supported operation codes a3 0c 01 12 00 00 00 00 00 0a 00 00 [ 12.060697] sd 0:0:0:1084178560: [sdb] tag#1226 Sense Key : Illegal Request [current] [ 12.060699] sd 0:0:0:1084178560: [sdb] tag#1226 Add. Sense: Invalid field in cdb [ 12.060784] sd 0:0:0:1084178561: [sdd] tag#1227 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s [ 12.060786] sd 0:0:0:1084178561: [sdd] tag#1227 CDB: Report supported operation codes a3 0c 01 12 00 00 00 00 00 0a 00 00 [ 12.060788] sd 0:0:0:1084178561: [sdd] tag#1227 Sense Key : Illegal Request [current] [ 12.060790] sd 0:0:0:1084178561: [sdd] tag#1227 Add. Sense: Invalid field in cdb [ 12.060797] sd 0:0:0:1084113025: [sdc] tag#672 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s [ 12.060816] sd 0:0:0:1084178561: [sdd] Disabling DIF Type 1 protection [ 12.060817] sd 0:0:0:1084113025: [sdc] tag#672 CDB: Report supported operation codes a3 0c 01 12 00 00 00 00 00 0a 00 00 [ 12.060818] sd 0:0:0:1084178561: [sdd] Enabling DIF Type 0 protection [ 12.060820] sd 0:0:0:1084113025: [sdc] tag#672 Sense Key : Illegal Request [current] [ 12.060823] sd 0:0:0:1084113025: [sdc] tag#672 Add. Sense: Invalid field in cdb [ 12.060828] sd 0:0:0:1084113025: [sdc] Disabling DIF Type 1 protection [ 12.060830] sd 0:0:0:1084113025: [sdc] Enabling DIF Type 0 protection [ 12.063360] sd 0:0:0:1084178561: [sdd] tag#3274 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s [ 12.063363] sd 0:0:0:1084178561: [sdd] tag#3274 CDB: Inquiry 12 01 b9 00 04 00 [ 12.063364] sd 0:0:0:1084178561: [sdd] tag#3274 Sense Key : Illegal Request [current] [ 12.063367] sd 0:0:0:1084178561: [sdd] tag#3274 Add. Sense: Invalid field in cdb [ 12.063825] sd 0:0:0:1084113025: [sdc] tag#675 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s [ 12.063827] sd 0:0:0:1084113025: [sdc] tag#675 CDB: Inquiry 12 01 b9 00 04 00 [ 12.063829] sd 0:0:0:1084113025: [sdc] tag#675 Sense Key : Illegal Request [current] [ 12.063830] sd 0:0:0:1084113025: [sdc] tag#675 Add. Sense: Invalid field in cdb [ 12.063837] sd 0:0:0:1084178560: [sdb] tag#1230 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s [ 12.063839] sd 0:0:0:1084178560: [sdb] tag#1230 CDB: Inquiry 12 01 b9 00 04 00 [ 12.063841] sd 0:0:0:1084178560: [sdb] tag#1230 Sense Key : Illegal Request [current] [ 12.063843] sd 0:0:0:1084178560: [sdb] tag#1230 Add. Sense: Invalid field in cdb [ 12.063920] sd 0:0:0:1084178561: [sdd] Attached SCSI disk [ 12.064305] sd 0:0:0:1084178560: [sdb] Attached SCSI disk [ 12.064457] sd 0:0:0:1084113025: [sdc] Attached SCSI disk [ 12.118155] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 12.173553] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 12.213521] device-mapper: multipath service-time: version 0.3.0 loaded [ 12.320946] zfcp 0.0.1940: qdio: ZFCP on SC 62 using AI:1 QEBSM:0 PRI:1 TDD:1 SIGA: W [ 12.350368] scsi host1: scsi_eh_1: sleeping [ 12.350411] scsi host1: zfcp [ 12.415631] zfcp 0.0.1940: FC Endpoint Security of connection to remote port 0x500507630914d435 enabled: Encryption [ 12.417541] scsi 1:0:0:0: scsi scan: INQUIRY pass 1 length 36 [ 12.417634] scsi 1:0:0:0: scsi scan: INQUIRY successful with code 0x0 [ 12.417658] scsi 1:0:0:0: scsi scan: INQUIRY pass 2 length 164 [ 12.417749] scsi 1:0:0:0: scsi scan: INQUIRY successful with code 0x0 [ 12.417755] scsi 1:0:0:0: scsi scan: peripheral device type of 31, no device added [ 12.418087] scsi 1:0:0:0: scsi scan: Sending REPORT LUNS to (try 0) [ 12.418541] scsi 1:0:0:0: scsi scan: REPORT LUNS successful (try 0) result 0x0 [ 12.418543] scsi 1:0:0:0: scsi scan: REPORT LUN scan [ 12.418789] scsi 1:0:0:1084113024: scsi scan: INQUIRY pass 1 length 36 [ 12.418903] scsi 1:0:0:1084113024: scsi scan: INQUIRY successful with code 0x0 [ 12.418908] scsi 1:0:0:1084113024: scsi scan: INQUIRY pass 2 length 164 [ 12.419005] scsi 1:0:0:1084113024: scsi scan: INQUIRY successful with code 0x0 [ 12.419010] scsi 1:0:0:1084113024: Direct-Access IBM 2107900 .102 PQ: 0 ANSI: 6 [ 12.420462] scsi 1:0:0:1084113024: alua: supports implicit TPGS [ 12.420466] scsi 1:0:0:1084113024: alua: device naa.6005076309ffd435000000000000809e port group 0 rel port 243 [ 12.420514] sd 1:0:0:1084113024: sg_alloc: dev=4 [ 12.420566] sd 1:0:0:1084113024: Attached scsi generic sg4 type 0 [ 12.420859] scsi 1:0:0:1084178560: scsi scan: INQUIRY pass 1 length 36 [ 12.420863] sd 1:0:0:1084113024: Power-on or device reset occurred [ 12.420867] sd 1:0:0:1084113024: [sde] tag#1664 Done: ADD_TO_MLQUEUE Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s [ 12.420870] sd 1:0:0:1084113024: [sde] tag#1664 CDB: Test Unit Ready 00 00 00 00 00 00 [ 12.420872] sd 1:0:0:1084113024: [sde] tag#1664 Sense Key : Unit Attention [current] [ 12.420874] sd 1:0:0:1084113024: [sde] tag#1664 Add. Sense: Power on, reset, or bus device reset occurred [ 12.420971] scsi 1:0:0:1084178560: scsi scan: INQUIRY successful with code 0x0 [ 12.420976] scsi 1:0:0:1084178560: scsi scan: INQUIRY pass 2 length 164 [ 12.421074] scsi 1:0:0:1084178560: scsi scan: INQUIRY successful with code 0x0 [ 12.421079] scsi 1:0:0:1084178560: Direct-Access IBM 2107900 .102 PQ: 0 ANSI: 6 [ 12.422435] scsi 1:0:0:1084178560: alua: supports implicit TPGS [ 12.422438] scsi 1:0:0:1084178560: alua: device naa.6005076309ffd435000000000000809f port group 0 rel port 243 [ 12.422481] sd 1:0:0:1084178560: sg_alloc: dev=5 [ 12.422513] sd 1:0:0:1084178560: Attached scsi generic sg5 type 0 [ 12.422818] scsi 1:0:0:1084113025: scsi scan: INQUIRY pass 1 length 36 [ 12.422918] scsi 1:0:0:1084113025: scsi scan: INQUIRY successful with code 0x0 [ 12.422923] scsi 1:0:0:1084113025: scsi scan: INQUIRY pass 2 length 164 [ 12.423017] scsi 1:0:0:1084113025: scsi scan: INQUIRY successful with code 0x0 [ 12.423022] scsi 1:0:0:1084113025: Direct-Access IBM 2107900 .102 PQ: 0 ANSI: 6 [ 12.423169] sd 1:0:0:1084178560: Power-on or device reset occurred [ 12.423173] sd 1:0:0:1084178560: [sdf] tag#896 Done: ADD_TO_MLQUEUE Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s [ 12.423175] sd 1:0:0:1084178560: [sdf] tag#896 CDB: Test Unit Ready 00 00 00 00 00 00 [ 12.423176] sd 1:0:0:1084178560: [sdf] tag#896 Sense Key : Unit Attention [current] [ 12.423178] sd 1:0:0:1084178560: [sdf] tag#896 Add. Sense: Power on, reset, or bus device reset occurred [ 12.424628] scsi 1:0:0:1084113025: alua: supports implicit TPGS [ 12.424630] scsi 1:0:0:1084113025: alua: device naa.6005076309ffd435000000000000819e port group 0 rel port 243 [ 12.424675] sd 1:0:0:1084113025: sg_alloc: dev=6 [ 12.424746] sd 1:0:0:1084113025: Attached scsi generic sg6 type 0 [ 12.425035] scsi 1:0:0:1084178561: scsi scan: INQUIRY pass 1 length 36 [ 12.425136] scsi 1:0:0:1084178561: scsi scan: INQUIRY successful with code 0x0 [ 12.425141] scsi 1:0:0:1084178561: scsi scan: INQUIRY pass 2 length 164 [ 12.425154] sd 1:0:0:1084113025: Power-on or device reset occurred [ 12.425157] sd 1:0:0:1084113025: [sdg] tag#1665 Done: ADD_TO_MLQUEUE Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s [ 12.425159] sd 1:0:0:1084113025: [sdg] tag#1665 CDB: Test Unit Ready 00 00 00 00 00 00 [ 12.425161] sd 1:0:0:1084113025: [sdg] tag#1665 Sense Key : Unit Attention [current] [ 12.425163] sd 1:0:0:1084113025: [sdg] tag#1665 Add. Sense: Power on, reset, or bus device reset occurred [ 12.425233] scsi 1:0:0:1084178561: scsi scan: INQUIRY successful with code 0x0 [ 12.425238] scsi 1:0:0:1084178561: Direct-Access IBM 2107900 .102 PQ: 0 ANSI: 6 [ 12.426688] scsi 1:0:0:1084178561: alua: supports implicit TPGS [ 12.426691] scsi 1:0:0:1084178561: alua: device naa.6005076309ffd435000000000000819f port group 0 rel port 243 [ 12.426934] sd 1:0:0:1084178561: sg_alloc: dev=7 [ 12.427059] sd 1:0:0:1084178561: Attached scsi generic sg7 type 0 [ 12.427341] sd 1:0:0:1084113024: scsi scan: device exists on 1:0:0:1084113024 [ 12.427411] sd 1:0:0:1084178561: Power-on or device reset occurred [ 12.427414] sd 1:0:0:1084178561: [sdh] tag#897 Done: ADD_TO_MLQUEUE Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s [ 12.427417] sd 1:0:0:1084178561: [sdh] tag#897 CDB: Test Unit Ready 00 00 00 00 00 00 [ 12.427419] sd 1:0:0:1084178561: [sdh] tag#897 Sense Key : Unit Attention [current] [ 12.427422] sd 1:0:0:1084178561: [sdh] tag#897 Add. Sense: Power on, reset, or bus device reset occurred [ 12.427766] sd 1:0:0:1084178560: scsi scan: device exists on 1:0:0:1084178560 [ 12.428386] sd 1:0:0:1084113025: scsi scan: device exists on 1:0:0:1084113025 [ 12.428806] sd 1:0:0:1084178561: scsi scan: device exists on 1:0:0:1084178561 [ 12.440305] sd 1:0:0:1084113025: [sdg] 41943040 512-byte logical blocks: (21.5 GB/20.0 GiB) [ 12.440309] sd 1:0:0:1084113024: [sde] 41943040 512-byte logical blocks: (21.5 GB/20.0 GiB) [ 12.440328] sd 1:0:0:1084178561: [sdh] 41943040 512-byte logical blocks: (21.5 GB/20.0 GiB) [ 12.440365] sd 1:0:0:1084178560: [sdf] 41943040 512-byte logical blocks: (21.5 GB/20.0 GiB) [ 12.440405] sd 1:0:0:1084113025: [sdg] Write Protect is off [ 12.440406] sd 1:0:0:1084113025: [sdg] Mode Sense: ed 00 00 08 [ 12.440408] sd 1:0:0:1084113024: [sde] Write Protect is off [ 12.440410] sd 1:0:0:1084113024: [sde] Mode Sense: ed 00 00 08 [ 12.440426] sd 1:0:0:1084178561: [sdh] Write Protect is off [ 12.440428] sd 1:0:0:1084178561: [sdh] Mode Sense: ed 00 00 08 [ 12.440451] sd 1:0:0:1084178560: [sdf] Write Protect is off [ 12.440453] sd 1:0:0:1084178560: [sdf] Mode Sense: ed 00 00 08 [ 12.440613] sd 1:0:0:1084113025: [sdg] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA [ 12.440615] sd 1:0:0:1084113024: [sde] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA [ 12.440625] sd 1:0:0:1084178561: [sdh] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA [ 12.440627] sd 1:0:0:1084178560: [sdf] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA [ 12.440709] sd 1:0:0:1084113024: [sde] tag#2055 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s [ 12.440712] sd 1:0:0:1084113024: [sde] tag#2055 CDB: Report supported operation codes a3 0c 01 12 00 00 00 00 00 0a 00 00 [ 12.440714] sd 1:0:0:1084113024: [sde] tag#2055 Sense Key : Illegal Request [current] [ 12.440716] sd 1:0:0:1084113024: [sde] tag#2055 Add. Sense: Invalid field in cdb [ 12.440722] sd 1:0:0:1084178560: [sdf] tag#906 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s [ 12.440724] sd 1:0:0:1084178560: [sdf] tag#906 CDB: Report supported operation codes a3 0c 01 12 00 00 00 00 00 0a 00 00 [ 12.440727] sd 1:0:0:1084178560: [sdf] tag#906 Sense Key : Illegal Request [current] [ 12.440729] sd 1:0:0:1084178560: [sdf] tag#906 Add. Sense: Invalid field in cdb [ 12.440826] sd 1:0:0:1084113025: [sdg] tag#1677 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s [ 12.440846] sd 1:0:0:1084113025: [sdg] tag#1677 CDB: Report supported operation codes a3 0c 01 12 00 00 00 00 00 0a 00 00 [ 12.440849] sd 1:0:0:1084113025: [sdg] tag#1677 Sense Key : Illegal Request [current] [ 12.440851] sd 1:0:0:1084113025: [sdg] tag#1677 Add. Sense: Invalid field in cdb [ 12.440855] sd 1:0:0:1084113025: [sdg] Disabling DIF Type 1 protection [ 12.440857] sd 1:0:0:1084113025: [sdg] Enabling DIF Type 0 protection [ 12.440861] sd 1:0:0:1084178561: [sdh] tag#325 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s [ 12.440874] sd 1:0:0:1084178561: [sdh] tag#325 CDB: Report supported operation codes a3 0c 01 12 00 00 00 00 00 0a 00 00 [ 12.440881] sd 1:0:0:1084178561: [sdh] tag#325 Sense Key : Illegal Request [current] [ 12.440882] sd 1:0:0:1084178561: [sdh] tag#325 Add. Sense: Invalid field in cdb [ 12.440886] sd 1:0:0:1084178561: [sdh] Disabling DIF Type 1 protection [ 12.440888] sd 1:0:0:1084178561: [sdh] Enabling DIF Type 0 protection [ 12.443759] sd 1:0:0:1084113024: [sde] tag#1679 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s [ 12.443780] sd 1:0:0:1084113024: [sde] tag#1679 CDB: Inquiry 12 01 b9 00 04 00 [ 12.443782] sd 1:0:0:1084113024: [sde] tag#1679 Sense Key : Illegal Request [current] [ 12.443785] sd 1:0:0:1084113024: [sde] tag#1679 Add. Sense: Invalid field in cdb [ 12.443797] sd 1:0:0:1084178560: [sdf] tag#327 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s [ 12.443800] sd 1:0:0:1084178560: [sdf] tag#327 CDB: Inquiry 12 01 b9 00 04 00 [ 12.443802] sd 1:0:0:1084178560: [sdf] tag#327 Sense Key : Illegal Request [current] [ 12.443805] sd 1:0:0:1084178560: [sdf] tag#327 Add. Sense: Invalid field in cdb [ 12.443902] sd 1:0:0:1084113025: [sdg] tag#1682 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s [ 12.443905] sd 1:0:0:1084113025: [sdg] tag#1682 CDB: Inquiry 12 01 b9 00 04 00 [ 12.443908] sd 1:0:0:1084113025: [sdg] tag#1682 Sense Key : Illegal Request [current] [ 12.443910] sd 1:0:0:1084113025: [sdg] tag#1682 Add. Sense: Invalid field in cdb [ 12.443912] sd 1:0:0:1084178561: [sdh] tag#2057 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s [ 12.443917] sd 1:0:0:1084178561: [sdh] tag#2057 CDB: Inquiry 12 01 b9 00 04 00 [ 12.443919] sd 1:0:0:1084178561: [sdh] tag#2057 Sense Key : Illegal Request [current] [ 12.443921] sd 1:0:0:1084178561: [sdh] tag#2057 Add. Sense: Invalid field in cdb [ 12.444277] sd 1:0:0:1084178560: [sdf] Attached SCSI disk [ 12.444413] sd 1:0:0:1084113025: [sdg] Attached SCSI disk [ 12.444437] sd 1:0:0:1084178561: [sdh] Attached SCSI disk [ 12.445055] sde: sde1 [ 12.445135] sd 1:0:0:1084113024: [sde] Attached SCSI disk [ 12.455157] mlx5_core 0001:00:00.0 ens8192f0np0: Link up [ 12.754503] mlx5_core 0000:00:00.0 ens8320f0np0: Link up [ 12.870161] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 12.871810] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 12.873288] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 12.879490] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 12.881609] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 12.883524] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 13.129973] systemd-journald[943]: Compressed data object 621 -> 266 using ZSTD [ 13.130596] systemd-journald[943]: Compressed data object 621 -> 274 using ZSTD [ 14.130283] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 52.526889] crw_info : CRW reports slct=0, oflw=0, chn=0, rsc=B, anc=0, erc=0, rsid=0 [ 64.832872] systemd-journald[943]: Compressed data object 533 -> 400 using ZSTD [ 64.919285] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 64.928008] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 65.045916] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 65.046557] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 65.206974] systemd-journald[943]: Successfully sent stream file descriptor to service manager. [ 84.040569] livepatch: kernel.ftrace_enabled = 1 [ 84.047983] ===== TEST: basic function patching ===== [ 84.052146] % modprobe test_klp_livepatch [ 84.054139] test_klp_livepatch: tainting kernel with TAINT_LIVEPATCH [ 84.054277] livepatch: enabling patch 'test_klp_livepatch' [ 84.054279] livepatch: 'test_klp_livepatch': initializing patching transition [ 84.055514] livepatch: 'test_klp_livepatch': starting patching transition [ 84.867407] livepatch: 'test_klp_livepatch': completing patching transition [ 84.867542] livepatch: 'test_klp_livepatch': patching complete [ 84.872840] % echo 0 > /sys/kernel/livepatch/test_klp_livepatch/enabled [ 84.872891] livepatch: 'test_klp_livepatch': initializing unpatching transition [ 84.872925] livepatch: 'test_klp_livepatch': starting unpatching transition [ 85.987407] livepatch: 'test_klp_livepatch': completing unpatching transition [ 85.989034] livepatch: 'test_klp_livepatch': unpatching complete [ 86.084797] % rmmod test_klp_livepatch [ 86.153886] ===== TEST: multiple livepatches ===== [ 86.157188] % modprobe test_klp_livepatch [ 86.158657] livepatch: enabling patch 'test_klp_livepatch' [ 86.158659] livepatch: 'test_klp_livepatch': initializing patching transition [ 86.159793] livepatch: 'test_klp_livepatch': starting patching transition [ 87.027437] livepatch: 'test_klp_livepatch': completing patching transition [ 87.027546] livepatch: 'test_klp_livepatch': patching complete [ 87.078385] test_klp_livepatch: this has been live patched [ 87.083290] % modprobe test_klp_atomic_replace replace=0 [ 87.085500] livepatch: enabling patch 'test_klp_atomic_replace' [ 87.085502] livepatch: 'test_klp_atomic_replace': initializing patching transition [ 87.086685] livepatch: 'test_klp_atomic_replace': starting patching transition [ 87.907412] livepatch: 'test_klp_atomic_replace': completing patching transition [ 87.907555] livepatch: 'test_klp_atomic_replace': patching complete [ 88.004547] test_klp_livepatch: this has been live patched [ 88.005509] test_klp_atomic_replace: this has been live patched [ 88.005634] % echo 0 > /sys/kernel/livepatch/test_klp_atomic_replace/enabled [ 88.005721] livepatch: 'test_klp_atomic_replace': initializing unpatching transition [ 88.005740] livepatch: 'test_klp_atomic_replace': starting unpatching transition [ 88.947422] livepatch: 'test_klp_atomic_replace': completing unpatching transition [ 88.948800] livepatch: 'test_klp_atomic_replace': unpatching complete [ 89.016537] % rmmod test_klp_atomic_replace [ 89.097952] test_klp_livepatch: this has been live patched [ 89.099036] % echo 0 > /sys/kernel/livepatch/test_klp_livepatch/enabled [ 89.099056] livepatch: 'test_klp_livepatch': initializing unpatching transition [ 89.099079] livepatch: 'test_klp_livepatch': starting unpatching transition [ 89.907443] livepatch: 'test_klp_livepatch': completing unpatching transition [ 89.908927] livepatch: 'test_klp_livepatch': unpatching complete [ 90.008993] % rmmod test_klp_livepatch [ 90.075281] ===== TEST: atomic replace livepatch ===== [ 90.078563] % modprobe test_klp_livepatch [ 90.080025] livepatch: enabling patch 'test_klp_livepatch' [ 90.080027] livepatch: 'test_klp_livepatch': initializing patching transition [ 90.081063] livepatch: 'test_klp_livepatch': starting patching transition [ 91.667362] livepatch: 'test_klp_livepatch': completing patching transition [ 91.667466] livepatch: 'test_klp_livepatch': patching complete [ 91.711116] test_klp_livepatch: this has been live patched [ 91.715609] % modprobe test_klp_atomic_replace replace=1 [ 91.717349] livepatch: enabling patch 'test_klp_atomic_replace' [ 91.717350] livepatch: 'test_klp_atomic_replace': initializing patching transition [ 91.718440] livepatch: 'test_klp_atomic_replace': starting patching transition [ 93.027449] livepatch: 'test_klp_atomic_replace': completing patching transition [ 93.028821] livepatch: 'test_klp_atomic_replace': patching complete [ 93.044211] test_klp_atomic_replace: this has been live patched [ 93.045414] % rmmod test_klp_livepatch [ 93.138826] test_klp_atomic_replace: this has been live patched [ 93.138945] % echo 0 > /sys/kernel/livepatch/test_klp_atomic_replace/enabled [ 93.139013] livepatch: 'test_klp_atomic_replace': initializing unpatching transition [ 93.139039] livepatch: 'test_klp_atomic_replace': starting unpatching transition [ 93.987388] livepatch: 'test_klp_atomic_replace': completing unpatching transition [ 93.988892] livepatch: 'test_klp_atomic_replace': unpatching complete [ 94.048696] % rmmod test_klp_atomic_replace [ 94.131346] livepatch: kernel.ftrace_enabled = 1 [ 94.138074] ===== TEST: target module before livepatch ===== [ 94.141712] % modprobe test_klp_callbacks_mod [ 94.143390] test_klp_callbacks_mod: test_klp_callbacks_mod_init [ 94.147450] % modprobe test_klp_callbacks_demo [ 94.149518] livepatch: enabling patch 'test_klp_callbacks_demo' [ 94.149520] livepatch: 'test_klp_callbacks_demo': initializing patching transition [ 94.149584] test_klp_callbacks_demo: pre_patch_callback: vmlinux [ 94.149585] test_klp_callbacks_demo: pre_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_LIVE] Normal state [ 94.149586] livepatch: 'test_klp_callbacks_demo': starting patching transition [ 95.827310] livepatch: 'test_klp_callbacks_demo': completing patching transition [ 95.827414] test_klp_callbacks_demo: post_patch_callback: vmlinux [ 95.827416] test_klp_callbacks_demo: post_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_LIVE] Normal state [ 95.827417] livepatch: 'test_klp_callbacks_demo': patching complete [ 95.880751] % echo 0 > /sys/kernel/livepatch/test_klp_callbacks_demo/enabled [ 95.880770] livepatch: 'test_klp_callbacks_demo': initializing unpatching transition [ 95.880792] test_klp_callbacks_demo: pre_unpatch_callback: vmlinux [ 95.880793] test_klp_callbacks_demo: pre_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_LIVE] Normal state [ 95.880795] livepatch: 'test_klp_callbacks_demo': starting unpatching transition [ 96.947362] livepatch: 'test_klp_callbacks_demo': completing unpatching transition [ 96.947467] test_klp_callbacks_demo: post_unpatch_callback: vmlinux [ 96.947468] test_klp_callbacks_demo: post_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_LIVE] Normal state [ 96.947470] livepatch: 'test_klp_callbacks_demo': unpatching complete [ 96.991491] % rmmod test_klp_callbacks_demo [ 97.047939] % rmmod test_klp_callbacks_mod [ 97.049129] test_klp_callbacks_mod: test_klp_callbacks_mod_exit [ 97.123448] ===== TEST: module_coming notifier ===== [ 97.126706] % modprobe test_klp_callbacks_demo [ 97.128201] livepatch: enabling patch 'test_klp_callbacks_demo' [ 97.128202] livepatch: 'test_klp_callbacks_demo': initializing patching transition [ 97.128221] test_klp_callbacks_demo: pre_patch_callback: vmlinux [ 97.128222] livepatch: 'test_klp_callbacks_demo': starting patching transition [ 97.907366] livepatch: 'test_klp_callbacks_demo': completing patching transition [ 97.907523] test_klp_callbacks_demo: post_patch_callback: vmlinux [ 97.907524] livepatch: 'test_klp_callbacks_demo': patching complete [ 97.947504] % modprobe test_klp_callbacks_mod [ 97.948836] livepatch: applying patch 'test_klp_callbacks_demo' to loading module 'test_klp_callbacks_mod' [ 97.948839] test_klp_callbacks_demo: pre_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_COMING] Full formed, running module_init [ 97.948841] test_klp_callbacks_demo: post_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_COMING] Full formed, running module_init [ 97.948883] test_klp_callbacks_mod: test_klp_callbacks_mod_init [ 97.949244] % echo 0 > /sys/kernel/livepatch/test_klp_callbacks_demo/enabled [ 97.949263] livepatch: 'test_klp_callbacks_demo': initializing unpatching transition [ 97.949283] test_klp_callbacks_demo: pre_unpatch_callback: vmlinux [ 97.949284] test_klp_callbacks_demo: pre_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_LIVE] Normal state [ 97.949285] livepatch: 'test_klp_callbacks_demo': starting unpatching transition [ 99.117355] livepatch: 'test_klp_callbacks_demo': completing unpatching transition [ 99.117458] test_klp_callbacks_demo: post_unpatch_callback: vmlinux [ 99.117460] test_klp_callbacks_demo: post_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_LIVE] Normal state [ 99.117461] livepatch: 'test_klp_callbacks_demo': unpatching complete [ 99.160962] % rmmod test_klp_callbacks_demo [ 99.207962] % rmmod test_klp_callbacks_mod [ 99.209122] test_klp_callbacks_mod: test_klp_callbacks_mod_exit [ 99.283107] ===== TEST: module_going notifier ===== [ 99.286635] % modprobe test_klp_callbacks_mod [ 99.288047] test_klp_callbacks_mod: test_klp_callbacks_mod_init [ 99.291742] % modprobe test_klp_callbacks_demo [ 99.293440] livepatch: enabling patch 'test_klp_callbacks_demo' [ 99.293441] livepatch: 'test_klp_callbacks_demo': initializing patching transition [ 99.293462] test_klp_callbacks_demo: pre_patch_callback: vmlinux [ 99.293463] test_klp_callbacks_demo: pre_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_LIVE] Normal state [ 99.293465] livepatch: 'test_klp_callbacks_demo': starting patching transition [ 101.027350] livepatch: 'test_klp_callbacks_demo': completing patching transition [ 101.027455] test_klp_callbacks_demo: post_patch_callback: vmlinux [ 101.027456] test_klp_callbacks_demo: post_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_LIVE] Normal state [ 101.027458] livepatch: 'test_klp_callbacks_demo': patching complete [ 101.126745] % rmmod test_klp_callbacks_mod [ 101.127848] test_klp_callbacks_mod: test_klp_callbacks_mod_exit [ 101.127863] test_klp_callbacks_demo: pre_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_GOING] Going away [ 101.127865] livepatch: reverting patch 'test_klp_callbacks_demo' on unloading module 'test_klp_callbacks_mod' [ 101.127866] test_klp_callbacks_demo: post_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_GOING] Going away [ 101.187049] % echo 0 > /sys/kernel/livepatch/test_klp_callbacks_demo/enabled [ 101.187066] livepatch: 'test_klp_callbacks_demo': initializing unpatching transition [ 101.187085] test_klp_callbacks_demo: pre_unpatch_callback: vmlinux [ 101.187086] livepatch: 'test_klp_callbacks_demo': starting unpatching transition [ 102.067340] livepatch: 'test_klp_callbacks_demo': completing unpatching transition [ 102.067461] test_klp_callbacks_demo: post_unpatch_callback: vmlinux [ 102.067463] livepatch: 'test_klp_callbacks_demo': unpatching complete [ 102.096546] % rmmod test_klp_callbacks_demo [ 102.183243] ===== TEST: module_coming and module_going notifiers ===== [ 102.186391] % modprobe test_klp_callbacks_demo [ 102.187856] livepatch: enabling patch 'test_klp_callbacks_demo' [ 102.187858] livepatch: 'test_klp_callbacks_demo': initializing patching transition [ 102.187879] test_klp_callbacks_demo: pre_patch_callback: vmlinux [ 102.187881] livepatch: 'test_klp_callbacks_demo': starting patching transition [ 103.827367] livepatch: 'test_klp_callbacks_demo': completing patching transition [ 103.827510] test_klp_callbacks_demo: post_patch_callback: vmlinux [ 103.827511] livepatch: 'test_klp_callbacks_demo': patching complete [ 103.920248] % modprobe test_klp_callbacks_mod [ 103.921535] livepatch: applying patch 'test_klp_callbacks_demo' to loading module 'test_klp_callbacks_mod' [ 103.921537] test_klp_callbacks_demo: pre_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_COMING] Full formed, running module_init [ 103.921539] test_klp_callbacks_demo: post_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_COMING] Full formed, running module_init [ 103.921581] test_klp_callbacks_mod: test_klp_callbacks_mod_init [ 103.922691] % rmmod test_klp_callbacks_mod [ 103.923756] test_klp_callbacks_mod: test_klp_callbacks_mod_exit [ 103.923786] test_klp_callbacks_demo: pre_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_GOING] Going away [ 103.923788] livepatch: reverting patch 'test_klp_callbacks_demo' on unloading module 'test_klp_callbacks_mod' [ 103.923789] test_klp_callbacks_demo: post_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_GOING] Going away [ 103.987019] % echo 0 > /sys/kernel/livepatch/test_klp_callbacks_demo/enabled [ 103.987036] livepatch: 'test_klp_callbacks_demo': initializing unpatching transition [ 103.987057] test_klp_callbacks_demo: pre_unpatch_callback: vmlinux [ 103.987058] livepatch: 'test_klp_callbacks_demo': starting unpatching transition [ 105.027318] livepatch: 'test_klp_callbacks_demo': completing unpatching transition [ 105.027425] test_klp_callbacks_demo: post_unpatch_callback: vmlinux [ 105.027426] livepatch: 'test_klp_callbacks_demo': unpatching complete [ 105.096960] % rmmod test_klp_callbacks_demo [ 105.193366] ===== TEST: target module not present ===== [ 105.196426] % modprobe test_klp_callbacks_demo [ 105.197920] livepatch: enabling patch 'test_klp_callbacks_demo' [ 105.197923] livepatch: 'test_klp_callbacks_demo': initializing patching transition [ 105.197944] test_klp_callbacks_demo: pre_patch_callback: vmlinux [ 105.197945] livepatch: 'test_klp_callbacks_demo': starting patching transition [ 106.957298] livepatch: 'test_klp_callbacks_demo': completing patching transition [ 106.957421] test_klp_callbacks_demo: post_patch_callback: vmlinux [ 106.957422] livepatch: 'test_klp_callbacks_demo': patching complete [ 107.027668] % echo 0 > /sys/kernel/livepatch/test_klp_callbacks_demo/enabled [ 107.027687] livepatch: 'test_klp_callbacks_demo': initializing unpatching transition [ 107.027708] test_klp_callbacks_demo: pre_unpatch_callback: vmlinux [ 107.027709] livepatch: 'test_klp_callbacks_demo': starting unpatching transition [ 108.067334] livepatch: 'test_klp_callbacks_demo': completing unpatching transition [ 108.067440] test_klp_callbacks_demo: post_unpatch_callback: vmlinux [ 108.067441] livepatch: 'test_klp_callbacks_demo': unpatching complete [ 108.137719] % rmmod test_klp_callbacks_demo [ 108.213123] ===== TEST: pre-patch callback -ENODEV ===== [ 108.216268] % modprobe test_klp_callbacks_mod [ 108.217645] test_klp_callbacks_mod: test_klp_callbacks_mod_init [ 108.218019] % modprobe test_klp_callbacks_demo pre_patch_ret=-19 [ 108.219501] livepatch: enabling patch 'test_klp_callbacks_demo' [ 108.219503] livepatch: 'test_klp_callbacks_demo': initializing patching transition [ 108.219523] test_klp_callbacks_demo: pre_patch_callback: vmlinux [ 108.219524] livepatch: pre-patch callback failed for object 'vmlinux' [ 108.219524] livepatch: failed to enable patch 'test_klp_callbacks_demo' [ 108.219526] livepatch: 'test_klp_callbacks_demo': canceling patching transition, going to unpatch [ 108.219527] livepatch: 'test_klp_callbacks_demo': completing unpatching transition [ 108.219633] livepatch: 'test_klp_callbacks_demo': unpatching complete [ 108.366951] modprobe: ERROR: could not insert 'test_klp_callbacks_demo': No such device [ 108.367826] % rmmod test_klp_callbacks_mod [ 108.368966] test_klp_callbacks_mod: test_klp_callbacks_mod_exit [ 108.463160] ===== TEST: module_coming + pre-patch callback -ENODEV ===== [ 108.466160] % modprobe test_klp_callbacks_demo [ 108.467614] livepatch: enabling patch 'test_klp_callbacks_demo' [ 108.467616] livepatch: 'test_klp_callbacks_demo': initializing patching transition [ 108.467638] test_klp_callbacks_demo: pre_patch_callback: vmlinux [ 108.467639] livepatch: 'test_klp_callbacks_demo': starting patching transition [ 109.667362] livepatch: 'test_klp_callbacks_demo': completing patching transition [ 109.667472] test_klp_callbacks_demo: post_patch_callback: vmlinux [ 109.667473] livepatch: 'test_klp_callbacks_demo': patching complete [ 109.689019] % echo -19 > /sys/module/test_klp_callbacks_demo/parameters/pre_patch_ret [ 109.689979] % modprobe test_klp_callbacks_mod [ 109.691291] livepatch: applying patch 'test_klp_callbacks_demo' to loading module 'test_klp_callbacks_mod' [ 109.691294] test_klp_callbacks_demo: pre_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_COMING] Full formed, running module_init [ 109.691296] livepatch: pre-patch callback failed for object 'test_klp_callbacks_mod' [ 109.691297] livepatch: patch 'test_klp_callbacks_demo' failed for module 'test_klp_callbacks_mod', refusing to load module 'test_klp_callbacks_mod' [ 109.837006] modprobe: ERROR: could not insert 'test_klp_callbacks_mod': No such device [ 109.837051] % echo 0 > /sys/kernel/livepatch/test_klp_callbacks_demo/enabled [ 109.837066] livepatch: 'test_klp_callbacks_demo': initializing unpatching transition [ 109.837088] test_klp_callbacks_demo: pre_unpatch_callback: vmlinux [ 109.837089] livepatch: 'test_klp_callbacks_demo': starting unpatching transition [ 111.027394] livepatch: 'test_klp_callbacks_demo': completing unpatching transition [ 111.027554] test_klp_callbacks_demo: post_unpatch_callback: vmlinux [ 111.027555] livepatch: 'test_klp_callbacks_demo': unpatching complete [ 111.048716] % rmmod test_klp_callbacks_demo [ 111.124777] ===== TEST: multiple target modules ===== [ 111.128696] % modprobe test_klp_callbacks_busy block_transition=N [ 111.130780] test_klp_callbacks_busy: test_klp_callbacks_busy_init [ 111.130784] test_klp_callbacks_busy: busymod_work_func enter [ 111.130786] test_klp_callbacks_busy: busymod_work_func exit [ 111.134478] % modprobe test_klp_callbacks_demo [ 111.135984] livepatch: enabling patch 'test_klp_callbacks_demo' [ 111.135986] livepatch: 'test_klp_callbacks_demo': initializing patching transition [ 111.136005] test_klp_callbacks_demo: pre_patch_callback: vmlinux [ 111.136006] test_klp_callbacks_demo: pre_patch_callback: test_klp_callbacks_busy -> [MODULE_STATE_LIVE] Normal state [ 111.137437] livepatch: 'test_klp_callbacks_demo': starting patching transition [ 111.987405] livepatch: 'test_klp_callbacks_demo': completing patching transition [ 111.987513] test_klp_callbacks_demo: post_patch_callback: vmlinux [ 111.987515] test_klp_callbacks_demo: post_patch_callback: test_klp_callbacks_busy -> [MODULE_STATE_LIVE] Normal state [ 111.987516] livepatch: 'test_klp_callbacks_demo': patching complete [ 112.058064] % modprobe test_klp_callbacks_mod [ 112.059514] livepatch: applying patch 'test_klp_callbacks_demo' to loading module 'test_klp_callbacks_mod' [ 112.059516] test_klp_callbacks_demo: pre_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_COMING] Full formed, running module_init [ 112.059518] test_klp_callbacks_demo: post_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_COMING] Full formed, running module_init [ 112.059560] test_klp_callbacks_mod: test_klp_callbacks_mod_init [ 112.060788] % rmmod test_klp_callbacks_mod [ 112.061910] test_klp_callbacks_mod: test_klp_callbacks_mod_exit [ 112.061925] test_klp_callbacks_demo: pre_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_GOING] Going away [ 112.061927] livepatch: reverting patch 'test_klp_callbacks_demo' on unloading module 'test_klp_callbacks_mod' [ 112.061928] test_klp_callbacks_demo: post_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_GOING] Going away [ 112.137104] % echo 0 > /sys/kernel/livepatch/test_klp_callbacks_demo/enabled [ 112.137122] livepatch: 'test_klp_callbacks_demo': initializing unpatching transition [ 112.137143] test_klp_callbacks_demo: pre_unpatch_callback: vmlinux [ 112.137144] test_klp_callbacks_demo: pre_unpatch_callback: test_klp_callbacks_busy -> [MODULE_STATE_LIVE] Normal state [ 112.137146] livepatch: 'test_klp_callbacks_demo': starting unpatching transition [ 113.027375] livepatch: 'test_klp_callbacks_demo': completing unpatching transition [ 113.029229] test_klp_callbacks_demo: post_unpatch_callback: vmlinux [ 113.029230] test_klp_callbacks_demo: post_unpatch_callback: test_klp_callbacks_busy -> [MODULE_STATE_LIVE] Normal state [ 113.029232] livepatch: 'test_klp_callbacks_demo': unpatching complete [ 113.046037] % rmmod test_klp_callbacks_demo [ 113.117945] % rmmod test_klp_callbacks_busy [ 113.119077] test_klp_callbacks_busy: test_klp_callbacks_busy_exit [ 113.184611] ===== TEST: busy target module ===== [ 113.187764] % modprobe test_klp_callbacks_busy block_transition=Y [ 113.189352] test_klp_callbacks_busy: test_klp_callbacks_busy_init [ 113.189356] test_klp_callbacks_busy: busymod_work_func enter [ 113.192845] % modprobe test_klp_callbacks_demo [ 113.194361] livepatch: enabling patch 'test_klp_callbacks_demo' [ 113.194363] livepatch: 'test_klp_callbacks_demo': initializing patching transition [ 113.194384] test_klp_callbacks_demo: pre_patch_callback: vmlinux [ 113.194385] test_klp_callbacks_demo: pre_patch_callback: test_klp_callbacks_busy -> [MODULE_STATE_LIVE] Normal state [ 113.195818] livepatch: 'test_klp_callbacks_demo': starting patching transition [ 113.201297] % modprobe test_klp_callbacks_mod [ 113.202625] livepatch: applying patch 'test_klp_callbacks_demo' to loading module 'test_klp_callbacks_mod' [ 113.202627] test_klp_callbacks_demo: pre_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_COMING] Full formed, running module_init [ 113.202719] test_klp_callbacks_mod: test_klp_callbacks_mod_init [ 113.203890] % rmmod test_klp_callbacks_mod [ 113.204951] test_klp_callbacks_mod: test_klp_callbacks_mod_exit [ 113.204963] livepatch: reverting patch 'test_klp_callbacks_demo' on unloading module 'test_klp_callbacks_mod' [ 113.204964] test_klp_callbacks_demo: post_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_GOING] Going away [ 113.267080] % echo 0 > /sys/kernel/livepatch/test_klp_callbacks_demo/enabled [ 113.267098] livepatch: 'test_klp_callbacks_demo': reversing transition from patching to unpatching [ 113.267246] livepatch: 'test_klp_callbacks_demo': starting unpatching transition [ 115.907346] livepatch: 'test_klp_callbacks_demo': completing unpatching transition [ 115.909130] test_klp_callbacks_demo: post_unpatch_callback: vmlinux [ 115.909132] test_klp_callbacks_demo: post_unpatch_callback: test_klp_callbacks_busy -> [MODULE_STATE_LIVE] Normal state [ 115.909133] livepatch: 'test_klp_callbacks_demo': unpatching complete [ 115.989675] % rmmod test_klp_callbacks_demo [ 116.047878] % rmmod test_klp_callbacks_busy [ 116.066667] test_klp_callbacks_busy: busymod_work_func exit [ 116.066674] test_klp_callbacks_busy: test_klp_callbacks_busy_exit [ 116.194426] ===== TEST: multiple livepatches ===== [ 116.197597] % modprobe test_klp_callbacks_demo [ 116.199116] livepatch: enabling patch 'test_klp_callbacks_demo' [ 116.199118] livepatch: 'test_klp_callbacks_demo': initializing patching transition [ 116.199139] test_klp_callbacks_demo: pre_patch_callback: vmlinux [ 116.199140] livepatch: 'test_klp_callbacks_demo': starting patching transition [ 117.667375] livepatch: 'test_klp_callbacks_demo': completing patching transition [ 117.667525] test_klp_callbacks_demo: post_patch_callback: vmlinux [ 117.667527] livepatch: 'test_klp_callbacks_demo': patching complete [ 117.729276] % modprobe test_klp_callbacks_demo2 [ 117.731386] livepatch: enabling patch 'test_klp_callbacks_demo2' [ 117.731388] livepatch: 'test_klp_callbacks_demo2': initializing patching transition [ 117.731409] test_klp_callbacks_demo2: pre_patch_callback: vmlinux [ 117.731410] livepatch: 'test_klp_callbacks_demo2': starting patching transition [ 118.707443] livepatch: 'test_klp_callbacks_demo2': completing patching transition [ 118.707552] test_klp_callbacks_demo2: post_patch_callback: vmlinux [ 118.707553] livepatch: 'test_klp_callbacks_demo2': patching complete [ 118.749944] % echo 0 > /sys/kernel/livepatch/test_klp_callbacks_demo2/enabled [ 118.749964] livepatch: 'test_klp_callbacks_demo2': initializing unpatching transition [ 118.749986] test_klp_callbacks_demo2: pre_unpatch_callback: vmlinux [ 118.749987] livepatch: 'test_klp_callbacks_demo2': starting unpatching transition [ 119.907371] livepatch: 'test_klp_callbacks_demo2': completing unpatching transition [ 119.907541] test_klp_callbacks_demo2: post_unpatch_callback: vmlinux [ 119.907543] livepatch: 'test_klp_callbacks_demo2': unpatching complete [ 119.960612] % echo 0 > /sys/kernel/livepatch/test_klp_callbacks_demo/enabled [ 119.960630] livepatch: 'test_klp_callbacks_demo': initializing unpatching transition [ 119.960649] test_klp_callbacks_demo: pre_unpatch_callback: vmlinux [ 119.960650] livepatch: 'test_klp_callbacks_demo': starting unpatching transition [ 120.867332] livepatch: 'test_klp_callbacks_demo': completing unpatching transition [ 120.867435] test_klp_callbacks_demo: post_unpatch_callback: vmlinux [ 120.867436] livepatch: 'test_klp_callbacks_demo': unpatching complete [ 120.869780] % rmmod test_klp_callbacks_demo2 [ 120.917849] % rmmod test_klp_callbacks_demo [ 120.984589] ===== TEST: atomic replace ===== [ 120.987657] % modprobe test_klp_callbacks_demo [ 120.989209] livepatch: enabling patch 'test_klp_callbacks_demo' [ 120.989211] livepatch: 'test_klp_callbacks_demo': initializing patching transition [ 120.989232] test_klp_callbacks_demo: pre_patch_callback: vmlinux [ 120.989233] livepatch: 'test_klp_callbacks_demo': starting patching transition [ 121.907296] livepatch: 'test_klp_callbacks_demo': completing patching transition [ 121.907399] test_klp_callbacks_demo: post_patch_callback: vmlinux [ 121.907401] livepatch: 'test_klp_callbacks_demo': patching complete [ 122.010261] % modprobe test_klp_callbacks_demo2 replace=1 [ 122.011745] livepatch: enabling patch 'test_klp_callbacks_demo2' [ 122.011747] livepatch: 'test_klp_callbacks_demo2': initializing patching transition [ 122.011767] test_klp_callbacks_demo2: pre_patch_callback: vmlinux [ 122.011768] livepatch: 'test_klp_callbacks_demo2': starting patching transition [ 122.947337] livepatch: 'test_klp_callbacks_demo2': completing patching transition [ 122.947446] test_klp_callbacks_demo2: post_patch_callback: vmlinux [ 122.947448] livepatch: 'test_klp_callbacks_demo2': patching complete [ 123.030617] % echo 0 > /sys/kernel/livepatch/test_klp_callbacks_demo2/enabled [ 123.030637] livepatch: 'test_klp_callbacks_demo2': initializing unpatching transition [ 123.030658] test_klp_callbacks_demo2: pre_unpatch_callback: vmlinux [ 123.030659] livepatch: 'test_klp_callbacks_demo2': starting unpatching transition [ 123.907269] livepatch: 'test_klp_callbacks_demo2': completing unpatching transition [ 123.907424] test_klp_callbacks_demo2: post_unpatch_callback: vmlinux [ 123.907426] livepatch: 'test_klp_callbacks_demo2': unpatching complete [ 123.939784] % rmmod test_klp_callbacks_demo2 [ 123.987825] % rmmod test_klp_callbacks_demo [ 124.090148] livepatch: kernel.ftrace_enabled = 1 [ 124.097727] ===== TEST: basic shadow variable API ===== [ 124.101462] % modprobe test_klp_shadow_vars [ 124.103146] test_klp_shadow_vars: klp_shadow_get(obj=PTR1, id=0x1234) = PTR0 [ 124.103148] test_klp_shadow_vars: got expected NULL result [ 124.103150] test_klp_shadow_vars: shadow_ctor: PTR3 -> PTR2 [ 124.103151] test_klp_shadow_vars: klp_shadow_get_or_alloc(obj=PTR1, id=0x1234, size=8, gfp_flags=GFP_KERNEL), ctor=PTR4, ctor_data=PTR2 = PTR3 [ 124.103155] test_klp_shadow_vars: shadow_ctor: PTR6 -> PTR5 [ 124.103156] test_klp_shadow_vars: klp_shadow_alloc(obj=PTR1, id=0x1235, size=8, gfp_flags=GFP_KERNEL), ctor=PTR4, ctor_data=PTR5 = PTR6 [ 124.103158] test_klp_shadow_vars: shadow_ctor: PTR8 -> PTR7 [ 124.103160] test_klp_shadow_vars: klp_shadow_alloc(obj=PTR9, id=0x1234, size=8, gfp_flags=GFP_KERNEL), ctor=PTR4, ctor_data=PTR7 = PTR8 [ 124.103162] test_klp_shadow_vars: shadow_ctor: PTR11 -> PTR10 [ 124.103163] test_klp_shadow_vars: klp_shadow_alloc(obj=PTR9, id=0x1235, size=8, gfp_flags=GFP_KERNEL), ctor=PTR4, ctor_data=PTR10 = PTR11 [ 124.103165] test_klp_shadow_vars: shadow_ctor: PTR13 -> PTR12 [ 124.103167] test_klp_shadow_vars: klp_shadow_get_or_alloc(obj=PTR14, id=0x1234, size=8, gfp_flags=GFP_KERNEL), ctor=PTR4, ctor_data=PTR12 = PTR13 [ 124.103169] test_klp_shadow_vars: shadow_ctor: PTR16 -> PTR15 [ 124.103170] test_klp_shadow_vars: klp_shadow_alloc(obj=PTR14, id=0x1235, size=8, gfp_flags=GFP_KERNEL), ctor=PTR4, ctor_data=PTR15 = PTR16 [ 124.103173] test_klp_shadow_vars: klp_shadow_get(obj=PTR1, id=0x1234) = PTR3 [ 124.103174] test_klp_shadow_vars: got expected PTR3 -> PTR2 result [ 124.103175] test_klp_shadow_vars: klp_shadow_get(obj=PTR1, id=0x1235) = PTR6 [ 124.103176] test_klp_shadow_vars: got expected PTR6 -> PTR5 result [ 124.103177] test_klp_shadow_vars: klp_shadow_get(obj=PTR9, id=0x1234) = PTR8 [ 124.103179] test_klp_shadow_vars: got expected PTR8 -> PTR7 result [ 124.103180] test_klp_shadow_vars: klp_shadow_get(obj=PTR9, id=0x1235) = PTR11 [ 124.103181] test_klp_shadow_vars: got expected PTR11 -> PTR10 result [ 124.103182] test_klp_shadow_vars: klp_shadow_get(obj=PTR14, id=0x1234) = PTR13 [ 124.103184] test_klp_shadow_vars: got expected PTR13 -> PTR12 result [ 124.103185] test_klp_shadow_vars: klp_shadow_get(obj=PTR14, id=0x1235) = PTR16 [ 124.103186] test_klp_shadow_vars: got expected PTR16 -> PTR15 result [ 124.103187] test_klp_shadow_vars: klp_shadow_get_or_alloc(obj=PTR1, id=0x1234, size=8, gfp_flags=GFP_KERNEL), ctor=PTR4, ctor_data=PTR2 = PTR3 [ 124.103189] test_klp_shadow_vars: got expected PTR3 -> PTR2 result [ 124.103191] test_klp_shadow_vars: klp_shadow_get_or_alloc(obj=PTR9, id=0x1234, size=8, gfp_flags=GFP_KERNEL), ctor=PTR4, ctor_data=PTR7 = PTR8 [ 124.103193] test_klp_shadow_vars: got expected PTR8 -> PTR7 result [ 124.103194] test_klp_shadow_vars: klp_shadow_get_or_alloc(obj=PTR14, id=0x1234, size=8, gfp_flags=GFP_KERNEL), ctor=PTR4, ctor_data=PTR12 = PTR13 [ 124.103196] test_klp_shadow_vars: got expected PTR13 -> PTR12 result [ 124.103197] test_klp_shadow_vars: shadow_dtor(obj=PTR1, shadow_data=PTR3) [ 124.103199] test_klp_shadow_vars: klp_shadow_free(obj=PTR1, id=0x1234, dtor=PTR17) [ 124.103200] test_klp_shadow_vars: klp_shadow_get(obj=PTR1, id=0x1234) = PTR0 [ 124.103201] test_klp_shadow_vars: got expected NULL result [ 124.103202] test_klp_shadow_vars: shadow_dtor(obj=PTR9, shadow_data=PTR8) [ 124.103204] test_klp_shadow_vars: klp_shadow_free(obj=PTR9, id=0x1234, dtor=PTR17) [ 124.103205] test_klp_shadow_vars: klp_shadow_get(obj=PTR9, id=0x1234) = PTR0 [ 124.103206] test_klp_shadow_vars: got expected NULL result [ 124.103207] test_klp_shadow_vars: shadow_dtor(obj=PTR14, shadow_data=PTR13) [ 124.103208] test_klp_shadow_vars: klp_shadow_free(obj=PTR14, id=0x1234, dtor=PTR17) [ 124.103209] test_klp_shadow_vars: klp_shadow_get(obj=PTR14, id=0x1234) = PTR0 [ 124.103211] test_klp_shadow_vars: got expected NULL result [ 124.103212] test_klp_shadow_vars: klp_shadow_get(obj=PTR1, id=0x1235) = PTR6 [ 124.103213] test_klp_shadow_vars: got expected PTR6 -> PTR5 result [ 124.103214] test_klp_shadow_vars: klp_shadow_get(obj=PTR9, id=0x1235) = PTR11 [ 124.103215] test_klp_shadow_vars: got expected PTR11 -> PTR10 result [ 124.103216] test_klp_shadow_vars: klp_shadow_get(obj=PTR14, id=0x1235) = PTR16 [ 124.103218] test_klp_shadow_vars: got expected PTR16 -> PTR15 result [ 124.103231] test_klp_shadow_vars: klp_shadow_free_all(id=0x1235, dtor=PTR0) [ 124.103232] test_klp_shadow_vars: klp_shadow_get(obj=PTR1, id=0x1235) = PTR0 [ 124.103233] test_klp_shadow_vars: got expected NULL result [ 124.103234] test_klp_shadow_vars: klp_shadow_get(obj=PTR9, id=0x1235) = PTR0 [ 124.103235] test_klp_shadow_vars: got expected NULL result [ 124.103236] test_klp_shadow_vars: klp_shadow_get(obj=PTR14, id=0x1235) = PTR0 [ 124.103238] test_klp_shadow_vars: got expected NULL result [ 124.104546] % rmmod test_klp_shadow_vars [ 124.201338] livepatch: kernel.ftrace_enabled = 1 [ 124.208997] ===== TEST: system state modification ===== [ 124.212733] % modprobe test_klp_state [ 124.214788] livepatch: enabling patch 'test_klp_state' [ 124.214790] livepatch: 'test_klp_state': initializing patching transition [ 124.214811] test_klp_state: pre_patch_callback: vmlinux [ 124.214812] test_klp_state: allocate_loglevel_state: allocating space to store console_loglevel [ 124.214814] livepatch: 'test_klp_state': starting patching transition [ 125.107324] livepatch: 'test_klp_state': completing patching transition [ 125.107502] test_klp_state: post_patch_callback: vmlinux [ 125.107504] test_klp_state: fix_console_loglevel: fixing console_loglevel [ 125.107505] livepatch: 'test_klp_state': patching complete [ 125.132083] % echo 0 > /sys/kernel/livepatch/test_klp_state/enabled [ 125.132120] livepatch: 'test_klp_state': initializing unpatching transition [ 125.132141] test_klp_state: pre_unpatch_callback: vmlinux [ 125.132142] test_klp_state: restore_console_loglevel: restoring console_loglevel [ 125.132143] livepatch: 'test_klp_state': starting unpatching transition [ 125.987299] livepatch: 'test_klp_state': completing unpatching transition [ 125.987400] test_klp_state: post_unpatch_callback: vmlinux [ 125.987401] test_klp_state: free_loglevel_state: freeing space for the stored console_loglevel [ 125.987402] livepatch: 'test_klp_state': unpatching complete [ 126.040767] % rmmod test_klp_state [ 126.104509] ===== TEST: taking over system state modification ===== [ 126.107689] % modprobe test_klp_state [ 126.109150] livepatch: enabling patch 'test_klp_state' [ 126.109152] livepatch: 'test_klp_state': initializing patching transition [ 126.109173] test_klp_state: pre_patch_callback: vmlinux [ 126.109174] test_klp_state: allocate_loglevel_state: allocating space to store console_loglevel [ 126.109176] livepatch: 'test_klp_state': starting patching transition [ 127.107325] livepatch: 'test_klp_state': completing patching transition [ 127.107431] test_klp_state: post_patch_callback: vmlinux [ 127.107432] test_klp_state: fix_console_loglevel: fixing console_loglevel [ 127.107433] livepatch: 'test_klp_state': patching complete [ 127.131647] % modprobe test_klp_state2 [ 127.133754] livepatch: enabling patch 'test_klp_state2' [ 127.133756] livepatch: 'test_klp_state2': initializing patching transition [ 127.133777] test_klp_state2: pre_patch_callback: vmlinux [ 127.133778] test_klp_state2: allocate_loglevel_state: space to store console_loglevel already allocated [ 127.133779] livepatch: 'test_klp_state2': starting patching transition [ 127.987333] livepatch: 'test_klp_state2': completing patching transition [ 127.987456] test_klp_state2: post_patch_callback: vmlinux [ 127.987457] test_klp_state2: fix_console_loglevel: taking over the console_loglevel change [ 127.987458] livepatch: 'test_klp_state2': patching complete [ 128.051214] % rmmod test_klp_state [ 128.117089] % echo 0 > /sys/kernel/livepatch/test_klp_state2/enabled [ 128.117108] livepatch: 'test_klp_state2': initializing unpatching transition [ 128.117128] test_klp_state2: pre_unpatch_callback: vmlinux [ 128.117129] test_klp_state2: restore_console_loglevel: restoring console_loglevel [ 128.117131] livepatch: 'test_klp_state2': starting unpatching transition [ 129.027341] livepatch: 'test_klp_state2': completing unpatching transition [ 129.027447] test_klp_state2: post_unpatch_callback: vmlinux [ 129.027449] test_klp_state2: free_loglevel_state: freeing space for the stored console_loglevel [ 129.027451] livepatch: 'test_klp_state2': unpatching complete [ 129.127118] % rmmod test_klp_state2 [ 129.194469] ===== TEST: compatible cumulative livepatches ===== [ 129.197663] % modprobe test_klp_state2 [ 129.199144] livepatch: enabling patch 'test_klp_state2' [ 129.199146] livepatch: 'test_klp_state2': initializing patching transition [ 129.199166] test_klp_state2: pre_patch_callback: vmlinux [ 129.199167] test_klp_state2: allocate_loglevel_state: allocating space to store console_loglevel [ 129.199168] livepatch: 'test_klp_state2': starting patching transition [ 130.707290] livepatch: 'test_klp_state2': completing patching transition [ 130.707484] test_klp_state2: post_patch_callback: vmlinux [ 130.707485] test_klp_state2: fix_console_loglevel: fixing console_loglevel [ 130.707486] livepatch: 'test_klp_state2': patching complete [ 130.728829] % modprobe test_klp_state3 [ 130.730860] livepatch: enabling patch 'test_klp_state3' [ 130.730863] livepatch: 'test_klp_state3': initializing patching transition [ 130.730883] test_klp_state3: pre_patch_callback: vmlinux [ 130.730884] test_klp_state3: allocate_loglevel_state: space to store console_loglevel already allocated [ 130.730886] livepatch: 'test_klp_state3': starting patching transition [ 131.747404] livepatch: 'test_klp_state3': completing patching transition [ 131.747514] test_klp_state3: post_patch_callback: vmlinux [ 131.747516] test_klp_state3: fix_console_loglevel: taking over the console_loglevel change [ 131.747517] livepatch: 'test_klp_state3': patching complete [ 131.751280] % rmmod test_klp_state2 [ 131.830254] % modprobe test_klp_state2 [ 131.831912] livepatch: enabling patch 'test_klp_state2' [ 131.831914] livepatch: 'test_klp_state2': initializing patching transition [ 131.831932] test_klp_state2: pre_patch_callback: vmlinux [ 131.831933] test_klp_state2: allocate_loglevel_state: space to store console_loglevel already allocated [ 131.831934] livepatch: 'test_klp_state2': starting patching transition [ 132.787297] livepatch: 'test_klp_state2': completing patching transition [ 132.787417] test_klp_state2: post_patch_callback: vmlinux [ 132.787418] test_klp_state2: fix_console_loglevel: taking over the console_loglevel change [ 132.787420] livepatch: 'test_klp_state2': patching complete [ 132.849950] % echo 0 > /sys/kernel/livepatch/test_klp_state2/enabled [ 132.850015] livepatch: 'test_klp_state2': initializing unpatching transition [ 132.850036] test_klp_state2: pre_unpatch_callback: vmlinux [ 132.850037] test_klp_state2: restore_console_loglevel: restoring console_loglevel [ 132.850038] livepatch: 'test_klp_state2': starting unpatching transition [ 133.907269] livepatch: 'test_klp_state2': completing unpatching transition [ 133.907403] test_klp_state2: post_unpatch_callback: vmlinux [ 133.907405] test_klp_state2: free_loglevel_state: freeing space for the stored console_loglevel [ 133.907406] livepatch: 'test_klp_state2': unpatching complete [ 133.960649] % rmmod test_klp_state2 [ 134.007856] % rmmod test_klp_state3 [ 134.074550] ===== TEST: incompatible cumulative livepatches ===== [ 134.077882] % modprobe test_klp_state2 [ 134.079476] livepatch: enabling patch 'test_klp_state2' [ 134.079478] livepatch: 'test_klp_state2': initializing patching transition [ 134.079498] test_klp_state2: pre_patch_callback: vmlinux [ 134.079499] test_klp_state2: allocate_loglevel_state: allocating space to store console_loglevel [ 134.079501] livepatch: 'test_klp_state2': starting patching transition [ 135.587306] livepatch: 'test_klp_state2': completing patching transition [ 135.587415] test_klp_state2: post_patch_callback: vmlinux [ 135.587417] test_klp_state2: fix_console_loglevel: fixing console_loglevel [ 135.587418] livepatch: 'test_klp_state2': patching complete [ 135.606549] % modprobe test_klp_state [ 135.608261] livepatch: Livepatch patch (test_klp_state) is not compatible with the already installed livepatches. [ 135.736937] modprobe: ERROR: could not insert 'test_klp_state': Invalid argument [ 135.736975] % echo 0 > /sys/kernel/livepatch/test_klp_state2/enabled [ 135.736992] livepatch: 'test_klp_state2': initializing unpatching transition [ 135.737013] test_klp_state2: pre_unpatch_callback: vmlinux [ 135.737014] test_klp_state2: restore_console_loglevel: restoring console_loglevel [ 135.737015] livepatch: 'test_klp_state2': starting unpatching transition [ 136.947325] livepatch: 'test_klp_state2': completing unpatching transition [ 136.947481] test_klp_state2: post_unpatch_callback: vmlinux [ 136.947482] test_klp_state2: free_loglevel_state: freeing space for the stored console_loglevel [ 136.947483] livepatch: 'test_klp_state2': unpatching complete [ 136.948539] % rmmod test_klp_state2 [ 137.041414] livepatch: kernel.ftrace_enabled = 1 [ 137.049296] ===== TEST: livepatch interaction with ftrace_enabled sysctl ===== [ 137.051220] livepatch: kernel.ftrace_enabled = 0 [ 137.051281] % modprobe test_klp_livepatch [ 137.052860] livepatch: enabling patch 'test_klp_livepatch' [ 137.052862] livepatch: 'test_klp_livepatch': initializing patching transition [ 137.052885] livepatch: failed to register ftrace handler for function 'cmdline_proc_show' (-16) [ 137.052887] livepatch: failed to patch object 'vmlinux' [ 137.052888] livepatch: failed to enable patch 'test_klp_livepatch' [ 137.052889] livepatch: 'test_klp_livepatch': canceling patching transition, going to unpatch [ 137.052890] livepatch: 'test_klp_livepatch': completing unpatching transition [ 137.052996] livepatch: 'test_klp_livepatch': unpatching complete [ 137.176943] modprobe: ERROR: could not insert 'test_klp_livepatch': Device or resource busy [ 137.178976] livepatch: kernel.ftrace_enabled = 1 [ 137.182231] % modprobe test_klp_livepatch [ 137.183760] livepatch: enabling patch 'test_klp_livepatch' [ 137.183762] livepatch: 'test_klp_livepatch': initializing patching transition [ 137.184843] livepatch: 'test_klp_livepatch': starting patching transition [ 138.067403] livepatch: 'test_klp_livepatch': completing patching transition [ 138.067507] livepatch: 'test_klp_livepatch': patching complete [ 138.105610] livepatch: sysctl: setting key "kernel.ftrace_enabled": Device or resource busy [ 138.106627] % echo 0 > /sys/kernel/livepatch/test_klp_livepatch/enabled [ 138.106648] livepatch: 'test_klp_livepatch': initializing unpatching transition [ 138.106672] livepatch: 'test_klp_livepatch': starting unpatching transition [ 139.107365] livepatch: 'test_klp_livepatch': completing unpatching transition [ 139.108879] livepatch: 'test_klp_livepatch': unpatching complete [ 139.116355] % rmmod test_klp_livepatch [ 139.200586] livepatch: kernel.ftrace_enabled = 1 [ 139.208530] ===== TEST: sysfs test ===== [ 139.211756] % modprobe test_klp_livepatch [ 139.213178] livepatch: enabling patch 'test_klp_livepatch' [ 139.213180] livepatch: 'test_klp_livepatch': initializing patching transition [ 139.214331] livepatch: 'test_klp_livepatch': starting patching transition [ 140.867306] livepatch: 'test_klp_livepatch': completing patching transition [ 140.867409] livepatch: 'test_klp_livepatch': patching complete [ 140.953991] % echo 0 > /sys/kernel/livepatch/test_klp_livepatch/enabled [ 140.954006] livepatch: 'test_klp_livepatch': initializing unpatching transition [ 140.954028] livepatch: 'test_klp_livepatch': starting unpatching transition [ 141.997333] livepatch: 'test_klp_livepatch': completing unpatching transition [ 141.998940] livepatch: 'test_klp_livepatch': unpatching complete [ 142.064873] % rmmod test_klp_livepatch [ 142.144542] ===== TEST: sysfs test object/patched ===== [ 142.147844] % modprobe test_klp_callbacks_demo [ 142.149314] livepatch: enabling patch 'test_klp_callbacks_demo' [ 142.149316] livepatch: 'test_klp_callbacks_demo': initializing patching transition [ 142.149336] test_klp_callbacks_demo: pre_patch_callback: vmlinux [ 142.149337] livepatch: 'test_klp_callbacks_demo': starting patching transition [ 143.027295] livepatch: 'test_klp_callbacks_demo': completing patching transition [ 143.027399] test_klp_callbacks_demo: post_patch_callback: vmlinux [ 143.027400] livepatch: 'test_klp_callbacks_demo': patching complete [ 143.071068] % modprobe test_klp_callbacks_mod [ 143.072452] livepatch: applying patch 'test_klp_callbacks_demo' to loading module 'test_klp_callbacks_mod' [ 143.072454] test_klp_callbacks_demo: pre_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_COMING] Full formed, running module_init [ 143.072456] test_klp_callbacks_demo: post_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_COMING] Full formed, running module_init [ 143.072497] test_klp_callbacks_mod: test_klp_callbacks_mod_init [ 143.074775] % rmmod test_klp_callbacks_mod [ 143.076064] test_klp_callbacks_mod: test_klp_callbacks_mod_exit [ 143.076077] test_klp_callbacks_demo: pre_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_GOING] Going away [ 143.076079] livepatch: reverting patch 'test_klp_callbacks_demo' on unloading module 'test_klp_callbacks_mod' [ 143.076081] test_klp_callbacks_demo: post_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_GOING] Going away [ 143.137979] % echo 0 > /sys/kernel/livepatch/test_klp_callbacks_demo/enabled [ 143.138015] livepatch: 'test_klp_callbacks_demo': initializing unpatching transition [ 143.138036] test_klp_callbacks_demo: pre_unpatch_callback: vmlinux [ 143.138038] livepatch: 'test_klp_callbacks_demo': starting unpatching transition [ 144.147343] livepatch: 'test_klp_callbacks_demo': completing unpatching transition [ 144.147528] test_klp_callbacks_demo: post_unpatch_callback: vmlinux [ 144.147530] livepatch: 'test_klp_callbacks_demo': unpatching complete [ 144.249115] % rmmod test_klp_callbacks_demo [ 149.652836] livepatch: kernel.ftrace_enabled = 1 [ 149.660651] ===== TEST: basic function patching ===== [ 149.663714] % modprobe test_klp_livepatch [ 149.665324] livepatch: enabling patch 'test_klp_livepatch' [ 149.665326] livepatch: 'test_klp_livepatch': initializing patching transition [ 149.666432] livepatch: 'test_klp_livepatch': starting patching transition [ 151.027254] livepatch: 'test_klp_livepatch': completing patching transition [ 151.027390] livepatch: 'test_klp_livepatch': patching complete [ 151.092898] % echo 0 > /sys/kernel/livepatch/test_klp_livepatch/enabled [ 151.092917] livepatch: 'test_klp_livepatch': initializing unpatching transition [ 151.092934] livepatch: 'test_klp_livepatch': starting unpatching transition [ 152.067265] livepatch: 'test_klp_livepatch': completing unpatching transition [ 152.068794] livepatch: 'test_klp_livepatch': unpatching complete [ 152.102901] % rmmod test_klp_livepatch [ 152.175346] ===== TEST: multiple livepatches ===== [ 152.178402] % modprobe test_klp_livepatch [ 152.179854] livepatch: enabling patch 'test_klp_livepatch' [ 152.179857] livepatch: 'test_klp_livepatch': initializing patching transition [ 152.181052] livepatch: 'test_klp_livepatch': starting patching transition [ 153.587227] livepatch: 'test_klp_livepatch': completing patching transition [ 153.587346] livepatch: 'test_klp_livepatch': patching complete [ 153.605914] test_klp_livepatch: this has been live patched [ 153.610106] % modprobe test_klp_atomic_replace replace=0 [ 153.611743] livepatch: enabling patch 'test_klp_atomic_replace' [ 153.611746] livepatch: 'test_klp_atomic_replace': initializing patching transition [ 153.612988] livepatch: 'test_klp_atomic_replace': starting patching transition [ 154.867269] livepatch: 'test_klp_atomic_replace': completing patching transition [ 154.867427] livepatch: 'test_klp_atomic_replace': patching complete [ 154.936390] test_klp_livepatch: this has been live patched [ 154.937249] test_klp_atomic_replace: this has been live patched [ 154.937424] % echo 0 > /sys/kernel/livepatch/test_klp_atomic_replace/enabled [ 154.937443] livepatch: 'test_klp_atomic_replace': initializing unpatching transition [ 154.937463] livepatch: 'test_klp_atomic_replace': starting unpatching transition [ 156.067196] livepatch: 'test_klp_atomic_replace': completing unpatching transition [ 156.068608] livepatch: 'test_klp_atomic_replace': unpatching complete [ 156.148189] % rmmod test_klp_atomic_replace [ 156.197593] test_klp_livepatch: this has been live patched [ 156.198534] % echo 0 > /sys/kernel/livepatch/test_klp_livepatch/enabled [ 156.198551] livepatch: 'test_klp_livepatch': initializing unpatching transition [ 156.198569] livepatch: 'test_klp_livepatch': starting unpatching transition [ 157.027245] livepatch: 'test_klp_livepatch': completing unpatching transition [ 157.028678] livepatch: 'test_klp_livepatch': unpatching complete [ 157.107307] % rmmod test_klp_livepatch [ 157.196290] ===== TEST: atomic replace livepatch ===== [ 157.199586] % modprobe test_klp_livepatch [ 157.201016] livepatch: enabling patch 'test_klp_livepatch' [ 157.201018] livepatch: 'test_klp_livepatch': initializing patching transition [ 157.202113] livepatch: 'test_klp_livepatch': starting patching transition [ 159.027189] livepatch: 'test_klp_livepatch': completing patching transition [ 159.027295] livepatch: 'test_klp_livepatch': patching complete [ 159.033053] test_klp_livepatch: this has been live patched [ 159.037594] % modprobe test_klp_atomic_replace replace=1 [ 159.039272] livepatch: enabling patch 'test_klp_atomic_replace' [ 159.039274] livepatch: 'test_klp_atomic_replace': initializing patching transition [ 159.040394] livepatch: 'test_klp_atomic_replace': starting patching transition [ 160.627247] livepatch: 'test_klp_atomic_replace': completing patching transition [ 160.628733] livepatch: 'test_klp_atomic_replace': patching complete [ 160.669276] test_klp_atomic_replace: this has been live patched [ 160.670250] % rmmod test_klp_livepatch [ 160.728472] test_klp_atomic_replace: this has been live patched [ 160.728578] % echo 0 > /sys/kernel/livepatch/test_klp_atomic_replace/enabled [ 160.728647] livepatch: 'test_klp_atomic_replace': initializing unpatching transition [ 160.728675] livepatch: 'test_klp_atomic_replace': starting unpatching transition [ 162.067222] livepatch: 'test_klp_atomic_replace': completing unpatching transition [ 162.068711] livepatch: 'test_klp_atomic_replace': unpatching complete [ 162.140945] % rmmod test_klp_atomic_replace [ 162.231887] livepatch: kernel.ftrace_enabled = 1 [ 162.239588] ===== TEST: target module before livepatch ===== [ 162.242938] % modprobe test_klp_callbacks_mod [ 162.244287] test_klp_callbacks_mod: test_klp_callbacks_mod_init [ 162.247833] % modprobe test_klp_callbacks_demo [ 162.249367] livepatch: enabling patch 'test_klp_callbacks_demo' [ 162.249369] livepatch: 'test_klp_callbacks_demo': initializing patching transition [ 162.249388] test_klp_callbacks_demo: pre_patch_callback: vmlinux [ 162.249389] test_klp_callbacks_demo: pre_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_LIVE] Normal state [ 162.249406] livepatch: 'test_klp_callbacks_demo': starting patching transition [ 163.747295] livepatch: 'test_klp_callbacks_demo': completing patching transition [ 163.747452] test_klp_callbacks_demo: post_patch_callback: vmlinux [ 163.747454] test_klp_callbacks_demo: post_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_LIVE] Normal state [ 163.747456] livepatch: 'test_klp_callbacks_demo': patching complete [ 163.776543] % echo 0 > /sys/kernel/livepatch/test_klp_callbacks_demo/enabled [ 163.776563] livepatch: 'test_klp_callbacks_demo': initializing unpatching transition [ 163.776586] test_klp_callbacks_demo: pre_unpatch_callback: vmlinux [ 163.776587] test_klp_callbacks_demo: pre_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_LIVE] Normal state [ 163.776589] livepatch: 'test_klp_callbacks_demo': starting unpatching transition [ 165.027266] livepatch: 'test_klp_callbacks_demo': completing unpatching transition [ 165.027372] test_klp_callbacks_demo: post_unpatch_callback: vmlinux [ 165.027374] test_klp_callbacks_demo: post_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_LIVE] Normal state [ 165.027375] livepatch: 'test_klp_callbacks_demo': unpatching complete [ 165.088636] % rmmod test_klp_callbacks_demo [ 165.147720] % rmmod test_klp_callbacks_mod [ 165.148920] test_klp_callbacks_mod: test_klp_callbacks_mod_exit [ 165.243998] ===== TEST: module_coming notifier ===== [ 165.247169] % modprobe test_klp_callbacks_demo [ 165.248711] livepatch: enabling patch 'test_klp_callbacks_demo' [ 165.248713] livepatch: 'test_klp_callbacks_demo': initializing patching transition [ 165.248734] test_klp_callbacks_demo: pre_patch_callback: vmlinux [ 165.248735] livepatch: 'test_klp_callbacks_demo': starting patching transition [ 166.707205] livepatch: 'test_klp_callbacks_demo': completing patching transition [ 166.707378] test_klp_callbacks_demo: post_patch_callback: vmlinux [ 166.707380] livepatch: 'test_klp_callbacks_demo': patching complete [ 166.778763] % modprobe test_klp_callbacks_mod [ 166.780198] livepatch: applying patch 'test_klp_callbacks_demo' to loading module 'test_klp_callbacks_mod' [ 166.780201] test_klp_callbacks_demo: pre_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_COMING] Full formed, running module_init [ 166.780203] test_klp_callbacks_demo: post_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_COMING] Full formed, running module_init [ 166.780245] test_klp_callbacks_mod: test_klp_callbacks_mod_init [ 166.780610] % echo 0 > /sys/kernel/livepatch/test_klp_callbacks_demo/enabled [ 166.780628] livepatch: 'test_klp_callbacks_demo': initializing unpatching transition [ 166.780649] test_klp_callbacks_demo: pre_unpatch_callback: vmlinux [ 166.780650] test_klp_callbacks_demo: pre_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_LIVE] Normal state [ 166.780652] livepatch: 'test_klp_callbacks_demo': starting unpatching transition [ 168.067171] livepatch: 'test_klp_callbacks_demo': completing unpatching transition [ 168.067288] test_klp_callbacks_demo: post_unpatch_callback: vmlinux [ 168.067289] test_klp_callbacks_demo: post_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_LIVE] Normal state [ 168.067291] livepatch: 'test_klp_callbacks_demo': unpatching complete [ 168.092769] % rmmod test_klp_callbacks_demo [ 168.137636] % rmmod test_klp_callbacks_mod [ 168.138733] test_klp_callbacks_mod: test_klp_callbacks_mod_exit [ 168.214554] ===== TEST: module_going notifier ===== [ 168.217657] % modprobe test_klp_callbacks_mod [ 168.219088] test_klp_callbacks_mod: test_klp_callbacks_mod_init [ 168.222668] % modprobe test_klp_callbacks_demo [ 168.224189] livepatch: enabling patch 'test_klp_callbacks_demo' [ 168.224190] livepatch: 'test_klp_callbacks_demo': initializing patching transition [ 168.224209] test_klp_callbacks_demo: pre_patch_callback: vmlinux [ 168.224210] test_klp_callbacks_demo: pre_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_LIVE] Normal state [ 168.224211] livepatch: 'test_klp_callbacks_demo': starting patching transition [ 169.027192] livepatch: 'test_klp_callbacks_demo': completing patching transition [ 169.027294] test_klp_callbacks_demo: post_patch_callback: vmlinux [ 169.027296] test_klp_callbacks_demo: post_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_LIVE] Normal state [ 169.027297] livepatch: 'test_klp_callbacks_demo': patching complete [ 169.039955] % rmmod test_klp_callbacks_mod [ 169.041211] test_klp_callbacks_mod: test_klp_callbacks_mod_exit [ 169.041225] test_klp_callbacks_demo: pre_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_GOING] Going away [ 169.041227] livepatch: reverting patch 'test_klp_callbacks_demo' on unloading module 'test_klp_callbacks_mod' [ 169.041229] test_klp_callbacks_demo: post_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_GOING] Going away [ 169.096825] % echo 0 > /sys/kernel/livepatch/test_klp_callbacks_demo/enabled [ 169.096842] livepatch: 'test_klp_callbacks_demo': initializing unpatching transition [ 169.096860] test_klp_callbacks_demo: pre_unpatch_callback: vmlinux [ 169.096861] livepatch: 'test_klp_callbacks_demo': starting unpatching transition [ 170.067135] livepatch: 'test_klp_callbacks_demo': completing unpatching transition [ 170.067237] test_klp_callbacks_demo: post_unpatch_callback: vmlinux [ 170.067239] livepatch: 'test_klp_callbacks_demo': unpatching complete [ 170.106247] % rmmod test_klp_callbacks_demo [ 170.184203] ===== TEST: module_coming and module_going notifiers ===== [ 170.187291] % modprobe test_klp_callbacks_demo [ 170.188838] livepatch: enabling patch 'test_klp_callbacks_demo' [ 170.188840] livepatch: 'test_klp_callbacks_demo': initializing patching transition [ 170.188861] test_klp_callbacks_demo: pre_patch_callback: vmlinux [ 170.188862] livepatch: 'test_klp_callbacks_demo': starting patching transition [ 171.837198] livepatch: 'test_klp_callbacks_demo': completing patching transition [ 171.837326] test_klp_callbacks_demo: post_patch_callback: vmlinux [ 171.837328] livepatch: 'test_klp_callbacks_demo': patching complete [ 171.921732] % modprobe test_klp_callbacks_mod [ 171.923091] livepatch: applying patch 'test_klp_callbacks_demo' to loading module 'test_klp_callbacks_mod' [ 171.923094] test_klp_callbacks_demo: pre_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_COMING] Full formed, running module_init [ 171.923096] test_klp_callbacks_demo: post_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_COMING] Full formed, running module_init [ 171.923138] test_klp_callbacks_mod: test_klp_callbacks_mod_init [ 171.924441] % rmmod test_klp_callbacks_mod [ 171.925535] test_klp_callbacks_mod: test_klp_callbacks_mod_exit [ 171.925548] test_klp_callbacks_demo: pre_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_GOING] Going away [ 171.925550] livepatch: reverting patch 'test_klp_callbacks_demo' on unloading module 'test_klp_callbacks_mod' [ 171.925551] test_klp_callbacks_demo: post_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_GOING] Going away [ 171.966871] % echo 0 > /sys/kernel/livepatch/test_klp_callbacks_demo/enabled [ 171.966889] livepatch: 'test_klp_callbacks_demo': initializing unpatching transition [ 171.966909] test_klp_callbacks_demo: pre_unpatch_callback: vmlinux [ 171.966910] livepatch: 'test_klp_callbacks_demo': starting unpatching transition [ 173.027199] livepatch: 'test_klp_callbacks_demo': completing unpatching transition [ 173.027354] test_klp_callbacks_demo: post_unpatch_callback: vmlinux [ 173.027355] livepatch: 'test_klp_callbacks_demo': unpatching complete [ 173.076841] % rmmod test_klp_callbacks_demo [ 173.144067] ===== TEST: target module not present ===== [ 173.147097] % modprobe test_klp_callbacks_demo [ 173.148676] livepatch: enabling patch 'test_klp_callbacks_demo' [ 173.148678] livepatch: 'test_klp_callbacks_demo': initializing patching transition [ 173.148717] test_klp_callbacks_demo: pre_patch_callback: vmlinux [ 173.148719] livepatch: 'test_klp_callbacks_demo': starting patching transition [ 174.627151] livepatch: 'test_klp_callbacks_demo': completing patching transition [ 174.627256] test_klp_callbacks_demo: post_patch_callback: vmlinux [ 174.627257] livepatch: 'test_klp_callbacks_demo': patching complete [ 174.675094] % echo 0 > /sys/kernel/livepatch/test_klp_callbacks_demo/enabled [ 174.675112] livepatch: 'test_klp_callbacks_demo': initializing unpatching transition [ 174.675133] test_klp_callbacks_demo: pre_unpatch_callback: vmlinux [ 174.675134] livepatch: 'test_klp_callbacks_demo': starting unpatching transition [ 176.067150] livepatch: 'test_klp_callbacks_demo': completing unpatching transition [ 176.067252] test_klp_callbacks_demo: post_unpatch_callback: vmlinux [ 176.067253] livepatch: 'test_klp_callbacks_demo': unpatching complete [ 176.088083] % rmmod test_klp_callbacks_demo [ 176.194636] ===== TEST: pre-patch callback -ENODEV ===== [ 176.197807] % modprobe test_klp_callbacks_mod [ 176.199160] test_klp_callbacks_mod: test_klp_callbacks_mod_init [ 176.199520] % modprobe test_klp_callbacks_demo pre_patch_ret=-19 [ 176.201031] livepatch: enabling patch 'test_klp_callbacks_demo' [ 176.201033] livepatch: 'test_klp_callbacks_demo': initializing patching transition [ 176.201061] test_klp_callbacks_demo: pre_patch_callback: vmlinux [ 176.201062] livepatch: pre-patch callback failed for object 'vmlinux' [ 176.201063] livepatch: failed to enable patch 'test_klp_callbacks_demo' [ 176.201064] livepatch: 'test_klp_callbacks_demo': canceling patching transition, going to unpatch [ 176.201079] livepatch: 'test_klp_callbacks_demo': completing unpatching transition [ 176.201187] livepatch: 'test_klp_callbacks_demo': unpatching complete [ 176.346872] modprobe: ERROR: could not insert 'test_klp_callbacks_demo': No such device [ 176.347900] % rmmod test_klp_callbacks_mod [ 176.349044] test_klp_callbacks_mod: test_klp_callbacks_mod_exit [ 176.424402] ===== TEST: module_coming + pre-patch callback -ENODEV ===== [ 176.427567] % modprobe test_klp_callbacks_demo [ 176.429103] livepatch: enabling patch 'test_klp_callbacks_demo' [ 176.429105] livepatch: 'test_klp_callbacks_demo': initializing patching transition [ 176.429125] test_klp_callbacks_demo: pre_patch_callback: vmlinux [ 176.429126] livepatch: 'test_klp_callbacks_demo': starting patching transition [ 177.667156] livepatch: 'test_klp_callbacks_demo': completing patching transition [ 177.667260] test_klp_callbacks_demo: post_patch_callback: vmlinux [ 177.667261] livepatch: 'test_klp_callbacks_demo': patching complete [ 177.753119] % echo -19 > /sys/module/test_klp_callbacks_demo/parameters/pre_patch_ret [ 177.754056] % modprobe test_klp_callbacks_mod [ 177.755378] livepatch: applying patch 'test_klp_callbacks_demo' to loading module 'test_klp_callbacks_mod' [ 177.755381] test_klp_callbacks_demo: pre_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_COMING] Full formed, running module_init [ 177.755383] livepatch: pre-patch callback failed for object 'test_klp_callbacks_mod' [ 177.755385] livepatch: patch 'test_klp_callbacks_demo' failed for module 'test_klp_callbacks_mod', refusing to load module 'test_klp_callbacks_mod' [ 177.846782] modprobe: ERROR: could not insert 'test_klp_callbacks_mod': No such device [ 177.846853] % echo 0 > /sys/kernel/livepatch/test_klp_callbacks_demo/enabled [ 177.846869] livepatch: 'test_klp_callbacks_demo': initializing unpatching transition [ 177.846891] test_klp_callbacks_demo: pre_unpatch_callback: vmlinux [ 177.846892] livepatch: 'test_klp_callbacks_demo': starting unpatching transition [ 179.027108] livepatch: 'test_klp_callbacks_demo': completing unpatching transition [ 179.027212] test_klp_callbacks_demo: post_unpatch_callback: vmlinux [ 179.027214] livepatch: 'test_klp_callbacks_demo': unpatching complete [ 179.058400] % rmmod test_klp_callbacks_demo [ 179.124598] ===== TEST: multiple target modules ===== [ 179.127765] % modprobe test_klp_callbacks_busy block_transition=N [ 179.129305] test_klp_callbacks_busy: test_klp_callbacks_busy_init [ 179.129311] test_klp_callbacks_busy: busymod_work_func enter [ 179.129313] test_klp_callbacks_busy: busymod_work_func exit [ 179.132729] % modprobe test_klp_callbacks_demo [ 179.134243] livepatch: enabling patch 'test_klp_callbacks_demo' [ 179.134247] livepatch: 'test_klp_callbacks_demo': initializing patching transition [ 179.134267] test_klp_callbacks_demo: pre_patch_callback: vmlinux [ 179.134268] test_klp_callbacks_demo: pre_patch_callback: test_klp_callbacks_busy -> [MODULE_STATE_LIVE] Normal state [ 179.135680] livepatch: 'test_klp_callbacks_demo': starting patching transition [ 180.947100] livepatch: 'test_klp_callbacks_demo': completing patching transition [ 180.947201] test_klp_callbacks_demo: post_patch_callback: vmlinux [ 180.947203] test_klp_callbacks_demo: post_patch_callback: test_klp_callbacks_busy -> [MODULE_STATE_LIVE] Normal state [ 180.947204] livepatch: 'test_klp_callbacks_demo': patching complete [ 180.970719] % modprobe test_klp_callbacks_mod [ 180.972226] livepatch: applying patch 'test_klp_callbacks_demo' to loading module 'test_klp_callbacks_mod' [ 180.972228] test_klp_callbacks_demo: pre_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_COMING] Full formed, running module_init [ 180.972230] test_klp_callbacks_demo: post_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_COMING] Full formed, running module_init [ 180.972273] test_klp_callbacks_mod: test_klp_callbacks_mod_init [ 180.973615] % rmmod test_klp_callbacks_mod [ 180.974736] test_klp_callbacks_mod: test_klp_callbacks_mod_exit [ 180.974748] test_klp_callbacks_demo: pre_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_GOING] Going away [ 180.974750] livepatch: reverting patch 'test_klp_callbacks_demo' on unloading module 'test_klp_callbacks_mod' [ 180.974751] test_klp_callbacks_demo: post_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_GOING] Going away [ 181.046824] % echo 0 > /sys/kernel/livepatch/test_klp_callbacks_demo/enabled [ 181.046842] livepatch: 'test_klp_callbacks_demo': initializing unpatching transition [ 181.046860] test_klp_callbacks_demo: pre_unpatch_callback: vmlinux [ 181.046861] test_klp_callbacks_demo: pre_unpatch_callback: test_klp_callbacks_busy -> [MODULE_STATE_LIVE] Normal state [ 181.046863] livepatch: 'test_klp_callbacks_demo': starting unpatching transition [ 181.907102] livepatch: 'test_klp_callbacks_demo': completing unpatching transition [ 181.908849] test_klp_callbacks_demo: post_unpatch_callback: vmlinux [ 181.908851] test_klp_callbacks_demo: post_unpatch_callback: test_klp_callbacks_busy -> [MODULE_STATE_LIVE] Normal state [ 181.908853] livepatch: 'test_klp_callbacks_demo': unpatching complete [ 181.955928] % rmmod test_klp_callbacks_demo [ 182.057660] % rmmod test_klp_callbacks_busy [ 182.058777] test_klp_callbacks_busy: test_klp_callbacks_busy_exit [ 182.134704] ===== TEST: busy target module ===== [ 182.137780] % modprobe test_klp_callbacks_busy block_transition=Y [ 182.139259] test_klp_callbacks_busy: test_klp_callbacks_busy_init [ 182.139263] test_klp_callbacks_busy: busymod_work_func enter [ 182.142889] % modprobe test_klp_callbacks_demo [ 182.144362] livepatch: enabling patch 'test_klp_callbacks_demo' [ 182.144364] livepatch: 'test_klp_callbacks_demo': initializing patching transition [ 182.144382] test_klp_callbacks_demo: pre_patch_callback: vmlinux [ 182.144383] test_klp_callbacks_demo: pre_patch_callback: test_klp_callbacks_busy -> [MODULE_STATE_LIVE] Normal state [ 182.145742] livepatch: 'test_klp_callbacks_demo': starting patching transition [ 182.150873] % modprobe test_klp_callbacks_mod [ 182.152293] livepatch: applying patch 'test_klp_callbacks_demo' to loading module 'test_klp_callbacks_mod' [ 182.152296] test_klp_callbacks_demo: pre_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_COMING] Full formed, running module_init [ 182.152339] test_klp_callbacks_mod: test_klp_callbacks_mod_init [ 182.153479] % rmmod test_klp_callbacks_mod [ 182.154578] test_klp_callbacks_mod: test_klp_callbacks_mod_exit [ 182.154591] livepatch: reverting patch 'test_klp_callbacks_demo' on unloading module 'test_klp_callbacks_mod' [ 182.154592] test_klp_callbacks_demo: post_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_GOING] Going away [ 182.196952] % echo 0 > /sys/kernel/livepatch/test_klp_callbacks_demo/enabled [ 182.196973] livepatch: 'test_klp_callbacks_demo': reversing transition from patching to unpatching [ 182.197122] livepatch: 'test_klp_callbacks_demo': starting unpatching transition [ 184.947083] livepatch: 'test_klp_callbacks_demo': completing unpatching transition [ 184.948859] test_klp_callbacks_demo: post_unpatch_callback: vmlinux [ 184.948861] test_klp_callbacks_demo: post_unpatch_callback: test_klp_callbacks_busy -> [MODULE_STATE_LIVE] Normal state [ 184.948862] livepatch: 'test_klp_callbacks_demo': unpatching complete [ 185.020008] % rmmod test_klp_callbacks_demo [ 185.077670] % rmmod test_klp_callbacks_busy [ 185.106398] test_klp_callbacks_busy: busymod_work_func exit [ 185.106407] test_klp_callbacks_busy: test_klp_callbacks_busy_exit [ 185.184323] ===== TEST: multiple livepatches ===== [ 185.187426] % modprobe test_klp_callbacks_demo [ 185.188999] livepatch: enabling patch 'test_klp_callbacks_demo' [ 185.189001] livepatch: 'test_klp_callbacks_demo': initializing patching transition [ 185.189021] test_klp_callbacks_demo: pre_patch_callback: vmlinux [ 185.189022] livepatch: 'test_klp_callbacks_demo': starting patching transition [ 186.067143] livepatch: 'test_klp_callbacks_demo': completing patching transition [ 186.067283] test_klp_callbacks_demo: post_patch_callback: vmlinux [ 186.067284] livepatch: 'test_klp_callbacks_demo': patching complete [ 186.109240] % modprobe test_klp_callbacks_demo2 [ 186.110881] livepatch: enabling patch 'test_klp_callbacks_demo2' [ 186.110883] livepatch: 'test_klp_callbacks_demo2': initializing patching transition [ 186.110904] test_klp_callbacks_demo2: pre_patch_callback: vmlinux [ 186.110906] livepatch: 'test_klp_callbacks_demo2': starting patching transition [ 187.107240] livepatch: 'test_klp_callbacks_demo2': completing patching transition [ 187.107352] test_klp_callbacks_demo2: post_patch_callback: vmlinux [ 187.107353] livepatch: 'test_klp_callbacks_demo2': patching complete [ 187.129168] % echo 0 > /sys/kernel/livepatch/test_klp_callbacks_demo2/enabled [ 187.129188] livepatch: 'test_klp_callbacks_demo2': initializing unpatching transition [ 187.129208] test_klp_callbacks_demo2: pre_unpatch_callback: vmlinux [ 187.129209] livepatch: 'test_klp_callbacks_demo2': starting unpatching transition [ 187.987516] livepatch: 'test_klp_callbacks_demo2': completing unpatching transition [ 187.987618] test_klp_callbacks_demo2: post_unpatch_callback: vmlinux [ 187.987620] livepatch: 'test_klp_callbacks_demo2': unpatching complete [ 188.037170] % echo 0 > /sys/kernel/livepatch/test_klp_callbacks_demo/enabled [ 188.037188] livepatch: 'test_klp_callbacks_demo': initializing unpatching transition [ 188.037205] test_klp_callbacks_demo: pre_unpatch_callback: vmlinux [ 188.037206] livepatch: 'test_klp_callbacks_demo': starting unpatching transition [ 189.027062] livepatch: 'test_klp_callbacks_demo': completing unpatching transition [ 189.027164] test_klp_callbacks_demo: post_unpatch_callback: vmlinux [ 189.027166] livepatch: 'test_klp_callbacks_demo': unpatching complete [ 189.047265] % rmmod test_klp_callbacks_demo2 [ 189.137664] % rmmod test_klp_callbacks_demo [ 189.224455] ===== TEST: atomic replace ===== [ 189.227586] % modprobe test_klp_callbacks_demo [ 189.229201] livepatch: enabling patch 'test_klp_callbacks_demo' [ 189.229203] livepatch: 'test_klp_callbacks_demo': initializing patching transition [ 189.229222] test_klp_callbacks_demo: pre_patch_callback: vmlinux [ 189.229224] livepatch: 'test_klp_callbacks_demo': starting patching transition [ 190.067084] livepatch: 'test_klp_callbacks_demo': completing patching transition [ 190.067235] test_klp_callbacks_demo: post_patch_callback: vmlinux [ 190.067237] livepatch: 'test_klp_callbacks_demo': patching complete [ 190.148887] % modprobe test_klp_callbacks_demo2 replace=1 [ 190.150416] livepatch: enabling patch 'test_klp_callbacks_demo2' [ 190.150419] livepatch: 'test_klp_callbacks_demo2': initializing patching transition [ 190.150439] test_klp_callbacks_demo2: pre_patch_callback: vmlinux [ 190.150441] livepatch: 'test_klp_callbacks_demo2': starting patching transition [ 191.747107] livepatch: 'test_klp_callbacks_demo2': completing patching transition [ 191.747218] test_klp_callbacks_demo2: post_patch_callback: vmlinux [ 191.747220] livepatch: 'test_klp_callbacks_demo2': patching complete [ 191.778578] % echo 0 > /sys/kernel/livepatch/test_klp_callbacks_demo2/enabled [ 191.778598] livepatch: 'test_klp_callbacks_demo2': initializing unpatching transition [ 191.778619] test_klp_callbacks_demo2: pre_unpatch_callback: vmlinux [ 191.778621] livepatch: 'test_klp_callbacks_demo2': starting unpatching transition [ 192.947121] livepatch: 'test_klp_callbacks_demo2': completing unpatching transition [ 192.947227] test_klp_callbacks_demo2: post_unpatch_callback: vmlinux [ 192.947229] livepatch: 'test_klp_callbacks_demo2': unpatching complete [ 192.989892] % rmmod test_klp_callbacks_demo2 [ 193.057940] % rmmod test_klp_callbacks_demo [ 193.160197] livepatch: kernel.ftrace_enabled = 1 [ 193.167730] ===== TEST: basic shadow variable API ===== [ 193.170833] % modprobe test_klp_shadow_vars [ 193.172209] test_klp_shadow_vars: klp_shadow_get(obj=PTR1, id=0x1234) = PTR0 [ 193.172211] test_klp_shadow_vars: got expected NULL result [ 193.172213] test_klp_shadow_vars: shadow_ctor: PTR3 -> PTR2 [ 193.172214] test_klp_shadow_vars: klp_shadow_get_or_alloc(obj=PTR1, id=0x1234, size=8, gfp_flags=GFP_KERNEL), ctor=PTR4, ctor_data=PTR2 = PTR3 [ 193.172217] test_klp_shadow_vars: shadow_ctor: PTR6 -> PTR5 [ 193.172218] test_klp_shadow_vars: klp_shadow_alloc(obj=PTR1, id=0x1235, size=8, gfp_flags=GFP_KERNEL), ctor=PTR4, ctor_data=PTR5 = PTR6 [ 193.172220] test_klp_shadow_vars: shadow_ctor: PTR8 -> PTR7 [ 193.172221] test_klp_shadow_vars: klp_shadow_alloc(obj=PTR9, id=0x1234, size=8, gfp_flags=GFP_KERNEL), ctor=PTR4, ctor_data=PTR7 = PTR8 [ 193.172224] test_klp_shadow_vars: shadow_ctor: PTR11 -> PTR10 [ 193.172225] test_klp_shadow_vars: klp_shadow_alloc(obj=PTR9, id=0x1235, size=8, gfp_flags=GFP_KERNEL), ctor=PTR4, ctor_data=PTR10 = PTR11 [ 193.172227] test_klp_shadow_vars: shadow_ctor: PTR13 -> PTR12 [ 193.172229] test_klp_shadow_vars: klp_shadow_get_or_alloc(obj=PTR14, id=0x1234, size=8, gfp_flags=GFP_KERNEL), ctor=PTR4, ctor_data=PTR12 = PTR13 [ 193.172231] test_klp_shadow_vars: shadow_ctor: PTR16 -> PTR15 [ 193.172232] test_klp_shadow_vars: klp_shadow_alloc(obj=PTR14, id=0x1235, size=8, gfp_flags=GFP_KERNEL), ctor=PTR4, ctor_data=PTR15 = PTR16 [ 193.172234] test_klp_shadow_vars: klp_shadow_get(obj=PTR1, id=0x1234) = PTR3 [ 193.172236] test_klp_shadow_vars: got expected PTR3 -> PTR2 result [ 193.172237] test_klp_shadow_vars: klp_shadow_get(obj=PTR1, id=0x1235) = PTR6 [ 193.172238] test_klp_shadow_vars: got expected PTR6 -> PTR5 result [ 193.172239] test_klp_shadow_vars: klp_shadow_get(obj=PTR9, id=0x1234) = PTR8 [ 193.172240] test_klp_shadow_vars: got expected PTR8 -> PTR7 result [ 193.172241] test_klp_shadow_vars: klp_shadow_get(obj=PTR9, id=0x1235) = PTR11 [ 193.172243] test_klp_shadow_vars: got expected PTR11 -> PTR10 result [ 193.172244] test_klp_shadow_vars: klp_shadow_get(obj=PTR14, id=0x1234) = PTR13 [ 193.172245] test_klp_shadow_vars: got expected PTR13 -> PTR12 result [ 193.172246] test_klp_shadow_vars: klp_shadow_get(obj=PTR14, id=0x1235) = PTR16 [ 193.172247] test_klp_shadow_vars: got expected PTR16 -> PTR15 result [ 193.172249] test_klp_shadow_vars: klp_shadow_get_or_alloc(obj=PTR1, id=0x1234, size=8, gfp_flags=GFP_KERNEL), ctor=PTR4, ctor_data=PTR2 = PTR3 [ 193.172251] test_klp_shadow_vars: got expected PTR3 -> PTR2 result [ 193.172252] test_klp_shadow_vars: klp_shadow_get_or_alloc(obj=PTR9, id=0x1234, size=8, gfp_flags=GFP_KERNEL), ctor=PTR4, ctor_data=PTR7 = PTR8 [ 193.172254] test_klp_shadow_vars: got expected PTR8 -> PTR7 result [ 193.172255] test_klp_shadow_vars: klp_shadow_get_or_alloc(obj=PTR14, id=0x1234, size=8, gfp_flags=GFP_KERNEL), ctor=PTR4, ctor_data=PTR12 = PTR13 [ 193.172257] test_klp_shadow_vars: got expected PTR13 -> PTR12 result [ 193.172258] test_klp_shadow_vars: shadow_dtor(obj=PTR1, shadow_data=PTR3) [ 193.172260] test_klp_shadow_vars: klp_shadow_free(obj=PTR1, id=0x1234, dtor=PTR17) [ 193.172261] test_klp_shadow_vars: klp_shadow_get(obj=PTR1, id=0x1234) = PTR0 [ 193.172262] test_klp_shadow_vars: got expected NULL result [ 193.172263] test_klp_shadow_vars: shadow_dtor(obj=PTR9, shadow_data=PTR8) [ 193.172265] test_klp_shadow_vars: klp_shadow_free(obj=PTR9, id=0x1234, dtor=PTR17) [ 193.172266] test_klp_shadow_vars: klp_shadow_get(obj=PTR9, id=0x1234) = PTR0 [ 193.172267] test_klp_shadow_vars: got expected NULL result [ 193.172268] test_klp_shadow_vars: shadow_dtor(obj=PTR14, shadow_data=PTR13) [ 193.172269] test_klp_shadow_vars: klp_shadow_free(obj=PTR14, id=0x1234, dtor=PTR17) [ 193.172270] test_klp_shadow_vars: klp_shadow_get(obj=PTR14, id=0x1234) = PTR0 [ 193.172271] test_klp_shadow_vars: got expected NULL result [ 193.172272] test_klp_shadow_vars: klp_shadow_get(obj=PTR1, id=0x1235) = PTR6 [ 193.172274] test_klp_shadow_vars: got expected PTR6 -> PTR5 result [ 193.172275] test_klp_shadow_vars: klp_shadow_get(obj=PTR9, id=0x1235) = PTR11 [ 193.172276] test_klp_shadow_vars: got expected PTR11 -> PTR10 result [ 193.172277] test_klp_shadow_vars: klp_shadow_get(obj=PTR14, id=0x1235) = PTR16 [ 193.172278] test_klp_shadow_vars: got expected PTR16 -> PTR15 result [ 193.172287] test_klp_shadow_vars: klp_shadow_free_all(id=0x1235, dtor=PTR0) [ 193.172288] test_klp_shadow_vars: klp_shadow_get(obj=PTR1, id=0x1235) = PTR0 [ 193.172289] test_klp_shadow_vars: got expected NULL result [ 193.172290] test_klp_shadow_vars: klp_shadow_get(obj=PTR9, id=0x1235) = PTR0 [ 193.172291] test_klp_shadow_vars: got expected NULL result [ 193.172292] test_klp_shadow_vars: klp_shadow_get(obj=PTR14, id=0x1235) = PTR0 [ 193.172293] test_klp_shadow_vars: got expected NULL result [ 193.173588] % rmmod test_klp_shadow_vars [ 193.270211] livepatch: kernel.ftrace_enabled = 1 [ 193.277772] ===== TEST: system state modification ===== [ 193.280982] % modprobe test_klp_state [ 193.282421] livepatch: enabling patch 'test_klp_state' [ 193.282422] livepatch: 'test_klp_state': initializing patching transition [ 193.282443] test_klp_state: pre_patch_callback: vmlinux [ 193.282444] test_klp_state: allocate_loglevel_state: allocating space to store console_loglevel [ 193.282445] livepatch: 'test_klp_state': starting patching transition [ 194.627016] livepatch: 'test_klp_state': completing patching transition [ 194.627121] test_klp_state: post_patch_callback: vmlinux [ 194.627122] test_klp_state: fix_console_loglevel: fixing console_loglevel [ 194.627123] livepatch: 'test_klp_state': patching complete [ 194.707923] % echo 0 > /sys/kernel/livepatch/test_klp_state/enabled [ 194.707943] livepatch: 'test_klp_state': initializing unpatching transition [ 194.707962] test_klp_state: pre_unpatch_callback: vmlinux [ 194.707963] test_klp_state: restore_console_loglevel: restoring console_loglevel [ 194.707964] livepatch: 'test_klp_state': starting unpatching transition [ 195.667037] livepatch: 'test_klp_state': completing unpatching transition [ 195.667141] test_klp_state: post_unpatch_callback: vmlinux [ 195.667143] test_klp_state: free_loglevel_state: freeing space for the stored console_loglevel [ 195.667144] livepatch: 'test_klp_state': unpatching complete [ 195.718014] % rmmod test_klp_state [ 195.794830] ===== TEST: taking over system state modification ===== [ 195.797971] % modprobe test_klp_state [ 195.799572] livepatch: enabling patch 'test_klp_state' [ 195.799574] livepatch: 'test_klp_state': initializing patching transition [ 195.799595] test_klp_state: pre_patch_callback: vmlinux [ 195.799596] test_klp_state: allocate_loglevel_state: allocating space to store console_loglevel [ 195.799598] livepatch: 'test_klp_state': starting patching transition [ 196.867056] livepatch: 'test_klp_state': completing patching transition [ 196.867162] test_klp_state: post_patch_callback: vmlinux [ 196.867164] test_klp_state: fix_console_loglevel: fixing console_loglevel [ 196.867165] livepatch: 'test_klp_state': patching complete [ 196.922499] % modprobe test_klp_state2 [ 196.924010] livepatch: enabling patch 'test_klp_state2' [ 196.924012] livepatch: 'test_klp_state2': initializing patching transition [ 196.924032] test_klp_state2: pre_patch_callback: vmlinux [ 196.924033] test_klp_state2: allocate_loglevel_state: space to store console_loglevel already allocated [ 196.924034] livepatch: 'test_klp_state2': starting patching transition [ 198.627070] livepatch: 'test_klp_state2': completing patching transition [ 198.627227] test_klp_state2: post_patch_callback: vmlinux [ 198.627229] test_klp_state2: fix_console_loglevel: taking over the console_loglevel change [ 198.627230] livepatch: 'test_klp_state2': patching complete [ 198.654169] % rmmod test_klp_state [ 198.696775] % echo 0 > /sys/kernel/livepatch/test_klp_state2/enabled [ 198.696796] livepatch: 'test_klp_state2': initializing unpatching transition [ 198.696818] test_klp_state2: pre_unpatch_callback: vmlinux [ 198.696820] test_klp_state2: restore_console_loglevel: restoring console_loglevel [ 198.696821] livepatch: 'test_klp_state2': starting unpatching transition [ 199.667041] livepatch: 'test_klp_state2': completing unpatching transition [ 199.667222] test_klp_state2: post_unpatch_callback: vmlinux [ 199.667223] test_klp_state2: free_loglevel_state: freeing space for the stored console_loglevel [ 199.667224] livepatch: 'test_klp_state2': unpatching complete [ 199.706641] % rmmod test_klp_state2 [ 199.794709] ===== TEST: compatible cumulative livepatches ===== [ 199.797951] % modprobe test_klp_state2 [ 199.799497] livepatch: enabling patch 'test_klp_state2' [ 199.799500] livepatch: 'test_klp_state2': initializing patching transition [ 199.799521] test_klp_state2: pre_patch_callback: vmlinux [ 199.799522] test_klp_state2: allocate_loglevel_state: allocating space to store console_loglevel [ 199.799524] livepatch: 'test_klp_state2': starting patching transition [ 200.707033] livepatch: 'test_klp_state2': completing patching transition [ 200.707156] test_klp_state2: post_patch_callback: vmlinux [ 200.707158] test_klp_state2: fix_console_loglevel: fixing console_loglevel [ 200.707159] livepatch: 'test_klp_state2': patching complete [ 200.719453] % modprobe test_klp_state3 [ 200.721036] livepatch: enabling patch 'test_klp_state3' [ 200.721040] livepatch: 'test_klp_state3': initializing patching transition [ 200.721063] test_klp_state3: pre_patch_callback: vmlinux [ 200.721064] test_klp_state3: allocate_loglevel_state: space to store console_loglevel already allocated [ 200.721065] livepatch: 'test_klp_state3': starting patching transition [ 201.667030] livepatch: 'test_klp_state3': completing patching transition [ 201.667132] test_klp_state3: post_patch_callback: vmlinux [ 201.667134] test_klp_state3: fix_console_loglevel: taking over the console_loglevel change [ 201.667135] livepatch: 'test_klp_state3': patching complete [ 201.740654] % rmmod test_klp_state2 [ 201.790108] % modprobe test_klp_state2 [ 201.791613] livepatch: enabling patch 'test_klp_state2' [ 201.791616] livepatch: 'test_klp_state2': initializing patching transition [ 201.791636] test_klp_state2: pre_patch_callback: vmlinux [ 201.791637] test_klp_state2: allocate_loglevel_state: space to store console_loglevel already allocated [ 201.791639] livepatch: 'test_klp_state2': starting patching transition [ 202.947001] livepatch: 'test_klp_state2': completing patching transition [ 202.947134] test_klp_state2: post_patch_callback: vmlinux [ 202.947136] test_klp_state2: fix_console_loglevel: taking over the console_loglevel change [ 202.947137] livepatch: 'test_klp_state2': patching complete [ 203.013457] % echo 0 > /sys/kernel/livepatch/test_klp_state2/enabled [ 203.013476] livepatch: 'test_klp_state2': initializing unpatching transition [ 203.013497] test_klp_state2: pre_unpatch_callback: vmlinux [ 203.013498] test_klp_state2: restore_console_loglevel: restoring console_loglevel [ 203.013499] livepatch: 'test_klp_state2': starting unpatching transition [ 204.627021] livepatch: 'test_klp_state2': completing unpatching transition [ 204.627127] test_klp_state2: post_unpatch_callback: vmlinux [ 204.627128] test_klp_state2: free_loglevel_state: freeing space for the stored console_loglevel [ 204.627130] livepatch: 'test_klp_state2': unpatching complete [ 204.628240] % rmmod test_klp_state2 [ 204.677492] % rmmod test_klp_state3 [ 204.754498] ===== TEST: incompatible cumulative livepatches ===== [ 204.757803] % modprobe test_klp_state2 [ 204.759469] livepatch: enabling patch 'test_klp_state2' [ 204.759471] livepatch: 'test_klp_state2': initializing patching transition [ 204.759509] test_klp_state2: pre_patch_callback: vmlinux [ 204.759511] test_klp_state2: allocate_loglevel_state: allocating space to store console_loglevel [ 204.759512] livepatch: 'test_klp_state2': starting patching transition [ 205.667054] livepatch: 'test_klp_state2': completing patching transition [ 205.667221] test_klp_state2: post_patch_callback: vmlinux [ 205.667223] test_klp_state2: fix_console_loglevel: fixing console_loglevel [ 205.667224] livepatch: 'test_klp_state2': patching complete [ 205.676418] % modprobe test_klp_state [ 205.678021] livepatch: Livepatch patch (test_klp_state) is not compatible with the already installed livepatches. [ 205.796666] modprobe: ERROR: could not insert 'test_klp_state': Invalid argument [ 205.796711] % echo 0 > /sys/kernel/livepatch/test_klp_state2/enabled [ 205.796727] livepatch: 'test_klp_state2': initializing unpatching transition [ 205.796748] test_klp_state2: pre_unpatch_callback: vmlinux [ 205.796749] test_klp_state2: restore_console_loglevel: restoring console_loglevel [ 205.796750] livepatch: 'test_klp_state2': starting unpatching transition [ 206.627024] livepatch: 'test_klp_state2': completing unpatching transition [ 206.627126] test_klp_state2: post_unpatch_callback: vmlinux [ 206.627127] test_klp_state2: free_loglevel_state: freeing space for the stored console_loglevel [ 206.627128] livepatch: 'test_klp_state2': unpatching complete [ 206.705649] % rmmod test_klp_state2 [ 206.799832] livepatch: kernel.ftrace_enabled = 1 [ 206.807523] ===== TEST: livepatch interaction with ftrace_enabled sysctl ===== [ 206.809453] livepatch: kernel.ftrace_enabled = 0 [ 206.809519] % modprobe test_klp_livepatch [ 206.811132] livepatch: enabling patch 'test_klp_livepatch' [ 206.811134] livepatch: 'test_klp_livepatch': initializing patching transition [ 206.811157] livepatch: failed to register ftrace handler for function 'cmdline_proc_show' (-16) [ 206.811159] livepatch: failed to patch object 'vmlinux' [ 206.811160] livepatch: failed to enable patch 'test_klp_livepatch' [ 206.811161] livepatch: 'test_klp_livepatch': canceling patching transition, going to unpatch [ 206.811162] livepatch: 'test_klp_livepatch': completing unpatching transition [ 206.811267] livepatch: 'test_klp_livepatch': unpatching complete [ 206.946752] modprobe: ERROR: could not insert 'test_klp_livepatch': Device or resource busy [ 206.948665] livepatch: kernel.ftrace_enabled = 1 [ 206.951864] % modprobe test_klp_livepatch [ 206.953500] livepatch: enabling patch 'test_klp_livepatch' [ 206.953502] livepatch: 'test_klp_livepatch': initializing patching transition [ 206.954621] livepatch: 'test_klp_livepatch': starting patching transition [ 208.147074] livepatch: 'test_klp_livepatch': completing patching transition [ 208.147180] livepatch: 'test_klp_livepatch': patching complete [ 208.181130] livepatch: sysctl: setting key "kernel.ftrace_enabled": Device or resource busy [ 208.182202] % echo 0 > /sys/kernel/livepatch/test_klp_livepatch/enabled [ 208.182223] livepatch: 'test_klp_livepatch': initializing unpatching transition [ 208.182241] livepatch: 'test_klp_livepatch': starting unpatching transition [ 209.106989] livepatch: 'test_klp_livepatch': completing unpatching transition [ 209.108516] livepatch: 'test_klp_livepatch': unpatching complete [ 209.192468] % rmmod test_klp_livepatch [ 209.269412] livepatch: kernel.ftrace_enabled = 1 [ 209.277289] ===== TEST: sysfs test ===== [ 209.280562] % modprobe test_klp_livepatch [ 209.282041] livepatch: enabling patch 'test_klp_livepatch' [ 209.282043] livepatch: 'test_klp_livepatch': initializing patching transition [ 209.283130] livepatch: 'test_klp_livepatch': starting patching transition [ 210.946994] livepatch: 'test_klp_livepatch': completing patching transition [ 210.947096] livepatch: 'test_klp_livepatch': patching complete [ 211.020069] % echo 0 > /sys/kernel/livepatch/test_klp_livepatch/enabled [ 211.020084] livepatch: 'test_klp_livepatch': initializing unpatching transition [ 211.020103] livepatch: 'test_klp_livepatch': starting unpatching transition [ 211.906955] livepatch: 'test_klp_livepatch': completing unpatching transition [ 211.908429] livepatch: 'test_klp_livepatch': unpatching complete [ 211.928959] % rmmod test_klp_livepatch [ 212.004690] ===== TEST: sysfs test object/patched ===== [ 212.007954] % modprobe test_klp_callbacks_demo [ 212.009626] livepatch: enabling patch 'test_klp_callbacks_demo' [ 212.009628] livepatch: 'test_klp_callbacks_demo': initializing patching transition [ 212.009649] test_klp_callbacks_demo: pre_patch_callback: vmlinux [ 212.009650] livepatch: 'test_klp_callbacks_demo': starting patching transition [ 213.106985] livepatch: 'test_klp_callbacks_demo': completing patching transition [ 213.107148] test_klp_callbacks_demo: post_patch_callback: vmlinux [ 213.107150] livepatch: 'test_klp_callbacks_demo': patching complete [ 213.133983] % modprobe test_klp_callbacks_mod [ 213.135432] livepatch: applying patch 'test_klp_callbacks_demo' to loading module 'test_klp_callbacks_mod' [ 213.135434] test_klp_callbacks_demo: pre_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_COMING] Full formed, running module_init [ 213.135436] test_klp_callbacks_demo: post_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_COMING] Full formed, running module_init [ 213.135478] test_klp_callbacks_mod: test_klp_callbacks_mod_init [ 213.137671] % rmmod test_klp_callbacks_mod [ 213.138782] test_klp_callbacks_mod: test_klp_callbacks_mod_exit [ 213.138796] test_klp_callbacks_demo: pre_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_GOING] Going away [ 213.138798] livepatch: reverting patch 'test_klp_callbacks_demo' on unloading module 'test_klp_callbacks_mod' [ 213.138799] test_klp_callbacks_demo: post_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_GOING] Going away [ 213.187620] % echo 0 > /sys/kernel/livepatch/test_klp_callbacks_demo/enabled [ 213.187639] livepatch: 'test_klp_callbacks_demo': initializing unpatching transition [ 213.187660] test_klp_callbacks_demo: pre_unpatch_callback: vmlinux [ 213.187661] livepatch: 'test_klp_callbacks_demo': starting unpatching transition [ 214.956966] livepatch: 'test_klp_callbacks_demo': completing unpatching transition [ 214.957069] test_klp_callbacks_demo: post_unpatch_callback: vmlinux [ 214.957070] livepatch: 'test_klp_callbacks_demo': unpatching complete [ 215.004034] % rmmod test_klp_callbacks_demo [ 216.486413] livepatch: kernel.ftrace_enabled = 1 [ 216.494184] ===== TEST: basic function patching ===== [ 216.497478] % modprobe test_klp_livepatch [ 216.499123] livepatch: enabling patch 'test_klp_livepatch' [ 216.499125] livepatch: 'test_klp_livepatch': initializing patching transition [ 216.500232] livepatch: 'test_klp_livepatch': starting patching transition [ 217.906980] livepatch: 'test_klp_livepatch': completing patching transition [ 217.907138] livepatch: 'test_klp_livepatch': patching complete [ 217.927548] % echo 0 > /sys/kernel/livepatch/test_klp_livepatch/enabled [ 217.927569] livepatch: 'test_klp_livepatch': initializing unpatching transition [ 217.927590] livepatch: 'test_klp_livepatch': starting unpatching transition [ 218.947043] livepatch: 'test_klp_livepatch': completing unpatching transition [ 218.948644] livepatch: 'test_klp_livepatch': unpatching complete [ 219.038726] % rmmod test_klp_livepatch [ 219.115033] ===== TEST: multiple livepatches ===== [ 219.118186] % modprobe test_klp_livepatch [ 219.119788] livepatch: enabling patch 'test_klp_livepatch' [ 219.119790] livepatch: 'test_klp_livepatch': initializing patching transition [ 219.120986] livepatch: 'test_klp_livepatch': starting patching transition [ 220.866989] livepatch: 'test_klp_livepatch': completing patching transition [ 220.867145] livepatch: 'test_klp_livepatch': patching complete [ 220.952783] test_klp_livepatch: this has been live patched [ 220.957044] % modprobe test_klp_atomic_replace replace=0 [ 220.958580] livepatch: enabling patch 'test_klp_atomic_replace' [ 220.958582] livepatch: 'test_klp_atomic_replace': initializing patching transition [ 220.959660] livepatch: 'test_klp_atomic_replace': starting patching transition [ 221.826984] livepatch: 'test_klp_atomic_replace': completing patching transition [ 221.827087] livepatch: 'test_klp_atomic_replace': patching complete [ 221.877823] test_klp_livepatch: this has been live patched [ 221.878665] test_klp_atomic_replace: this has been live patched [ 221.878801] % echo 0 > /sys/kernel/livepatch/test_klp_atomic_replace/enabled [ 221.878822] livepatch: 'test_klp_atomic_replace': initializing unpatching transition [ 221.878843] livepatch: 'test_klp_atomic_replace': starting unpatching transition [ 222.947011] livepatch: 'test_klp_atomic_replace': completing unpatching transition [ 222.948465] livepatch: 'test_klp_atomic_replace': unpatching complete [ 222.989788] % rmmod test_klp_atomic_replace [ 223.047531] test_klp_livepatch: this has been live patched [ 223.048613] % echo 0 > /sys/kernel/livepatch/test_klp_livepatch/enabled [ 223.048632] livepatch: 'test_klp_livepatch': initializing unpatching transition [ 223.048654] livepatch: 'test_klp_livepatch': starting unpatching transition [ 223.987012] livepatch: 'test_klp_livepatch': completing unpatching transition [ 223.988534] livepatch: 'test_klp_livepatch': unpatching complete [ 224.059000] % rmmod test_klp_livepatch [ 224.156318] ===== TEST: atomic replace livepatch ===== [ 224.159489] % modprobe test_klp_livepatch [ 224.160923] livepatch: enabling patch 'test_klp_livepatch' [ 224.160926] livepatch: 'test_klp_livepatch': initializing patching transition [ 224.162024] livepatch: 'test_klp_livepatch': starting patching transition [ 225.666965] livepatch: 'test_klp_livepatch': completing patching transition [ 225.667118] livepatch: 'test_klp_livepatch': patching complete [ 225.689716] test_klp_livepatch: this has been live patched [ 225.693937] % modprobe test_klp_atomic_replace replace=1 [ 225.695517] livepatch: enabling patch 'test_klp_atomic_replace' [ 225.695519] livepatch: 'test_klp_atomic_replace': initializing patching transition [ 225.696644] livepatch: 'test_klp_atomic_replace': starting patching transition [ 226.786967] livepatch: 'test_klp_atomic_replace': completing patching transition [ 226.788286] livepatch: 'test_klp_atomic_replace': patching complete [ 226.818010] test_klp_atomic_replace: this has been live patched [ 226.819031] % rmmod test_klp_livepatch [ 226.878235] test_klp_atomic_replace: this has been live patched [ 226.878402] % echo 0 > /sys/kernel/livepatch/test_klp_atomic_replace/enabled [ 226.878421] livepatch: 'test_klp_atomic_replace': initializing unpatching transition [ 226.878443] livepatch: 'test_klp_atomic_replace': starting unpatching transition [ 227.907041] livepatch: 'test_klp_atomic_replace': completing unpatching transition [ 227.908601] livepatch: 'test_klp_atomic_replace': unpatching complete [ 227.988889] % rmmod test_klp_atomic_replace [ 228.081616] livepatch: kernel.ftrace_enabled = 1 [ 228.089746] ===== TEST: target module before livepatch ===== [ 228.093012] % modprobe test_klp_callbacks_mod [ 228.094389] test_klp_callbacks_mod: test_klp_callbacks_mod_init [ 228.097768] % modprobe test_klp_callbacks_demo [ 228.099261] livepatch: enabling patch 'test_klp_callbacks_demo' [ 228.099263] livepatch: 'test_klp_callbacks_demo': initializing patching transition [ 228.099286] test_klp_callbacks_demo: pre_patch_callback: vmlinux [ 228.099287] test_klp_callbacks_demo: pre_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_LIVE] Normal state [ 228.099289] livepatch: 'test_klp_callbacks_demo': starting patching transition [ 229.027084] livepatch: 'test_klp_callbacks_demo': completing patching transition [ 229.027196] test_klp_callbacks_demo: post_patch_callback: vmlinux [ 229.027198] test_klp_callbacks_demo: post_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_LIVE] Normal state [ 229.027199] livepatch: 'test_klp_callbacks_demo': patching complete [ 229.118464] % echo 0 > /sys/kernel/livepatch/test_klp_callbacks_demo/enabled [ 229.118483] livepatch: 'test_klp_callbacks_demo': initializing unpatching transition [ 229.118504] test_klp_callbacks_demo: pre_unpatch_callback: vmlinux [ 229.118505] test_klp_callbacks_demo: pre_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_LIVE] Normal state [ 229.118506] livepatch: 'test_klp_callbacks_demo': starting unpatching transition [ 230.866938] livepatch: 'test_klp_callbacks_demo': completing unpatching transition [ 230.867117] test_klp_callbacks_demo: post_unpatch_callback: vmlinux [ 230.867118] test_klp_callbacks_demo: post_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_LIVE] Normal state [ 230.867120] livepatch: 'test_klp_callbacks_demo': unpatching complete [ 230.935471] % rmmod test_klp_callbacks_demo [ 230.997625] % rmmod test_klp_callbacks_mod [ 230.998771] test_klp_callbacks_mod: test_klp_callbacks_mod_exit [ 231.064190] ===== TEST: module_coming notifier ===== [ 231.067155] % modprobe test_klp_callbacks_demo [ 231.068630] livepatch: enabling patch 'test_klp_callbacks_demo' [ 231.068632] livepatch: 'test_klp_callbacks_demo': initializing patching transition [ 231.068652] test_klp_callbacks_demo: pre_patch_callback: vmlinux [ 231.068653] livepatch: 'test_klp_callbacks_demo': starting patching transition [ 232.786968] livepatch: 'test_klp_callbacks_demo': completing patching transition [ 232.787122] test_klp_callbacks_demo: post_patch_callback: vmlinux [ 232.787123] livepatch: 'test_klp_callbacks_demo': patching complete [ 232.800046] % modprobe test_klp_callbacks_mod [ 232.801418] livepatch: applying patch 'test_klp_callbacks_demo' to loading module 'test_klp_callbacks_mod' [ 232.801421] test_klp_callbacks_demo: pre_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_COMING] Full formed, running module_init [ 232.801423] test_klp_callbacks_demo: post_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_COMING] Full formed, running module_init [ 232.801465] test_klp_callbacks_mod: test_klp_callbacks_mod_init [ 232.801808] % echo 0 > /sys/kernel/livepatch/test_klp_callbacks_demo/enabled [ 232.801826] livepatch: 'test_klp_callbacks_demo': initializing unpatching transition [ 232.801848] test_klp_callbacks_demo: pre_unpatch_callback: vmlinux [ 232.801849] test_klp_callbacks_demo: pre_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_LIVE] Normal state [ 232.801850] livepatch: 'test_klp_callbacks_demo': starting unpatching transition [ 233.906995] livepatch: 'test_klp_callbacks_demo': completing unpatching transition [ 233.907137] test_klp_callbacks_demo: post_unpatch_callback: vmlinux [ 233.907139] test_klp_callbacks_demo: post_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_LIVE] Normal state [ 233.907140] livepatch: 'test_klp_callbacks_demo': unpatching complete [ 233.912080] % rmmod test_klp_callbacks_demo [ 233.987482] % rmmod test_klp_callbacks_mod [ 233.988644] test_klp_callbacks_mod: test_klp_callbacks_mod_exit [ 234.064216] ===== TEST: module_going notifier ===== [ 234.067491] % modprobe test_klp_callbacks_mod [ 234.068784] test_klp_callbacks_mod: test_klp_callbacks_mod_init [ 234.072123] % modprobe test_klp_callbacks_demo [ 234.073590] livepatch: enabling patch 'test_klp_callbacks_demo' [ 234.073592] livepatch: 'test_klp_callbacks_demo': initializing patching transition [ 234.073611] test_klp_callbacks_demo: pre_patch_callback: vmlinux [ 234.073613] test_klp_callbacks_demo: pre_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_LIVE] Normal state [ 234.073614] livepatch: 'test_klp_callbacks_demo': starting patching transition [ 234.866962] livepatch: 'test_klp_callbacks_demo': completing patching transition [ 234.867066] test_klp_callbacks_demo: post_patch_callback: vmlinux [ 234.867068] test_klp_callbacks_demo: post_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_LIVE] Normal state [ 234.867069] livepatch: 'test_klp_callbacks_demo': patching complete [ 234.889218] % rmmod test_klp_callbacks_mod [ 234.890290] test_klp_callbacks_mod: test_klp_callbacks_mod_exit [ 234.890303] test_klp_callbacks_demo: pre_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_GOING] Going away [ 234.890305] livepatch: reverting patch 'test_klp_callbacks_demo' on unloading module 'test_klp_callbacks_mod' [ 234.890307] test_klp_callbacks_demo: post_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_GOING] Going away [ 234.936640] % echo 0 > /sys/kernel/livepatch/test_klp_callbacks_demo/enabled [ 234.936658] livepatch: 'test_klp_callbacks_demo': initializing unpatching transition [ 234.936677] test_klp_callbacks_demo: pre_unpatch_callback: vmlinux [ 234.936678] livepatch: 'test_klp_callbacks_demo': starting unpatching transition [ 235.906953] livepatch: 'test_klp_callbacks_demo': completing unpatching transition [ 235.907059] test_klp_callbacks_demo: post_unpatch_callback: vmlinux [ 235.907060] livepatch: 'test_klp_callbacks_demo': unpatching complete [ 235.946374] % rmmod test_klp_callbacks_demo [ 236.044816] ===== TEST: module_coming and module_going notifiers ===== [ 236.047961] % modprobe test_klp_callbacks_demo [ 236.049483] livepatch: enabling patch 'test_klp_callbacks_demo' [ 236.049485] livepatch: 'test_klp_callbacks_demo': initializing patching transition [ 236.049505] test_klp_callbacks_demo: pre_patch_callback: vmlinux [ 236.049506] livepatch: 'test_klp_callbacks_demo': starting patching transition [ 236.947000] livepatch: 'test_klp_callbacks_demo': completing patching transition [ 236.947176] test_klp_callbacks_demo: post_patch_callback: vmlinux [ 236.947178] livepatch: 'test_klp_callbacks_demo': patching complete [ 236.969682] % modprobe test_klp_callbacks_mod [ 236.971078] livepatch: applying patch 'test_klp_callbacks_demo' to loading module 'test_klp_callbacks_mod' [ 236.971080] test_klp_callbacks_demo: pre_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_COMING] Full formed, running module_init [ 236.971082] test_klp_callbacks_demo: post_patch_callback: test_klp_callbacks_mod -> [MODULE_STATE_COMING] Full formed, running module_init [ 236.971123] test_klp_callbacks_mod: test_klp_callbacks_mod_init [ 236.972339] % rmmod test_klp_callbacks_mod [ 236.973427] test_klp_callbacks_mod: test_klp_callbacks_mod_exit [ 236.973439] test_klp_callbacks_demo: pre_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_GOING] Going away [ 236.973441] livepatch: reverting patch 'test_klp_callbacks_demo' on unloading module 'test_klp_callbacks_mod' [ 236.973442] test_klp_callbacks_demo: post_unpatch_callback: test_klp_callbacks_mod -> [MODULE_STATE_GOING] Going away [ 237.036714] % echo 0 > /sys/kernel/livepatch/test_klp_callbacks_demo/enabled [ 237.036732] livepatch: 'test_klp_callbacks_demo': initializing unpatching transition [ 237.036753] test_klp_callbacks_demo: pre_unpatch_callback: vmlinux [ 237.036754] livepatch: 'test_klp_callbacks_demo': starting unpatching transition [ 237.906936] livepatch: 'test_klp_callbacks_demo': completing unpatching transition [ 237.907087] test_klp_callbacks_demo: post_unpatch_callback: vmlinux [ 237.907088] livepatch: 'test_klp_callbacks_demo': unpatching complete [ 237.945408] % rmmod test_klp_callbacks_demo